Page MenuHomePhabricator

Scap should set 'level' in Logstash messages
Open, MediumPublic

Description

It seems that as of late, Scap no longer sets the level attribute in its Logstash messages.

https://logstash.wikimedia.org/app/kibana#/dashboard/mwdebug1002

Screenshot 1.png (742×1 px, 147 KB)

Instead, it seems to set an attribute called loglevel which isn't what MediaWiki, syslog and all other production services use for the severity. I couldn't find anything obvious in Puppet that changed so I suspect it might be due to a change in Scap itself.

Event Timeline

mmodell added a project: observability.
mmodell added a subscriber: fgiunchedi.

this looks like it's likely the culprit: rMSCA3ca8820b7a68: Support for logging json to syslog

@fgiunchedi do you think ^ is a likely cause of this regression?

Maybe due to something in the logging pipeline changed, although we're not using that specific feature yet:

deploy1001:~$ grep -ir syslog /etc/scap.cfg 
deploy1001:~$

@Krinkle do you know when this started happening?

The actual change in Scap happened last year, but it was included in a Scap release in 3.14.0, which happened February this year: release was made on Feb 18, and a few days later built and deployed to the hosts. You opened the ticket on March 3, so the times are close, which is certainly quite suspicious.

However, @fgiunchedi says we don't use the config yet, so the next question is to find out how Scap log messages end up on logstash and do they go via syslog or not.

Actually, when I look at deployment-mediawiki-07.deployment-prep.eqiad.wmflabs, I see syslog in the config:

~~~sh
liw@deployment-mediawiki-07:~$ grep syslog /etc/scap.cfg
use_syslog: True
~~~

Also on deployment-deploy01.deployment-prep.eqiad.wmflabs in fact.

thcipriani lowered the priority of this task from High to Medium.Apr 9 2020, 7:53 PM

I don't see a loglevel on any of our records in logstash, I do see levelname.

@Krinkle do you know when this started happening?

FWIW, I see levelname going back as far as logstash goes (January).

levelname is also the the name of a key in the python logging module log record. The LogstashFormatter class in scap starts by copying the internal __dict__ of a log record, and renaming a few fields (although level is not one of them).

Is it possible that this isn't a regression? AFAICT, this is how this code has been since 2014.

However, @fgiunchedi says we don't use the config yet, so the next question is to find out how Scap log messages end up on logstash and do they go via syslog or not.

Actually, when I look at deployment-mediawiki-07.deployment-prep.eqiad.wmflabs, I see syslog in the config:

~~~sh
liw@deployment-mediawiki-07:~$ grep syslog /etc/scap.cfg
use_syslog: True
~~~

Also on deployment-deploy01.deployment-prep.eqiad.wmflabs in fact.

This is due to puppet patches being cherry picked on deployment-puppetmaster: https://gerrit.wikimedia.org/r/574485/

thcipriani renamed this task from Scap no longer sets 'level' in Logstash messages to Scap should set 'level' in Logstash messages.Jun 23 2020, 5:45 PM
thcipriani added a project: good first task.

@thcipriani: A good first task is a self-contained, non-controversial task with a clear approach and links to documentation and the codebase (see the project description). Given the current task description I'm removing the good first task tag, as there are several possible approaches here.