Untrusted kernel messages timestamp sub-second faking doesn't work

[opty77]

https://github.com/troglobit/sysklogd/commit/1e9f164198c527f123ede182883d3e6c29b27e2c should have brought untrusted kernel messages timestamp sub-second faking but it doesn't seem so:

2023-06-18T09:52:32.924290+02:00 qeporkak syslogd 822 - - syslogd v2.5.0: restart.
[mostly kernel messages]
2023-06-18T09:52:31.246848+02:00 qeporkak kernel - - - In-situ OAM (IOAM) with IPv6
2023-06-18T09:52:33.000705+02:00 qeporkak rc.syslog 810 - - syslogd[822] v2.5.0: restarted.
2023-06-18T09:52:34.479375+02:00 qeporkak rc.inet1 897 - - lo: configuring interface
2023-06-18T09:52:34.497160+02:00 qeporkak rc.inet1 897 - - eth0: configuring interface
2023-06-18T09:52:34.530470+02:00 qeporkak rc.inet1 897 - - eth0: setting IPv4 addresses
2023-06-18T09:52:34.000000+02:00 qeporkak kernel - - - Generic FE-GE Realtek PHY r8169-0-300:00: attached PHY driver (mii_bus:phy_addr=r8169-0-300:00, irq=MAC)
2023-06-18T09:52:34.000000+02:00 qeporkak kernel - - - r8169 0000:03:00.0 eth0: Link is Down

[opty77]

Unable to reproduce on 32-bit Slackware 15.0 using debugging instance.

[opty77]

Reproduced on 64-bit Slackware 15.0 using /usr/sbin/syslogd -dssF -f $CONF -p $SOCK -C $CACHE -P $PID -cc |& tee -a $OUT & and echo subseconds >> /dev/kmsg (for the completeness):

2023-06-20T18:06:00.431123+02:00 qeporkak syslogd 3462 - - syslogd v2.5.0: restart.
2023-06-20T18:10:00.000000+02:00 qeporkak kernel - - - subseconds
2023-06-20T18:12:40.721761+02:00 qeporkak syslogd 3462 - - exiting on signal 15

So either it depends on the bitness or this particular machine.

[opty77]

Reproduced on 64-bit Debian GNU/Linux 11.7 (Bullseye) in an LXC container.

[opty77]

-t works there, just for sure.

[opty77]

sysklogd-2_5_0-ustime-untrusted-syslogd_c.diff:

--- sysklogd-2.5.0/src/syslogd.c        2023-04-30 20:08:56.000000000 +0200
+++ sysklogd-2.5.0+uu/src/syslogd.c     2023-06-27 13:18:01.808434676 +0200
@@ -1404,7 +1404,9 @@
                                        tv.tv_sec  = time(NULL);
                                        tv.tv_usec = 0;
                                }
-                               ustime = tv.tv_usec * 1000000;
+                               /* Useless? */
+                               /* ustime = tv.tv_sec * 1000000 + tv.tv_usec; */
+                               ustime = tv.tv_usec;
                        }

                        localtime_r(&now, &buffer.timestamp.tm);

Seems to work.

[troglobit]

Yeah, you're right, this should do the trick. Thank you for tracking it down!

-                               ustime = tv.tv_usec * 1000000;
+                               ustime = tv.tv_usec;

[troglobit]

There, merged to master. Will be in the v2.5.0 release, which I honestly have no timeline for yet, but should be out at the end of the summer (when I have vacation :)

[opty77]

2.5.1?

[troglobit]

Ouch, yeah you're right. I meant v2.5.1 ... too many projects queued up so I'm mixing them up.