2002-01-04 20:09:13

by Chris Friesen

[permalink] [raw]
Subject: kernel log messages using wrong timezone


How does the kernel figure out how to timestamp the log output? The reason I'm
asking is that we have a system that has /etc/localtime pointing to the
Americas/Montreal timezone, but the log output from the kernel appears to be
UTC.

Can anyone point me to the right place to deal with this?

Thanks,

Chris

--
Chris Friesen | MailStop: 043/33/F10
Nortel Networks | work: (613) 765-0557
3500 Carling Avenue | fax: (613) 765-2986
Nepean, ON K2H 8E9 Canada | email: [email protected]


2002-01-04 20:52:04

by Andreas Dilger

[permalink] [raw]
Subject: Re: kernel log messages using wrong timezone

On Jan 04, 2002 15:14 -0500, Chris Friesen wrote:
> How does the kernel figure out how to timestamp the log output?
> The reason I'm asking is that we have a system that has /etc/localtime
> pointing to the Americas/Montreal timezone, but the log output from the
> kernel appears to be UTC.

The kernel doesn't timestamp the logs, AFAIK. That is done by syslog when
it writes the logs to disk. If you check "dmesg" output - no timestamps.

> Can anyone point me to the right place to deal with this?

Restart syslog so that it notices the new timezone, or something else, I
don't know. IIRC, you are the one doing strange things with syslog.
Are you doing network syslog logging now? Are both of your hosts running
with the same timezone?

Cheers, Andreas
--
Andreas Dilger
http://sourceforge.net/projects/ext2resize/
http://www-mddsp.enel.ucalgary.ca/People/adilger/

2002-01-04 21:07:35

by Chris Friesen

[permalink] [raw]
Subject: Re: kernel log messages using wrong timezone

Andreas Dilger wrote:
>
> On Jan 04, 2002 15:14 -0500, Chris Friesen wrote:
> > How does the kernel figure out how to timestamp the log output?
> > The reason I'm asking is that we have a system that has /etc/localtime
> > pointing to the Americas/Montreal timezone, but the log output from the
> > kernel appears to be UTC.
>
> The kernel doesn't timestamp the logs, AFAIK. That is done by syslog when
> it writes the logs to disk. If you check "dmesg" output - no timestamps.

Hmm...good point. However, I should clarify that userspace logs are being
corrected for timezone, but kernel logs are not. For userspace apps the
timestamping is done in the glibc syslog() call, so now I need to figure out
where it's done for the kernel.

> > Can anyone point me to the right place to deal with this?
>
> Restart syslog so that it notices the new timezone, or something else, I
> don't know. IIRC, you are the one doing strange things with syslog.
> Are you doing network syslog logging now? Are both of your hosts running
> with the same timezone?

I always was logging remotely, but we wanted to log to NFS-mounted files as well
without hanging the userspace apps when NFS borked.

What I ended up doing was to fork syslog and set up a sysV message queue between
the parent and child. The child does all writing to the NFS-mounted
filesystem. Thus, if NFS dies for whatever reason the child blocks and the
parent just dumps messages into the queue. Eventually (1024 messages or 16KB of
data) the queue fills up and we start to lose messages (the parent uses
non-blocking writes), but in practice we don't hit the limit before NFS is
regained.

Chris


--
Chris Friesen | MailStop: 043/33/F10
Nortel Networks | work: (613) 765-0557
3500 Carling Avenue | fax: (613) 765-2986
Nepean, ON K2H 8E9 Canada | email: [email protected]

2002-01-04 21:42:32

by Chris Friesen

[permalink] [raw]
Subject: Re: kernel log messages using wrong timezone -- solved

"Friesen, Christopher [CAR:3R60:EXCH]" wrote:
>
> How does the kernel figure out how to timestamp the log output? The reason I'm
> asking is that we have a system that has /etc/localtime pointing to the
> Americas/Montreal timezone, but the log output from the kernel appears to be
> UTC.

Well, it turns out that klogd was the culprit. We were booting a ramdisk,
setting the time, starting syslog, and then setting the timezone from an
NFS-mounted file. klogd checks the timezone on startup only, so changing the
timezone did not affect the output of klogd. Guess we'll have to restart syslog
after setting the timezone.

Thanks to those who responded.

Chris


--
Chris Friesen | MailStop: 043/33/F10
Nortel Networks | work: (613) 765-0557
3500 Carling Avenue | fax: (613) 765-2986
Nepean, ON K2H 8E9 Canada | email: [email protected]

2002-01-04 21:57:52

by Andreas Dilger

[permalink] [raw]
Subject: Re: kernel log messages using wrong timezone

On Jan 04, 2002 16:12 -0500, Chris Friesen wrote:
> Andreas Dilger wrote:
> > On Jan 04, 2002 15:14 -0500, Chris Friesen wrote:
> > > How does the kernel figure out how to timestamp the log output?
> > > The reason I'm asking is that we have a system that has /etc/localtime
> > > pointing to the Americas/Montreal timezone, but the log output from the
> > > kernel appears to be UTC.
> >
> > The kernel doesn't timestamp the logs, AFAIK. That is done by syslog when
> > it writes the logs to disk. If you check "dmesg" output - no timestamps.
>
> Hmm...good point. However, I should clarify that userspace logs are being
> corrected for timezone, but kernel logs are not. For userspace apps the
> timestamping is done in the glibc syslog() call, so now I need to figure out
> where it's done for the kernel.

Well, on my system I have "syslogd" and "klogd" running. Kernel logs are
extracted from the kernel ringbuffer by klogd and passed to syslog, so that
would be the place to look.

Cheers, Andreas
--
Andreas Dilger
http://sourceforge.net/projects/ext2resize/
http://www-mddsp.enel.ucalgary.ca/People/adilger/

2002-01-05 00:28:04

by Alan

[permalink] [raw]
Subject: Re: kernel log messages using wrong timezone

> How does the kernel figure out how to timestamp the log output? The reason I'm
> asking is that we have a system that has /etc/localtime pointing to the
> Americas/Montreal timezone, but the log output from the kernel appears to be
> UTC.

The kernel doesn't timestamp, the logging daemon syslogd/klogd does. Now
if the daemon is running UTC because your distribution starts it before
setting the timezones up that might cause wrong zones