Problem/Motivation

There is no test coverage for syslog functionality. #1748410: Include !severity in logged events by syslog made it evident.

Ideally we would like to test what syslog() function is actually saving in the /var/log/syslog.log file. To make sure that for a given entry we get things replaced correctly:

From this:
!base_url|!timestamp|!type|!ip|!request_uri|!referer|!uid|!link|!message

To this:
http://example.com|1493504803|page not found|127.0.0.1|http://example.com/admin/config/development/ logging0|1||/this-page-does-not-exists

Proposed resolution

Alternative 1:

  • Move the call to syslog() to a method of SysLog logger
  • Create a test module that provide its own Logger that extends SysLog and override the syslog method.
  • Create a testcase that installs the custom test module and makes the assertions.

Alternative 2:

  • Find a way to change the output of syslog to a file that drupal can read and inspect.
  • Create a testcase that installs the custom test module and makes the assertions.

Remaining tasks

Decide on which solution is the best.
Code it.
Review the patch.

User interface changes

None

API changes

New method for the SysLog logger.

Data model changes

None

CommentFileSizeAuthor
#20 interdiff-2874069-16-20.txt1.25 KBdagmar
#20 2874069-20.patch4.35 KBdagmar
#16 interdiff-2874069-15-16.txt712 bytesdagmar
#16 2874069-16.patch4.37 KBdagmar
#15 2874069-15.patch4.35 KBdagmar
#8 2874069-8.patch4.61 KBdagmar
#8 interdiff-2874069-6-8.txt1.14 KBdagmar
#6 2874069-6.patch4.64 KBdagmar
Support from Acquia helps fund testing for Drupal Acquia logo

Comments

dagmar created an issue. See original summary.

benjifisher’s picture

benjifisher
he/him or they/them
Primary language English
Location Boston area
CreditAttribution: benjifisher at Isovera commented
Title: Make syslog testeable » Make syslog testable
Issue summary: View changes

@dagmar, can you give a little more detail in the issue summary?

  1. In the issue title, does "syslog" mean the syslog module (core/modules/syslog)?
  2. Where is the call to syslog() that you want to move?
  3. What assertions do you want to test?

Searching the syslog module for "syslog(", the only place I find it is in the log() method of Drupal\syslog\Logger\SysLog. Probably I am misreading this issue, because it looks as though the code is already where you want it. I am not sure what you have in mind for this issue.

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented

@benjifisher, thanks for your questions.

In the issue title, does "syslog" mean the syslog module (core/modules/syslog)?

Yes

Where is the call to syslog() that you want to move?

Here: http://cgit.drupalcode.org/drupal/tree/core/modules/syslog/src/Logger/Sy...

However, I'm not sure if this is the best way to make this testable. Maybe we can find a way to change the path of the syslog file and just read it from the filesystem.

What assertions do you want to test?

I would like to test what syslog() function is actually saving in the /var/log/syslog.log file. To make sure that for a given entry we get things replaced correctly:

From this:
!base_url|!timestamp|!type|!ip|!request_uri|!referer|!uid|!link|!message

To this:
http://example.com|1493504803|page not found|127.0.0.1|http://example.com/admin/config/development/ logging0|1||/this-page-does-not-exists

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
Issue summary: View changes
dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
Status: Active » Closed (won't fix)

After read the syslog documentation I came to the conclusion this cannot be done. The syslog path cannot be changed from php and the replace the syslog() call with a new implementation basically means having something like this: https://www.phpclasses.org/package/2787-PHP-Log-data-to-a-RFC-3164-compl...

We should encourage manual testing for tickets like: #1748410: Include !severity in logged events by syslog.

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
Status: Closed (won't fix) » Needs review
Issue tags: +phpunit initiative
FileSize
2874069-6.patch4.64 KB

Actually, we still can use the first approach. Here is the patch.

Status: Needs review » Needs work

The last submitted patch, 6: 2874069-6.patch, failed testing.

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
Status: Needs work » Needs review
FileSize
interdiff-2874069-6-8.txt1.14 KB
2874069-8.patch4.61 KB

Weird, this pass in my local env. Let's try with this.

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
Issue summary: View changes

I had a conversation with one of the leaders of the PHP initiative. This confirms alternative 1 is not valid and the only path we have for this ticket is something like the alternative 2.

(10:52:49) dagmar_drupal: hi. I have a question regarding the approach to make the syslog module testable: https://www.drupal.org/node/2874069
(10:53:16) dagmar_drupal: do you know if there is something similar in contrib or core to see if that approach is correct?
(10:54:26) michielnugter: Honestly, I have no idea if anything like this is in contrib or core. Let me take a quick look
(11:01:02) michielnugter: I took a look at syslog. I can't figure out any way to reliably read the syslog file results
(11:01:30) michielnugter: Seems like your approach is the only viable way of testing it
(11:02:44) michielnugter: Shame it doesn't actually test syslog but it does test the really import parts (an error is logged)
(11:04:18) dagmar_drupal: thanks. Yes I spent a few hours trying to read the syslog entries directly, there is an interesting effect using the LOG_PERROR in openlog 
(11:05:02) michielnugter: Still searching core right now to see if I can find anything.
(11:05:14) dagmar_drupal: but it is always detected as an error by phpunit and I couldn't make it work
(11:06:40) michielnugter: Simpletest does have assertErrorMessage but it's not available in PHPUnit (yet). Only reference is EntityReferenceAutoCreateTest.php
(11:07:00) michielnugter: Was looking at that too, shame it doesn't work
(11:08:37) dagmar_drupal: assertErrorMessage works because it relies on error_log that allows you to change the path of the log
(11:09:00) michielnugter: Could we maybe do something like setting the error_log via ini_set() and then read it in the test?
(11:09:45) michielnugter: I saw that too. Seems there is no existing coverage for syslog usage.
(11:10:12) michielnugter:  Skip the last suggestion
(11:10:42) michielnugter: Would not work as it's not an error_log() message
(11:13:01) dagmar_drupal:  michielnugter: ok, thanks. Good to confirm at least there was no another way to make this work.
(11:13:34) michielnugter: No problem, hope I can be more helpful next time ;)
dawehner’s picture

dawehner
Primary language German
CreditAttribution: dawehner as a volunteer and at Chapter Three commented 
+++ b/core/modules/syslog/tests/modules/syslog_test/syslog_test.services.yml
index 11b577f..7753c89 100644
--- a/core/modules/syslog/tests/src/Functional/SyslogTest.php

+++ b/core/modules/syslog/tests/src/Functional/SyslogTest.php
@@ -37,4 +37,54 @@ public function testSettings() {
 
+  /**
+   * Test the syslog writing functionality.
+   */
+  public function testSyslogWriting() {

Is there a reason this is a functional test. Maybe i'm a bit stubborn, but couldn't this be a kernel test here?

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented

I made this a functional tests to avoid the need to fake a http request.

dawehner’s picture

dawehner
Primary language German
CreditAttribution: dawehner as a volunteer and at Chapter Three commented

Why do we do a HTTP request instead of just calling to the logging API?

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented

Because we need a full log in order to test all the placeholders.

!base_url|!timestamp|!type|!ip|!request_uri|!referer|!uid|!link|!message

dawehner’s picture

dawehner
Primary language German
CreditAttribution: dawehner as a volunteer and at Chapter Three commented

Mhhh, I mean you could create a request and push it onto the request stack, but I see what you mean. Do you maybe want to document that on the test?

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
FileSize
2874069-15.patch4.35 KB

Actually making this a Kernel Test give us much more control about the request, thanks @dawehner.

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
FileSize
2874069-16.patch4.37 KB
interdiff-2874069-15-16.txt712 bytes

Removed the hardcoded 127.0.0.1

dawehner’s picture

dawehner
Primary language German
CreditAttribution: dawehner as a volunteer and at Chapter Three commented 
+++ b/core/modules/syslog/tests/src/Kernel/SyslogTest.php
@@ -47,7 +47,7 @@ public function testSyslogWriting() {
-    $this->assertEquals('127.0.0.1', $log[3]);
+    $this->assertEquals(\Drupal::request()->getClientIp(), $log[3]);

I don't think we should "access" the current client IP, given its always artificial in the context of kernel tests ...

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented

I just trying to match a placeholder with a value that makes sense. Do you think a should skip this assertion?

dawehner’s picture

dawehner
Primary language German
CreditAttribution: dawehner as a volunteer and at Chapter Three commented

Can't you control everything when you create a request manually?

dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
FileSize
2874069-20.patch4.35 KB
interdiff-2874069-16-20.txt1.25 KB

Oh I see what you mean. What about this?

dawehner’s picture

dawehner
Primary language German
CreditAttribution: dawehner as a volunteer and at Chapter Three commented
Status: Needs review » Reviewed & tested by the community

+1 for that

catch’s picture

catch
he/him
Primary language English
CreditAttribution: catch at Third and Grove commented
Status: Reviewed & tested by the community » Fixed

Committed 3958a93 and pushed to 8.4.x. Thanks!\

  • catch committed 3958a93 on 8.4.x 
    Issue #2874069 by dagmar, dawehner: Make syslog testable

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.