Bug 4648

Summary: klogd: timestamps are incorrect around suspend
Product: Other Reporter: Toralf Förster (toralf.foerster)
Component: OtherAssignee: other_other
Status: REJECTED WILL_NOT_FIX    
Severity: low CC: john.stultz, pavel
Priority: P2    
Hardware: i386   
OS: Linux   
Kernel Version: 2.6.12 Subsystem:
Regression: --- Bisected commit-id:

Description Toralf Förster 2005-05-21 07:19:23 UTC 
Distribution: Gentoo
Hardware Environment: Thinkpad T41
Software Environment: straight Linux installation
Problem Description:During suspend and resume some logging entries got the wrong
timestamp. As you can see in the dump below the lines '... Stopping tasks ...'
and '... Back to C! ...' should have a timestamp around 15:40:01 but they have
the timestamp 16:07:36 of the systems it waked up. BTW I use syslog-ng but I
think it is related to klogd because I observed the same problem using syslog.


Steps to reproduce:

n22 ~ # tail -n 60 /var/log/messages | head -n 8
May 21 15:40:01 n22 cron[16939]: (root) CMD (test -x /usr/sbin/run-crons &&
/usr/sbin/run-crons )
May 21 16:07:36 n22 Stopping tasks:
==========================================================================|
May 21 16:07:36 n22 radeonfb (0000:01:00.0): suspending to state: 3...
May 21 16:07:36 n22 Back to C!
May 21 16:07:36 n22 Warning: CPU frequency is 1700000, cpufreq assumed 600000 kHz.
May 21 16:07:36 n22 PCI: Setting latency timer of device 0000:00:1d.0 to 64
Comment 1 Toralf Förster 2005-09-09 01:34:28 UTC 
As described in https://bugs.gentoo.org/show_bug.cgi?id=104829#c1 the logger
should get a chance to log the message bofore the system really shuts off, isn't
it ?
Comment 2 john stultz 2005-10-03 15:51:48 UTC 
Pavel, do you have any ideas on this one?

Also, I'd probably change the summary to "timestamps are incorrect around
suspend" for clarity.
Comment 3 Pavel Machek 2005-10-04 03:37:21 UTC 
Seems to me as it "works as designed".

dmesg buffer is not timestamped, so klogd adds its own stamps. That means that
timestamp for "Freezing processes" is wrong, because it is done before suspend
but logger can only see it after suspend....

....but that's nothing we can fix.