[PATCH v2 0/3] syslogd: Add a configurable option to log timestamps in ISO 8601 format

Wed Apr 2 14:43:50 UTC 2025

This provides unification for the several syslogd options that
influence handling and formatting of log timestamps and adds a new
configuration and option.

First, this unifies the handling of messages with a client-generated
timestamps when both 'FEATURE_SYSLOGD_PRECISE_TIMESTAMPS' and
'FEATURE_SYSLOGD_UTC' are asserted.

In particular, to support the intermix of client-generated and
server-generated timestamps, the former are zero-padded such that the
timestamp "column" of a log file is consistent in format.

Second, this adds a configurable option 'FEATURE_SYSLOGD_ISO8601FMT' enabling
a command line option ('-I', with semantics similar to 'date') that
directs syslogd to log timestamps in ISO 8601 format.

Precision in seconds (the default), milliseconds, and microseconds are
supported. Without the 'FEATURE_SYSLOGD_UTC' configuration and its
'-u' option, outputs are of the form:

  YYYY-MM-DDThh:mm:ss±hhmm (seconds)
  YYYY-MM-DDThh:mm:ss.sss±hhmm (milliseconds)
  YYYY-MM-DDThh:mm:ss.uuuuuu±hhmm (microseconds)

with the 'FEATURE_SYSLOGD_UTC' configuration and its '-u' option,
outputs are of the form:

  YYYY-MM-DDThh:mm:ssZ (seconds)
  YYYY-MM-DDThh:mm:ss.sssZ (milliseconds)
  YYYY-MM-DDThh:mm:ss.uuuuuuZ (microseconds)

With all three of the follow options asserted:

  * FEATURE_SYSLOGD_PRECISE_TIMESTAMPS
  * FEATURE_SYSLOGD_UTC
  * FEATURE_SYSLOGD_ISO8601FMT

there are a total of twenty (20) possible test cases of which sixteen
(16) are unique (several of which are defaults):

    1. syslogd -O - -n
    2. syslogd -O - -n -u
    3. syslogd -O - -n -I
    4. syslogd -O - -n -Is
    5. syslogd -O - -n -Ims
    6. syslogd -O - -n -Ius
    7. syslogd -O - -n -I -u
    8. syslogd -O - -n -Is -u
    9. syslogd -O - -n -Ims -u
    10. syslogd -O - -n -Ius -u
    11. syslogd -O - -n -t
    12. syslogd -O - -n -t -u
    13. syslogd -O - -n -t -I
    14. syslogd -O - -n -t -Is
    15. syslogd -O - -n -t -Ims
    16. syslogd -O - -n -t -Ius
    17. syslogd -O - -n -t -I -u
    18. syslogd -O - -n -t -Is -u
    19. syslogd -O - -n -t -Ims -u
    20. syslogd -O - -n -t -Ius -u

which result in the following test output, generated interactively
with 'logger' over ssh:

    2025-03-28T20:10:11-0600 [19205453]# ./busybox syslogd -O - -n
    Mar 28 20:10:54.824 19205453 syslog.info syslogd started: BusyBox v1.36.1
    Mar 28 20:10:59.000 19205453 auth.info sshd-session[940]: Accepted publickey for test from 192.168.1.94 port 44522 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    Mar 28 20:10:59.000 19205453 user.info test[42]: busybox syslogd test.
    Mar 28 20:10:59.000 19205453 auth.info sshd-session[942]: Received disconnect from 192.168.1.94 port 44522:11: disconnected by user
    Mar 28 20:10:59.000 19205453 auth.info sshd-session[942]: Disconnected from user test 192.168.1.94 port 44522
    Mar 28 20:11:09.185 19205453 syslog.info syslogd exiting

    2025-03-28T20:11:09-0600 [19205453]# ./busybox syslogd -O - -n -u
    Mar 29 02:11:11.742 19205453 syslog.info syslogd started: BusyBox v1.36.1
    Mar 29 02:11:14.000 19205453 auth.info sshd-session[945]: Accepted publickey for test from 192.168.1.94 port 45900 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    Mar 29 02:11:14.000 19205453 user.info test[42]: busybox syslogd test.
    Mar 29 02:11:14.000 19205453 auth.info sshd-session[947]: Received disconnect from 192.168.1.94 port 45900:11: disconnected by user
    Mar 29 02:11:14.000 19205453 auth.info sshd-session[947]: Disconnected from user test 192.168.1.94 port 45900
    Mar 29 02:11:21.280 19205453 syslog.info syslogd exiting

    2025-03-28T20:11:21-0600 [19205453]# ./busybox syslogd -O - -n -I
    2025-03-28T20:11:25-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:11:30-0600 19205453 auth.info sshd-session[950]: Accepted publickey for test from 192.168.1.94 port 45842 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:11:30-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:11:30-0600 19205453 auth.info sshd-session[952]: Received disconnect from 192.168.1.94 port 45842:11: disconnected by user
    2025-03-28T20:11:30-0600 19205453 auth.info sshd-session[952]: Disconnected from user test 192.168.1.94 port 45842
    2025-03-28T20:11:34-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:11:34-0600 [19205453]# ./busybox syslogd -O - -n -Is
    2025-03-28T20:11:35-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:11:38-0600 19205453 auth.info sshd-session[955]: Accepted publickey for test from 192.168.1.94 port 46904 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:11:38-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:11:38-0600 19205453 auth.info sshd-session[957]: Received disconnect from 192.168.1.94 port 46904:11: disconnected by user
    2025-03-28T20:11:38-0600 19205453 auth.info sshd-session[957]: Disconnected from user test 192.168.1.94 port 46904
    2025-03-28T20:11:41-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:11:41-0600 [19205453]# ./busybox syslogd -O - -n -Ims
    2025-03-28T20:11:45.942-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:11:49.000-0600 19205453 auth.info sshd-session[960]: Accepted publickey for test from 192.168.1.94 port 35262 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:11:49.000-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:11:49.000-0600 19205453 auth.info sshd-session[962]: Received disconnect from 192.168.1.94 port 35262:11: disconnected by user
    2025-03-28T20:11:49.000-0600 19205453 auth.info sshd-session[962]: Disconnected from user test 192.168.1.94 port 35262
    2025-03-28T20:11:54.296-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:11:54-0600 [19205453]# ./busybox syslogd -O - -n -Ius
    2025-03-28T20:11:58.332879-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:12:02.000000-0600 19205453 auth.info sshd-session[965]: Accepted publickey for test from 192.168.1.94 port 42812 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:12:02.000000-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:12:02.000000-0600 19205453 auth.info sshd-session[967]: Received disconnect from 192.168.1.94 port 42812:11: disconnected by user
    2025-03-28T20:12:02.000000-0600 19205453 auth.info sshd-session[967]: Disconnected from user test 192.168.1.94 port 42812
    2025-03-28T20:12:08.350903-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:12:08-0600 [19205453]# ./busybox syslogd -O - -n -I -u
    2025-03-29T02:12:18Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:12:21Z 19205453 auth.info sshd-session[970]: Accepted publickey for test from 192.168.1.94 port 59600 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:12:21Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:12:21Z 19205453 auth.info sshd-session[972]: Received disconnect from 192.168.1.94 port 59600:11: disconnected by user
    2025-03-29T02:12:21Z 19205453 auth.info sshd-session[972]: Disconnected from user test 192.168.1.94 port 59600
    2025-03-29T02:12:24Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:12:24-0600 [19205453]# ./busybox syslogd -O - -n -Is -u
    2025-03-29T02:12:27Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:12:30Z 19205453 auth.info sshd-session[975]: Accepted publickey for test from 192.168.1.94 port 49052 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:12:30Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:12:30Z 19205453 auth.info sshd-session[977]: Received disconnect from 192.168.1.94 port 49052:11: disconnected by user
    2025-03-29T02:12:30Z 19205453 auth.info sshd-session[977]: Disconnected from user test 192.168.1.94 port 49052
    2025-03-29T02:12:33Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:12:33-0600 [19205453]# ./busybox syslogd -O - -n -Ims -u
    2025-03-29T02:12:37.756Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:12:40.000Z 19205453 auth.info sshd-session[980]: Accepted publickey for test from 192.168.1.94 port 33894 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:12:40.000Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:12:40.000Z 19205453 auth.info sshd-session[982]: Received disconnect from 192.168.1.94 port 33894:11: disconnected by user
    2025-03-29T02:12:40.000Z 19205453 auth.info sshd-session[982]: Disconnected from user test 192.168.1.94 port 33894
    2025-03-29T02:13:06.782Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:13:06-0600 [19205453]# ./busybox syslogd -O - -n -Ius -u
    2025-03-29T02:13:09.593088Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:13:12.000000Z 19205453 auth.info sshd-session[986]: Accepted publickey for test from 192.168.1.94 port 49542 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:13:12.000000Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:13:12.000000Z 19205453 auth.info sshd-session[988]: Received disconnect from 192.168.1.94 port 49542:11: disconnected by user
    2025-03-29T02:13:12.000000Z 19205453 auth.info sshd-session[988]: Disconnected from user test 192.168.1.94 port 49542
    2025-03-29T02:13:12.000000Z 19205453 daemon.info connmand[529]: ntp: adjust (slew): +0.000051 sec
    2025-03-29T02:13:19.679452Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:13:19-0600 [19205453]# ./busybox syslogd -O - -n -t
    Mar 28 20:15:22.452 19205453 syslog.info syslogd started: BusyBox v1.36.1
    Mar 28 20:15:24.606 19205453 auth.info sshd-session[992]: Accepted publickey for test from 192.168.1.94 port 36734 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    Mar 28 20:15:24.682 19205453 user.info test[42]: busybox syslogd test.
    Mar 28 20:15:24.684 19205453 auth.info sshd-session[994]: Received disconnect from 192.168.1.94 port 36734:11: disconnected by user
    Mar 28 20:15:24.684 19205453 auth.info sshd-session[994]: Disconnected from user test 192.168.1.94 port 36734
    Mar 28 20:15:28.262 19205453 syslog.info syslogd exiting

    2025-03-28T20:15:28-0600 [19205453]# ./busybox syslogd -O - -n -t -u
    Mar 29 02:15:33.963 19205453 syslog.info syslogd started: BusyBox v1.36.1
    Mar 29 02:15:36.646 19205453 auth.info sshd-session[997]: Accepted publickey for test from 192.168.1.94 port 47486 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    Mar 29 02:15:36.719 19205453 user.info test[42]: busybox syslogd test.
    Mar 29 02:15:36.721 19205453 auth.info sshd-session[999]: Received disconnect from 192.168.1.94 port 47486:11: disconnected by user
    Mar 29 02:15:36.722 19205453 auth.info sshd-session[999]: Disconnected from user test 192.168.1.94 port 47486
    Mar 29 02:15:42.726 19205453 syslog.info syslogd exiting

    2025-03-28T20:15:42-0600 [19205453]# ./busybox syslogd -O - -n -t -I
    2025-03-28T20:15:44-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:15:47-0600 19205453 auth.info sshd-session[1002]: Accepted publickey for test from 192.168.1.94 port 40804 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:15:47-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:15:47-0600 19205453 auth.info sshd-session[1004]: Received disconnect from 192.168.1.94 port 40804:11: disconnected by user
    2025-03-28T20:15:47-0600 19205453 auth.info sshd-session[1004]: Disconnected from user test 192.168.1.94 port 40804
    2025-03-28T20:15:55-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:15:55-0600 [19205453]# ./busybox syslogd -O - -n -t -Is
    2025-03-28T20:15:58-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:16:00-0600 19205453 auth.info sshd-session[1007]: Accepted publickey for test from 192.168.1.94 port 59882 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:16:00-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:16:00-0600 19205453 auth.info sshd-session[1009]: Received disconnect from 192.168.1.94 port 59882:11: disconnected by user
    2025-03-28T20:16:00-0600 19205453 auth.info sshd-session[1009]: Disconnected from user test 192.168.1.94 port 59882
    2025-03-28T20:16:03-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:16:04-0600 [19205453]# ./busybox syslogd -O - -n -t -Ims
    2025-03-28T20:16:16.742-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:16:19.040-0600 19205453 auth.info sshd-session[1013]: Accepted publickey for test from 192.168.1.94 port 43856 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:16:19.115-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:16:19.119-0600 19205453 auth.info sshd-session[1015]: Received disconnect from 192.168.1.94 port 43856:11: disconnected by user
    2025-03-28T20:16:19.119-0600 19205453 auth.info sshd-session[1015]: Disconnected from user test 192.168.1.94 port 43856
    2025-03-28T20:16:25.382-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:16:25-0600 [19205453]# ./busybox syslogd -O - -n -t -Ius
    2025-03-28T20:16:27.542901-0600 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-28T20:16:29.717165-0600 19205453 auth.info sshd-session[1018]: Accepted publickey for test from 192.168.1.94 port 54902 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-28T20:16:29.792157-0600 19205453 user.info test[42]: busybox syslogd test.
    2025-03-28T20:16:29.794654-0600 19205453 auth.info sshd-session[1020]: Received disconnect from 192.168.1.94 port 54902:11: disconnected by user
    2025-03-28T20:16:29.795390-0600 19205453 auth.info sshd-session[1020]: Disconnected from user test 192.168.1.94 port 54902
    2025-03-28T20:16:31.518777-0600 19205453 syslog.info syslogd exiting

    2025-03-28T20:16:31-0600 [19205453]# ./busybox syslogd -O - -n -t -I -u
    2025-03-29T02:16:36Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:16:39Z 19205453 auth.info sshd-session[1023]: Accepted publickey for test from 192.168.1.94 port 37222 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:16:39Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:16:39Z 19205453 auth.info sshd-session[1025]: Received disconnect from 192.168.1.94 port 37222:11: disconnected by user
    2025-03-29T02:16:39Z 19205453 auth.info sshd-session[1025]: Disconnected from user test 192.168.1.94 port 37222
    2025-03-29T02:16:45Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:16:46-0600 [19205453]# ./busybox syslogd -O - -n -t -Is -u
    2025-03-29T02:16:47Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:16:49Z 19205453 auth.info sshd-session[1028]: Accepted publickey for test from 192.168.1.94 port 50590 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:16:49Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:16:49Z 19205453 auth.info sshd-session[1030]: Received disconnect from 192.168.1.94 port 50590:11: disconnected by user
    2025-03-29T02:16:49Z 19205453 auth.info sshd-session[1030]: Disconnected from user test 192.168.1.94 port 50590
    2025-03-29T02:16:59Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:16:59-0600 [19205453]# ./busybox syslogd -O - -n -t -Ims -u
    2025-03-29T02:16:59.792Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:17:03.189Z 19205453 auth.info sshd-session[1033]: Accepted publickey for test from 192.168.1.94 port 59012 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:17:03.263Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:17:03.267Z 19205453 auth.info sshd-session[1035]: Received disconnect from 192.168.1.94 port 59012:11: disconnected by user
    2025-03-29T02:17:03.267Z 19205453 auth.info sshd-session[1035]: Disconnected from user test 192.168.1.94 port 59012
    2025-03-29T02:17:11.750Z 19205453 syslog.info syslogd exiting

    2025-03-28T20:17:11-0600 [19205453]# ./busybox syslogd -O - -n -t -Ius -u
    2025-03-29T02:17:13.063079Z 19205453 syslog.info syslogd started: BusyBox v1.36.1
    2025-03-29T02:17:15.512774Z 19205453 auth.info sshd-session[1038]: Accepted publickey for test from 192.168.1.94 port 34840 ssh2: RSA SHA256:hvjEhxYOZchXOw6JKONWGR0Aei/02ef3bSvt5UF6/SE
    2025-03-29T02:17:15.592759Z 19205453 user.info test[42]: busybox syslogd test.
    2025-03-29T02:17:15.596451Z 19205453 auth.info sshd-session[1040]: Received disconnect from 192.168.1.94 port 34840:11: disconnected by user
    2025-03-29T02:17:15.596526Z 19205453 auth.info sshd-session[1040]: Disconnected from user test 192.168.1.94 port 34840
    2025-03-29T02:17:18.254941Z 19205453 syslog.info syslogd exiting

Grant Erickson (3):
  syslogd: Use a local to track whether a message has a timestamp.
  syslogd: Unify messages with client timestamps when both PRECISE and
    UTC are enabled.
  syslogd: Add a configurable option to log timestamps in ISO 8601
    format

 sysklogd/syslogd.c | 292 ++++++++++++++++++++++++++++++++-------------
 1 file changed, 206 insertions(+), 86 deletions(-)

-- 
2.45.0