Multiple timezone seen on messages originating from local machine
I'm trying to understand timezones in syslog-ng, but I think there's something I'm missing. If I do the following on my OpenWRT machine: /etc/init.d/syslog-ng restart logger TestA I see the following in /var/log/messages: Aug 14 20:39:35 hostname syslog-ng[9860]: syslog-ng shutting down; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: syslog-ng starting up; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: Syslog connection established; fd='15', server='AF_INET(192.168.1.10:514)', local='AF_INET(0.0.0.0:0)' Aug 15 03:39:49 hostname root: TestA The correct timezone is the one in the first three lines. Other daemon messages are displayed using the incorrect timezone like `logger`. I've attached my syslog-ng.conf file. So my question is why is the time information correct in the first three messages and then incorrect from there on? Francois -- https://fmarier.org/
On /dev/log (the usual means of submitting messages) the timestamp is formatted by the syslog() function call, part of libc (probably musl in the case of openwrt). Libc uses /etc/localtime to query the local time zone. On Mon, Aug 15, 2022, 05:56 Francois Marier <francois@fmarier.org> wrote:
I'm trying to understand timezones in syslog-ng, but I think there's something I'm missing.
If I do the following on my OpenWRT machine:
/etc/init.d/syslog-ng restart logger TestA
I see the following in /var/log/messages:
Aug 14 20:39:35 hostname syslog-ng[9860]: syslog-ng shutting down; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: syslog-ng starting up; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: Syslog connection established; fd='15', server='AF_INET(192.168.1.10:514)', local='AF_INET( 0.0.0.0:0)' Aug 15 03:39:49 hostname root: TestA
The correct timezone is the one in the first three lines. Other daemon messages are displayed using the incorrect timezone like `logger`.
I've attached my syslog-ng.conf file.
So my question is why is the time information correct in the first three messages and then incorrect from there on?
Francois
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq
As best as I can determine, there is a time zone problem associated with how the messages are generated through some of the channels. https://forum.openwrt.org/t/syslog-ng-timezone-issues/48130 https://forum.openwrt.org/t/utc-timezones-used-for-apps-in-syslog-ng-instead... https://github.com/openwrt/packages/issues/18633 https://gitlab.nic.cz/turris/os/packages/-/issues/471 Changing how /dev/log is interpreted may either hide or resolve the issue, depending on your perspective: source s_devlog { unix-dgram("/dev/log", keep-timestamp(no)); }; Jeff On 8/14/22 8:56 PM, Francois Marier wrote:
I'm trying to understand timezones in syslog-ng, but I think there's something I'm missing.
If I do the following on my OpenWRT machine:
/etc/init.d/syslog-ng restart logger TestA
I see the following in /var/log/messages:
Aug 14 20:39:35 hostname syslog-ng[9860]: syslog-ng shutting down; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: syslog-ng starting up; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: Syslog connection established; fd='15', server='AF_INET(192.168.1.10:514)', local='AF_INET(0.0.0.0:0)' Aug 15 03:39:49 hostname root: TestA
The correct timezone is the one in the first three lines. Other daemon messages are displayed using the incorrect timezone like `logger`.
I've attached my syslog-ng.conf file.
So my question is why is the time information correct in the first three messages and then incorrect from there on?
Francois
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq
Hi, Strange indeed. To solve this the logging application and syslog-ng needs to agree on the time-zone being used. syslog-ng uses the system time-zone by default but it can be overridden using the time-zone() option of the unix-dgram() source driver. The applications should also use the system time-zone. Here it's usually the libc (glibc or musl) that generates the timestamp. More specifically the syslog() function. It might happen that: * Some applications bypass the libc api and send its messages directly (util-linux logger does this for instance) * If an application has its own implementation, it may or may not use the system time-zone properly. To debug the problem, try to get access to the raw log data as received by syslog-ng. * It displays the incoming message on the debug level * You could strace the sending app * You could tell syslog-ng to store $RAWMSG using flags(store-raw-message) and then look at its value by using a destination that you use for debugging. In any case, once you recognize what sends the incorrect time-zone, you can probably find a reason why it sends it incorrectly. If you just want to solve this quickly, use keep-timestamp(no), that way syslog-ng will overwrite the message timestamp with the reception time, and that with correct time-zone. As a second alternative, you could use the pretty recent flags(guess-timezone) flag which uses a heuristic to fix up the time-zone, assuming the time between sending and receiving the message is less than 30 seconds. Bazsi On Mon, Aug 15, 2022, 18:31 Jeff Kletsky <syslogng@allycomm.com> wrote:
As best as I can determine, there is a time zone problem associated with how the messages are generated through some of the channels.
https://forum.openwrt.org/t/syslog-ng-timezone-issues/48130
https://forum.openwrt.org/t/utc-timezones-used-for-apps-in-syslog-ng-instead...
https://github.com/openwrt/packages/issues/18633
https://gitlab.nic.cz/turris/os/packages/-/issues/471
Changing how /dev/log is interpreted may either hide or resolve the issue, depending on your perspective:
source s_devlog { unix-dgram("/dev/log", keep-timestamp(no)); };
Jeff
On 8/14/22 8:56 PM, Francois Marier wrote:
I'm trying to understand timezones in syslog-ng, but I think there's something I'm missing.
If I do the following on my OpenWRT machine:
/etc/init.d/syslog-ng restart logger TestA
I see the following in /var/log/messages:
Aug 14 20:39:35 hostname syslog-ng[9860]: syslog-ng shutting down; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: syslog-ng starting up; version='3.37.1' Aug 14 20:39:36 hostname syslog-ng[10024]: Syslog connection established; fd='15', server='AF_INET(192.168.1.10:514)', local='AF_INET( 0.0.0.0:0)' Aug 15 03:39:49 hostname root: TestA
The correct timezone is the one in the first three lines. Other daemon messages are displayed using the incorrect timezone like `logger`.
I've attached my syslog-ng.conf file.
So my question is why is the time information correct in the first three messages and then incorrect from there on?
Francois
______________________________________________________________________________
Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq
Thank you so much Jeff and Balazs! I had not realized that this could simply be an upstream OpenWRT bug (that Turris bug tracker link was very helpful). The `keep-timestamp(no)` work-around sounds perfect since (1) these are all local messages and (2) Turris claims that it has been fixed upstream and so it should eventually arrive on my router, which is in fact a Turris Omnia. I've updated my remote logging blog post [1] to include this work-around. Francois [1] https://feeding.cloud.geek.nz/posts/remote-logging-turris-omnia-router/ -- https://fmarier.org/
participants (3)
-
Balazs Scheidler
-
Francois Marier
-
Jeff Kletsky