after suspend-resume, dmesg printk times look as if suspend happened exactly before resume?!

Question

Please help me understand this quirk:

sudo pm-suspend, wait 5 minutes, wake up the machine, dmesg:

...
  [  817.724316] PM: Entering mem sleep
...
  [  820.380646] ACPI: Waking up from system sleep state S3

The printk seconds are obviously wrong! I've waited much more than 4 seconds between suspending and resuming... what gives?

(used ocelot 11.10, kernel is 3.0.0-12-generic)

Answer 1

Well the timing is the system up-time. During suspend the system is not up, the counter is not incremented anymore. The reason for the 4 seconds is the time for suspending after the first message poped out and for waking, before the second message is printed. Thus this is normal.