Intro
Up to service-runner 2.7.7, logging to stdout would emit an integer log level, something that while functional, would not be very nice to see in logstash, nor would it convey any information (e.g. is "50" a warning or an information message?). While this wasn't a problem when services would directly log to logstash, in the logging pipeline that is becoming a minor nuisance and would be nice to solve.
We want to drop direct logstash logging and rely on the logging pipeline alone for a number of reasons, but this is a blocker.
Starting with service-runner 2.7.7, we can add named_levels: true to the configuration of services, thus emitting the more useful "WARNING", "INFO", "DEBUG" and so on.
Services
Below is a list of all services that need to be updated, before we disable direct logstash logging.
- changeprop
- chromium-render
- citoid
- cxserver
- eventgate - updated to 2.7.7 but named-levels: true not added yet
- eventstreams - uses fork which does not currently support named-levels:true (https://github.com/wikimedia/service-runner/tree/prometheus_metrics)
- mathoid
- mobileapps
-
restrouter - termbox
- wikifeeds
Those services need a service-runner bump and then the corresponding helm chart change.
Details
Looking at https://logstash.wikimedia.org/goto/eeb430dc9ce3bb2006e74d5535d72220 it appears that we have log messages of log level "50"
A sample would be
{
"_index": "logstash-2019.11.29",
"_type": "unsupported_language",
"_id": "AW62zVUfarkxubcmhm9E",
"_version": 1,
"_score": null,
"_source": {
"msg": "501: unsupported_language",
"kubernetes": {
"namespace_id": "78fc9cd8-d3db-11e9-9f9a-aa0000fe6bdf",
"container_name": "wikifeeds-production",
"creation_timestamp": "2019-09-10T14:58:39Z",
"host": "kubernetes1003.eqiad.wmnet",
"master_url": "https://kubemaster.svc.eqiad.wmnet:6443",
"pod_id": "f9c9f488-0fbe-11ea-a07e-aa0000fe6bdf",
"namespace_labels": {
"app": "raw",
"heritage": "Tiller",
"chart": "raw-0.2.0",
"release": "wikifeeds-namespace"
},
"labels": {
"app": "wikifeeds",
"pod-template-hash": "698dd6b976",
"release": "production"
},
"pod_name": "wikifeeds-production-698dd6b976-vx2lw",
"namespace_name": "wikifeeds"
},
"request": {
"headers": {
"x-request-id": "8eae2f83-2080-4d65-9862-5118cde9160b",
"content-length": "0"
},
"method": "GET",
"query": {},
"remotePort": 42778,
"params": {
"0": "/simple.wikipedia.org/v1/feed/onthisday/selected/11/23"
},
"url": "/simple.wikipedia.org/v1/feed/onthisday/selected/11/23",
"remoteAddress": "10.64.0.145"
},
"metadata": {
"filename": "/var/log/containers/wikifeeds-production-698dd6b976-vx2lw_wikifeeds_wikifeeds-production-51f6e0ed11a8bf36e95ee3c2b312804c351557ea7c01772bdb37d402d1b1f37f.log",
"fileoffset": "115335246"
},
"pid": 16,
"program": "input-file-kubernetes",
"type": "unsupported_language",
"docker": {
"container_id": "51f6e0ed11a8bf36e95ee3c2b312804c351557ea7c01772bdb37d402d1b1f37f"
},
"levelPath": "error/501",
"hostname": "wikifeeds-production-698dd6b976-vx2lw",
"stream": "stdout",
"host": "kubernetes1003",
"@version": "1",
"timestamp": "2019-11-29T10:55:39.480534+00:00",
"level": "50",
"logsource": "kubernetes1003",
"message": "501: unsupported_language",
"normalized_message": "501: unsupported_language",
"tags": [
"input-kafka-rsyslog-shipper",
"rsyslog-shipper",
"kafka",
"syslog",
"es",
"normalized_message_untrimmed"
],
"@timestamp": "2019-11-29T10:55:39.574Z",
"v": 0,
"name": "wikifeeds",
"time": "2019-11-29T10:55:39.480Z",
"detail": "The language you have requested is not yet supported.",
"facility": "local0",
"request_id": "8eae2f83-2080-4d65-9862-5118cde9160b",
"status": 501
},
"fields": {
"@timestamp": [
1575024939574
]
},
"sort": [
1575024939574
]
}kubectl logs for wikifeeds shows the same thing (which is expected since that's the exact content that get shipped to logstash)