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
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 ?
Pavel, do you have any ideas on this one? Also, I'd probably change the summary to "timestamps are incorrect around suspend" for clarity.
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.