Testsuite: syslog testcase

5 files changed, 179 insertions, 8 deletions

diff --git a/src/src/log.c b/src/src/log.c
index 9cde369c0..6d8fdd24d 100644
--- a/src/src/log.c
+++ b/src/src/log.c
@@ -145,8 +145,6 @@ write_syslog(int priority, const uschar *s)
 int len, pass;
 int linecount = 0;
 
-if (running_in_test_harness) return;
-
 if (!syslog_pid && LOGGING(pid))
   s = string_sprintf("%.*s%s", (int)pid_position[0], s, s + pid_position[1]);
 if (!syslog_timestamp)
@@ -159,7 +157,7 @@ if (!syslog_timestamp)
 len = Ustrlen(s);
 
 #ifndef NO_OPENLOG
-if (!syslog_open)
+if (!syslog_open && !running_in_test_harness)
   {
 # ifdef SYSLOG_LOG_PID
   openlog(CS syslog_processname, LOG_PID|LOG_CONS, syslog_facility);
@@ -189,15 +187,23 @@ for (pass = 0; pass < 2; pass++)
     tlen -= plen;
     if (ss[plen] == '\n') tlen--;    /* chars left */
 
-    if (pass == 0) linecount++; else
-      {
+    if (pass == 0)
+      linecount++;
+    else if (running_in_test_harness)
+      if (linecount == 1)
+        fprintf(stderr, "SYSLOG: '%.*s'\n", plen, ss);
+      else
+        fprintf(stderr, "SYSLOG: '[%d%c%d] %.*s'\n", i,
+          ss[plen] == '\n' && tlen != 0 ? '\\' : '/',
+          linecount, plen, ss);
+    else
       if (linecount == 1)
         syslog(priority, "%.*s", plen, ss);
       else
         syslog(priority, "[%d%c%d] %.*s", i,
           ss[plen] == '\n' && tlen != 0 ? '\\' : '/',
           linecount, plen, ss);
-      }
+
     ss += plen;
     if (*ss == '\n') ss++;
     }
diff --git a/test/confs/0615 b/test/confs/0615
new file mode 100644
index 000000000..63b9d7fac
--- /dev/null
+++ b/test/confs/0615
@@ -0,0 +1,28 @@
+# Exim test configuration 0615
+
+keep_environment = PATH
+exim_path = EXIM_PATH
+spool_directory = DIR/spool
+
+log_file_path = DIR/spool/log/%slog : syslog
+
+gecos_pattern = ""
+gecos_name = CALLER_NAME
+chunking_advertise_hosts =
+tls_advertise_hosts =
+
+primary_hostname = myhost.test.ex
+queue_only
+
+# ----- Main settings -----
+
+log_selector = LOG_SELECTOR
+log_timezone = TIMES
+
+syslog_timestamp = ARG1
+syslog_pid = ARG2
+
+acl_not_smtp = accept logwrite = msg
+
+
+# End
diff --git a/test/log/0615 b/test/log/0615
new file mode 100644
index 000000000..230bf71c2
--- /dev/null
+++ b/test/log/0615
@@ -0,0 +1,64 @@
+1999-03-02 09:44:33 10HmaX-0005vi-00 msg
+1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmaY-0005vi-00 msg
+1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbA-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbA-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1234] 10HmbB-0005vi-00 msg
+1999-03-02 09:44:33 [1234] 10HmbB-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1235] 10HmbC-0005vi-00 msg
+1999-03-02 09:44:33 [1235] 10HmbC-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1236] 10HmbD-0005vi-00 msg
+2017-07-30 18:51:05.712 [1236] 10HmbD-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1237] 10HmbE-0005vi-00 msg
+2017-07-30 18:51:05.712 [1237] 10HmbE-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmbF-0005vi-00 msg
+1999-03-02 09:44:33 10HmbF-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmbG-0005vi-00 msg
+1999-03-02 09:44:33 10HmbG-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbH-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbH-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbI-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbI-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1238] 10HmbJ-0005vi-00 msg
+1999-03-02 09:44:33 [1238] 10HmbJ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1239] 10HmbK-0005vi-00 msg
+1999-03-02 09:44:33 [1239] 10HmbK-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1240] 10HmbL-0005vi-00 msg
+2017-07-30 18:51:05.712 [1240] 10HmbL-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1241] 10HmbM-0005vi-00 msg
+2017-07-30 18:51:05.712 [1241] 10HmbM-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmbN-0005vi-00 msg
+1999-03-02 09:44:33 10HmbN-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmbO-0005vi-00 msg
+1999-03-02 09:44:33 10HmbO-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbP-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbP-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbQ-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbQ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1242] 10HmbR-0005vi-00 msg
+1999-03-02 09:44:33 [1242] 10HmbR-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1243] 10HmbS-0005vi-00 msg
+1999-03-02 09:44:33 [1243] 10HmbS-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1244] 10HmbT-0005vi-00 msg
+2017-07-30 18:51:05.712 [1244] 10HmbT-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1245] 10HmbU-0005vi-00 msg
+2017-07-30 18:51:05.712 [1245] 10HmbU-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmbV-0005vi-00 msg
+1999-03-02 09:44:33 10HmbV-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmbW-0005vi-00 msg
+1999-03-02 09:44:33 10HmbW-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbX-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 10HmbY-0005vi-00 msg
+2017-07-30 18:51:05.712 10HmbY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1246] 10HmbZ-0005vi-00 msg
+1999-03-02 09:44:33 [1246] 10HmbZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 [1247] 10HmcA-0005vi-00 msg
+1999-03-02 09:44:33 [1247] 10HmcA-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1248] 10HmcB-0005vi-00 msg
+2017-07-30 18:51:05.712 [1248] 10HmcB-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+2017-07-30 18:51:05.712 [1249] 10HmcC-0005vi-00 msg
+2017-07-30 18:51:05.712 [1249] 10HmcC-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
diff --git a/test/runtest b/test/runtest
index 7893dcbd7..63e6e11ea 100755
--- a/test/runtest
+++ b/test/runtest
@@ -490,6 +490,11 @@ RESET_AFTER_EXTRA_LINE_READ:
   s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d(\s[+-]\d\d\d\d)?\s/1999-03-02 09:44:33 /gx;
   s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}(\s[+-]\d\d\d\d)?\s/2017-07-30 18:51:05.712 /gx;
   s/^Logwrite\s"\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d/Logwrite "1999-03-02 09:44:33/gx;
+  # Date/time in syslog test
+  s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\s/2017-07-30 18:51:05 /gx;
+  s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}\s/2017-07-30 18:51:05.712 /gx;
+  s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\s[+-]\d\d\d\d\s/2017-07-30 18:51:05 +9999 /gx;
+  s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}\s[+-]\d\d\d\d\s/2017-07-30 18:51:05.712 +9999 /gx;
 
   s/((D|[RQD]T)=)\d+s/$1qqs/g;
   s/((D|[RQD]T)=)\d\.\d{3}s/$1q.qqqs/g;
@@ -675,8 +680,12 @@ RESET_AFTER_EXTRA_LINE_READ:
   s"test-mail/temp\.\d+\."test-mail/temp.pppp.";
 
   # Optional pid in log lines
-  s/^(\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d)(\s[+-]\d\d\d\d|)(\s\[\d+\])/
-    "$1$2 [" . new_value($3, "%s", \$next_pid) . "]"/gxe;
+  s/^(\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d)(\.\d{3}|)(\s[+-]\d{4}|)(\s\[\d+\])/
+    "$1$2$3 [" . new_value($4, "%s", \$next_pid) . "]"/gxe;
+
+  # Optional pid in syslog test lines
+  s/^(SYSLOG:\s\'([-0-9]{10}\s[:.0-9]{8,12}\s([-+]\d{4}\s)?|))(\[\d+\] )/
+    "$1\[" . new_value($4, "%s", \$next_pid) . "]"/gxe;
 
   # Detect a daemon stderr line with a pid and save the pid for subsequent
   # removal from following lines.
diff --git a/test/stderr/0615 b/test/stderr/0615
new file mode 100644
index 000000000..2a00021be
--- /dev/null
+++ b/test/stderr/0615
@@ -0,0 +1,64 @@
+SYSLOG: '10HmaX-0005vi-00 msg'
+SYSLOG: '10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmaY-0005vi-00 msg'
+SYSLOG: '10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmaZ-0005vi-00 msg'
+SYSLOG: '10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbA-0005vi-00 msg'
+SYSLOG: '10HmbA-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbB-0005vi-00 msg'
+SYSLOG: '10HmbB-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbC-0005vi-00 msg'
+SYSLOG: '10HmbC-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbD-0005vi-00 msg'
+SYSLOG: '10HmbD-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbE-0005vi-00 msg'
+SYSLOG: '10HmbE-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbF-0005vi-00 msg'
+SYSLOG: '10HmbF-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbG-0005vi-00 msg'
+SYSLOG: '10HmbG-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbH-0005vi-00 msg'
+SYSLOG: '10HmbH-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '10HmbI-0005vi-00 msg'
+SYSLOG: '10HmbI-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '[1250] 10HmbJ-0005vi-00 msg'
+SYSLOG: '[1250] 10HmbJ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '[1251] 10HmbK-0005vi-00 msg'
+SYSLOG: '[1251] 10HmbK-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '[1252] 10HmbL-0005vi-00 msg'
+SYSLOG: '[1252] 10HmbL-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '[1253] 10HmbM-0005vi-00 msg'
+SYSLOG: '[1253] 10HmbM-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 10HmbN-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 10HmbN-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmbO-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmbO-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 10HmbP-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 10HmbP-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 10HmbQ-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 10HmbQ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 10HmbR-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 10HmbR-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmbS-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmbS-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 10HmbT-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 10HmbT-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 10HmbU-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 10HmbU-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 10HmbV-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 10HmbV-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmbW-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmbW-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 10HmbX-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 10HmbX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 10HmbY-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 10HmbY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 [1254] 10HmbZ-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 [1254] 10HmbZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmcA-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05 +9999 10HmcA-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 [1255] 10HmcB-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 [1255] 10HmcB-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 [1256] 10HmcC-0005vi-00 msg'
+SYSLOG: '2017-07-30 18:51:05.712 +9999 [1256] 10HmcC-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss'