Include !severity in logged events by syslog

Proposed patch attached (option #1 - minor change, includes severity to the list of available variables).

Option #2 - updates syslog_format variable in addition.

To have the most accurate syslog and be able to apply policies based on any given severity, you need a severity in your syslog files. So I would propose to add this.

Manual Review

Individual user account

Yes: Follows the guidelines for individual user accounts.

No duplication

Yes: Does not cause module duplication and/or fragmentation.

Master Branch

Yes: Follows the guidelines for master branch.

Licensing

Yes: Follows the licensing requirements.

3rd party assets/code

Yes: Follows the guidelines for 3rd party assets/code.

Code long/complex enough for review

Yes: Follows the guidelines for project length and complexity.

Secure code

Yes: Meets the security requirements.

The severity is passed to syslog() itself and I think the idea is that separating them out based on severity might be handled by the syslog configuration on the server, although I agree it would be useful to simply have available in the syslog format too.

However, it looks like this would be relevant for Drupal 8 too, so it would need to be added there first.

I'm also not sure we'd want to change the default format for existing sites at this point (see discussion by doublejosh in #3) although we certainly could add it as an option for people who want to configure it on their own.

With d8, we don't have the problem of upgrade path because configs are not automatically updated if you change the default value on an yml is not automatically applied. So current installations will not break.

Tagging this as Novice for D8, we could include the !severity on syslog.settings.yml and in the $form['syslog_format'] description.

Then we should create a change record that explains that Drupal 8.4.x have this setting configured on new installations.

Thanks @Thomasdbcklr. We still need a change record do you want to create it?

Never done this before, can you check if the change record is ok? https://www.drupal.org/node/2872254

Thanks! Well in my opinion the change record should say that in 8.4.x severity is added by default. And also that existing sites are not updated by default.

This value was available before. So that's not relevant for the change record.

I've updated the change record.

I am removing the "Needs change record" tag since it has already been written. I think it is still a novice task to review the change record. In fact, a lot of change records would benefit from being reviewed by novices.

Thanks @falc0. Agree with @benjifisher here. The Change Record still needs a bit of work.

I'm at DrupalCon Baltimore at the sprint. I've reviewed the patch and happy to revise the change record.

Change record revised at https://www.drupal.org/node/2872254

I tried this parch and the syslog includes !severity without the replacement

10627 Apr 29 19:26:43 AR-IT06455 drupal: http://example.com|1493504803|page not found|127.0.0.1|http://example.com/admin/config/development/ logging0||!severity|1||/this-page-does-not-exists

This is because the Logger class doesn't include !severity in core/modules/syslog/src/Logger/SysLog.php

    $entry = strtr($this->config->get('format'), [
      '!base_url' => $base_url,
      '!timestamp' => $context['timestamp'],
      '!type' => $context['channel'],
      '!ip' => $context['ip'],
      '!request_uri' => $context['request_uri'],
      '!referer' => $context['referer'],
      '!uid' => $context['uid'],
      '!link' => strip_tags($context['link']),
      '!message' => strip_tags($message),
    ]);

    syslog($level, $entry);

Updated patch with changes to Logger class

Thanks @c.nish2k3. The tests will probably pass because we don't have tests for this feature. I created #2874069: Make syslog testable. In my opinion we should postpone this ticket until we have some test coverage that ensure this is working as expected.

Reopening this, syslog() cannot be covered with automated testing.
Also $context['severity'] is actually $level in the log() method

Applied patch successfully from #27. @ nish2k3 , please include the !severity under “Specify the format of the syslog entry. Available variables are:”

It is updated in the patch

I've tested the patch by c.nish2k3 in comment #27.

The extra token, !severity, appears in the list of available variables at /admin/config/development/logging.

The Syslog format is not changed if it has already been configured before applying the patch. But on a clean install, enabling syslog will add !severity to the format.

The following is an example output of the log file following clean installs of Drupal with and without the patch. (I have highlighted the added serverity in the second log.)

Log in with one time login link before patch:

May 13 15:10:02 local drupal: http://drupal.dev|1494688202|user|192.168.100.1|http://drupal.dev/user/reset/1/1494688183/oqZFZK2g2CH1BDvFApn-KwOJcwD39u...|http://drupal.dev/user/reset/1|1||Session opened for admin.
May 13 15:10:02 local drupal: http://drupal.dev|1494688202|user|192.168.100.1|http://drupal.dev/user/reset/1/1494688183/oqZFZK2g2CH1BDvFApn-KwOJcwD39u...|http://drupal.dev/user/reset/1|1||User admin used one-time login link at time 1494688183.

Log in with one time login link after patch:

May 13 15:13:18 local drupal: http://drupal.dev|1494688398|user|192.168.100.1|http://drupal.dev/user/reset/1/1494688372/pZCA75I_5V3i9gYqsna2_cSWy6fFoX...|http://drupal.dev/user/reset/1|5|1||Session opened for admin.
May 13 15:13:18 local drupal: http://drupal.dev|1494688398|user|192.168.100.1|http://drupal.dev/user/reset/1/1494688372/pZCA75I_5V3i9gYqsna2_cSWy6fFoX...|http://drupal.dev/user/reset/1|5|1||User admin used one-time login link at time 1494688372.

A change log has also been drafted, so I'm setting this to RTBC.

+++ b/core/modules/syslog/config/install/syslog.settings.yml
@@ -3,4 +3,4 @@ identity: drupal
-format: '!base_url|!timestamp|!type|!ip|!request_uri|!referer|!uid|!link|!message'
+format: '!base_url|!timestamp|!type|!ip|!request_uri|!referer|!severity|!uid|!link|!message'

I'm not sure that we need to make this change to the default configuration. The problem here is this is about integrating with 3rd party tools - so instructions for integrating with logstash / elastic search or whatever log analysis approach you want to take have to change. Why not just do the change without changing the default? And open another issue to discuss changing the default. Take way, people who want the severity and want to change their log analysis can but until we work out all the impacts nothing else has to change.

Also it is a shame that this can't be tested using PHPUnit or something.

Updated patch incorporating comments from alexpott

Also it is a shame that this can't be tested using PHPUnit or something.

I'm working on this: #2874069: Make syslog testable

Added interdiff from #27 to #32.

I have tested the patch from #32.

The outcome is the same as #30 except that the default value is not changed from before and after the patch. The !severity token can still be added and is output accordingly. This is all to be expect as the interdiff (#34) shows that the only change is the default value.

With this patch and the work being carried out by dagmar on a separate issue, I believe this addresses alexpott's concerns in comment #31. Because of this I'm setting back to RTBC.

Unless the approach suggested in #2874069: Make syslog testable is incorrect. We should work first on tests and then add new features. Let's try to get some reviews first on #2874069

#2874069: Make syslog testable is in. We now can test this is working as expected.

Patch for retesting of #32.

We need a test modification in the case introduced here: #2874069: Make syslog testable

Miss understood. My mistake.

I have an Idea you con retrieve the static vars about severity and set in array of Test

$severity_levels = RfcLogLevel::getLevels();
$severity = $severity_levels::WARNING;

$this->assertEquals($severity, $log[6]);

Its only a bet !! I try this weekend and upload a patch if working.
Regards
Jack

The approach I propose here is.

1. Save the settings for syslog using ConfigFactory::getEditable to include !severity in the placeholders.
2. Create a log message using the logger.
3. Make sure that the severity is logged like is done in testSyslogWriting

Uploaded patch:

- Adds !severity_string as some systems use the strings instead of the integers
- Adds test as described by dagmar

Amazing! Thanks @wesleydv

+++ b/core/modules/syslog/src/Logger/SysLog.php
@@ -34,6 +36,22 @@ class SysLog implements LoggerInterface {
+  /**
+   * Map RFC 5424 log constants to PSR3 log constants.
+   *
+   * @var array
+   */
+  protected $levelTranslation = [
+    RfcLogLevel::EMERGENCY => LogLevel::EMERGENCY,
+    RfcLogLevel::ALERT => LogLevel::ALERT,
+    RfcLogLevel::CRITICAL => LogLevel::CRITICAL,
+    RfcLogLevel::ERROR => LogLevel::ERROR,
+    RfcLogLevel::WARNING => LogLevel::WARNING,
+    RfcLogLevel::NOTICE => LogLevel::NOTICE,
+    RfcLogLevel::INFO => LogLevel::INFO,
+    RfcLogLevel::DEBUG => LogLevel::DEBUG,
+  ];
+

I'm not really sure if we should log severity string in syslog. This can be calculated using the RFC 5424 standard and any tool for parsing logs should be capable of do it.

There is no other part of code in core that is doing this as far I know. Actually LoggerChannel::log is doing just the opposite.

@dagmar yes you're probably right about the severity string thing.

I've added a new patch without it, so basicly #38 plus the test.

Great. Almost there.

1. +++ b/core/modules/syslog/tests/src/Kernel/SyslogTest.php
   @@ -54,4 +53,39 @@ public function testSyslogWriting() {
   +   * @covers ::log
   

   In addition to this, I would like to see a description of what this is actually testing.

2. +++ b/core/modules/syslog/tests/src/Kernel/SyslogTest.php
   @@ -54,4 +53,39 @@ public function testSyslogWriting() {
   +    $request = Request::create('/page-not-found', 'GET', [], [], [], ['REMOTE_ADDR' => '1.2.3.4']);
   +    $request->headers->set('Referer', 'other-site');
   +    \Drupal::requestStack()->push($request);
   +
   +    $user = $this->getMockBuilder('Drupal\Core\Session\AccountInterface')->getMock();
   +    $user->method('id')->willReturn(42);
   +    $this->container->set('current_user', $user);
   +
   

   All this is already covered in testSystlogWriting. I think we could simplify this to only use !type|!message|!severity to reduce the code of this function.

New patch reflecting dagmars remarks

This is coming along really well, with thanks to @dagmar and @wesleydv! :D

Can we get a patch with just the test to make sure it fails without the rest of the patch. Thanks.

Test only patch
I don't think this will add lot of insight, but I guess it won't hurt either.

Failed as expected. Great work @wesleydv!

I updated the change record: https://www.drupal.org/node/2872254

Thanks @dagmar and @wesleydv. Adding this feature makes sense to me.

+++ b/core/modules/syslog/tests/src/Kernel/SyslogTest.php
@@ -4,7 +4,6 @@
 use Drupal\KernelTests\KernelTestBase;
 use Symfony\Component\HttpFoundation\Request;
-use Symfony\Component\HttpFoundation\RequestStack;

I was wondering how it was that an unused use statement crept in despite our automated precommit hook that tests this rule along with the others in the ruleset. Turns out the use of \Drupal::requestStack() creates a false positive for the use statement.

This hunk is technically an out of scope change so shouldn't really be included in the patch, but I let it pass in this case.

Committed and pushed to 8.5.x. Thanks!

Since D7 "Patch (to be ported)" issues haven't been getting their backport issues filed (and so they're remained open , I'm adding a new "Needs D7 backport issue filed" tag, which can be searched on "Closed (fixed)" issues to get the queue of needed backports.

@xjm The !severity_string as initially developed in #45 bij @wesleydv is useful in cases you don't can or want to use the parser for translating the integers to the PRS Loglevels.

Is there any change the feature will be added to Drupal Core if I make a new issue with a new patch or will it never end up in Drupal Core anyway?

Backport of the patch for Drupal 7.84