I'm running 2.0.0, and the docs say that The sender can specify the timezone of the messages. If the incoming message includes a timezone it is associated with the message. Otherwise, the local timezone is assumed. I'm not specifying any timezone, but I'm seeing a bunch of messages stamped UTC mixed in with EDT, which makes the log a bit... weird: Jun 24 21:38:01 tolstoy.denmantire.com sshd[7949]: Connection closed by 192.168 Jun 24 17:40:01 tolstoy.denmantire.com crond[7987]: (root) CMD (/usr/lib/sa/sa1 Jun 24 21:43:01 tolstoy.denmantire.com sshd[7994]: Connection closed by 192.168 Jun 24 17:44:34 tolstoy.denmantire.com syslog-ng[11618]: Log statistics; droppe Jun 24 21:48:02 tolstoy.denmantire.com sshd[8036]: Connection closed by 192.168 Jun 24 17:50:01 tolstoy.denmantire.com crond[8082]: (root) CMD (/usr/lib/sa/sa1 Jun 24 21:53:03 tolstoy.denmantire.com sshd[8107]: Connection closed by 192.168 So just to test, I did this: TZ="UTC+23:56" logger "Look I'm logging from yesterday" and sure enough, it logged it as yesterday. So I tried to explicitly set the time zones: options { send_time_zone(-04:00); recv_time_zone(-04:00); destination dtolstoy_all { file("/var/log/tolstoy.log" owner(root) group(hobbit) perm(0640) time_zone(-04:00)); Restarted syslog-ng, and: Jun 24 17:09:00 tolstoy.denmantire.com syslog-ng: syslog-ng startup succeeded Jun 23 21:13:09 tolstoy.denmantire.com tim: Look I'm logging from yesterday I don't understand why it's not logging as local time without me having to do anything. And I _really_ don't understand why the explicit instructions don't work. Pounters in the the right direction appreciated... -- Tim Boyer Director Information Systems and Engineering Projects Denman Tire Corporation tim@denmantire.com
In your log snippet, it appears that it is sshd that is logging with the "wrong" timezone. This is a bug in some versions of sshd. Upgrading sshd may fix the specific problem you are having. I can not comment on the behavior of the timezone handling in syslog-ng. Evan Rempel Tim Boyer wrote:
I'm running 2.0.0, and the docs say that
The sender can specify the timezone of the messages. If the incoming message includes a timezone it is associated with the message. Otherwise, the local timezone is assumed.
I'm not specifying any timezone, but I'm seeing a bunch of messages stamped UTC mixed in with EDT, which makes the log a bit... weird:
Jun 24 21:38:01 tolstoy.denmantire.com sshd[7949]: Connection closed by 192.168 Jun 24 17:40:01 tolstoy.denmantire.com crond[7987]: (root) CMD (/usr/lib/sa/sa1 Jun 24 21:43:01 tolstoy.denmantire.com sshd[7994]: Connection closed by 192.168 Jun 24 17:44:34 tolstoy.denmantire.com syslog-ng[11618]: Log statistics; droppe Jun 24 21:48:02 tolstoy.denmantire.com sshd[8036]: Connection closed by 192.168 Jun 24 17:50:01 tolstoy.denmantire.com crond[8082]: (root) CMD (/usr/lib/sa/sa1 Jun 24 21:53:03 tolstoy.denmantire.com sshd[8107]: Connection closed by 192.168
So just to test, I did this:
TZ="UTC+23:56" logger "Look I'm logging from yesterday"
and sure enough, it logged it as yesterday.
So I tried to explicitly set the time zones:
options { send_time_zone(-04:00); recv_time_zone(-04:00);
destination dtolstoy_all { file("/var/log/tolstoy.log" owner(root) group(hobbit) perm(0640) time_zone(-04:00));
Restarted syslog-ng, and:
Jun 24 17:09:00 tolstoy.denmantire.com syslog-ng: syslog-ng startup succeeded Jun 23 21:13:09 tolstoy.denmantire.com tim: Look I'm logging from yesterday
I don't understand why it's not logging as local time without me having to do anything. And I _really_ don't understand why the explicit instructions don't work.
Pounters in the the right direction appreciated...
On Sun, 2007-06-24 at 18:13 -0400, Tim Boyer wrote:
I'm running 2.0.0, and the docs say that
The sender can specify the timezone of the messages. If the incoming message includes a timezone it is associated with the message. Otherwise, the local timezone is assumed.
I'm not specifying any timezone, but I'm seeing a bunch of messages stamped UTC mixed in with EDT, which makes the log a bit... weird:
Jun 24 21:38:01 tolstoy.denmantire.com sshd[7949]: Connection closed by 192.168 Jun 24 17:40:01 tolstoy.denmantire.com crond[7987]: (root) CMD (/usr/lib/sa/sa1 Jun 24 21:43:01 tolstoy.denmantire.com sshd[7994]: Connection closed by 192.168 Jun 24 17:44:34 tolstoy.denmantire.com syslog-ng[11618]: Log statistics; droppe Jun 24 21:48:02 tolstoy.denmantire.com sshd[8036]: Connection closed by 192.168 Jun 24 17:50:01 tolstoy.denmantire.com crond[8082]: (root) CMD (/usr/lib/sa/sa1 Jun 24 21:53:03 tolstoy.denmantire.com sshd[8107]: Connection closed by 192.168
This is probably an SSHD bug as someone else already pointed out.
So just to test, I did this:
TZ="UTC+23:56" logger "Look I'm logging from yesterday"
and sure enough, it logged it as yesterday.
Yes, that message still did not contain a timezone, as logger does not send it. Specifying the local timezone for logger only changed it the timestamp as it was sent to syslog-ng.
So I tried to explicitly set the time zones:
options { send_time_zone(-04:00); recv_time_zone(-04:00);
destination dtolstoy_all { file("/var/log/tolstoy.log" owner(root) group(hobbit) perm(0640) time_zone(-04:00));
Restarted syslog-ng, and:
Jun 24 17:09:00 tolstoy.denmantire.com syslog-ng: syslog-ng startup succeeded Jun 23 21:13:09 tolstoy.denmantire.com tim: Look I'm logging from yesterday
The timezone conversions that you specified (all incoming messages treated as -04:00 and then converted to -04:00 as written out), is a noop.
I don't understand why it's not logging as local time without me having to do anything. And I _really_ don't understand why the explicit instructions don't work.
Pounters in the the right direction appreciated...
When an incoming message specifies a timezone (which logger will not do by itself), syslog-ng uses that information to convert the time to UTC (e.g. GMT+0). If the message does not contain such information in the first place, it will _assume_ that it comes from the local timezone. The explicit timezone instructions only change this assumption. If a program generates messages using an incorrect timezone (e.g. ssh, or in the case above logger), and it does _NOT_ include this timezone information in the message (which the legacy syslog protocol cannot do), then syslog-ng has no means to do anything without further information. What you can do however, is to force sshd to log to a different socket instead of /dev/log and associate a different recv_time_zone() to the source handling this different socket. This is not easy, as there's no means to override the /dev/log socket when using the syslog functions from libc (which sshd does). So the easiest fix is to fix sshd. -- Bazsi
The timezone conversions that you specified (all incoming messages treated as -04:00 and then converted to -04:00 as written out), is a noop.
I don't understand why it's not logging as local time
without me having to
do anything. And I _really_ don't understand why the explicit instructions don't work.
Pounters in the the right direction appreciated...
When an incoming message specifies a timezone (which logger will not do by itself), syslog-ng uses that information to convert the time to UTC (e.g. GMT+0). If the message does not contain such information in the first place, it will _assume_ that it comes from the local timezone. The explicit timezone instructions only change this assumption.
If a program generates messages using an incorrect timezone (e.g. ssh, or in the case above logger), and it does _NOT_ include this timezone information in the message (which the legacy syslog protocol cannot do), then syslog-ng has no means to do anything without further information. What you can do however, is to force sshd to log to a different socket instead of /dev/log and associate a different recv_time_zone() to the source handling this different socket. This is not easy, as there's no means to override the /dev/log socket when using the syslog functions from libc (which sshd does).
So the easiest fix is to fix sshd.
I'll get right on that... :) Seriously, thanks for the detailed explanation - I know what's happening now, at least. It's Red Hat RHEL5, so it's as up-to-date as I'm going to get, but I'll at least let them know it's a problem. -- Tim Boyer Director IT and Engineering Projects Denman Tire Corporation
We had a weird problem last week when trying to roll in syslog-ng 2.0.2 over syslogd on SLES 9.3 running on IBM pSeries (PPC). Sorry this is not directly syslog-ng (or is it?), but I'm hoping that someone on this list was in a similar situation or can shed some light. I did what I could tell was the right thing, which was to disable klogd (and syslogd) before using syslog-ng, and my source looks something like this: file ("/proc/kmsg" log_prefix("kernel: ")); unix-stream ("/dev/log" max-connections(70)); When in place, syslog-ng seems to perform fine - it seemed to pick up all facilities and levels per initial testing. However, the machine then promptly hung. Or, rather, I found that all susefirewall packet messages (kernel, SFW2)) started going to console, in addition to file. I don't have any console destinations per se since these are headless, so I don't know exactly why messages would go to console when they should be going through /proc/kmsg (and thus syslog-ng), correct? Thanks for any pointers! Ian
On Tue, 2007-06-26 at 08:26 -0700, Ian Veach wrote:
We had a weird problem last week when trying to roll in syslog-ng 2.0.2 over syslogd on SLES 9.3 running on IBM pSeries (PPC). Sorry this is not directly syslog-ng (or is it?), but I'm hoping that someone on this list was in a similar situation or can shed some light.
I did what I could tell was the right thing, which was to disable klogd (and syslogd) before using syslog-ng, and my source looks something like this: file ("/proc/kmsg" log_prefix("kernel: ")); unix-stream ("/dev/log" max-connections(70));
When in place, syslog-ng seems to perform fine - it seemed to pick up all facilities and levels per initial testing. However, the machine then promptly hung. Or, rather, I found that all susefirewall packet messages (kernel, SFW2)) started going to console, in addition to file. I don't have any console destinations per se since these are headless, so I don't know exactly why messages would go to console when they should be going through /proc/kmsg (and thus syslog-ng), correct?
set the kernel's console log level. this is done by klogd but not syslog-ng automatically. something like "dmesg -n4" should help. -- Bazsi
On Tue, Jun 26, 2007 at 05:56:23PM +0200, Balazs Scheidler wrote:
When in place, syslog-ng seems to perform fine - it seemed to pick up all facilities and levels per initial testing. However, the machine then promptly hung. Or, rather, I found that all susefirewall packet messages (kernel, SFW2)) started going to console, in addition to file. I don't have any console destinations per se since these are headless, so I don't know exactly why messages would go to console when they should be going through /proc/kmsg (and thus syslog-ng), correct?
set the kernel's console log level. this is done by klogd but not syslog-ng automatically.
something like "dmesg -n4" should help.
Now documented in the FAQ: http://www.campin.net/syslog-ng/faq.html#klogd -- Nate Yea, tho I walk thru the valley of the shadow of clues, I shall fear no luser, for Thou lart with me, Thy chicken and Thy manual, they comfort me.
Awesome. Thanks Balazs and Nate! That sounds like it will work perfectly (we'll use -n 1, since we aren't on console and they are frame buffered anyway), and I'll try it tommorow morning! ivo Nate Campi wrote:
On Tue, Jun 26, 2007 at 05:56:23PM +0200, Balazs Scheidler wrote:
When in place, syslog-ng seems to perform fine - it seemed to pick up all facilities and levels per initial testing. However, the machine then promptly hung. Or, rather, I found that all susefirewall packet messages (kernel, SFW2)) started going to console, in addition to file. I don't have any console destinations per se since these are headless, so I don't know exactly why messages would go to console when they should be going through /proc/kmsg (and thus syslog-ng), correct?
set the kernel's console log level. this is done by klogd but not syslog-ng automatically.
something like "dmesg -n4" should help.
Now documented in the FAQ:
On Tue, 2007-06-26 at 10:49 -0400, Tim Boyer wrote:
...
So the easiest fix is to fix sshd.
I'll get right on that... :)
Seriously, thanks for the detailed explanation - I know what's happening now, at least. It's Red Hat RHEL5, so it's as up-to-date as I'm going to get, but I'll at least let them know it's a problem.
Hi, this is a know problem due to the chrooted sshd and the missing /etc/localtime in the the chroot under /var/empty/sshd. Check http://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=193184 for the discussion and a workaround. Running a couple of CentOS 4 and 5 systems here, the small script section from the bugzilla solved the time problem from the sshd logs for all of them. hope that helps. -- Jens Grigel Citysavingsbank Munich, Germany Dept. of Network/Security
So the easiest fix is to fix sshd.
I'll get right on that... :)
Seriously, thanks for the detailed explanation - I know what's happening now, at least. It's Red Hat RHEL5, so it's as up-to-date as I'm going to get, but I'll at least let them know it's a problem.
Hi,
this is a know problem due to the chrooted sshd and the missing /etc/localtime in the the chroot under /var/empty/sshd.
Check http://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=193184 for the discussion and a workaround.
Running a couple of CentOS 4 and 5 systems here, the small script section from the bugzilla solved the time problem from the sshd logs for all of them.
hope that helps.
Jens, that's a _huge_ help. Thanks very much! -- Tim Boyer Director Information Systems and Engineering Projects Denman Tire Corporation tim@denmantire.com
participants (6)
-
Balazs Scheidler
-
Evan Rempel
-
Ian Veach
-
Jens Grigel
-
Nate Campi
-
Tim Boyer