Re: strange timestamp in dmesg

[Andi Kleen <andi@firstfloor.org>]

Andrew Morton <akpm@linux-foundation.org> writes:

>> supports DPO and FUA
>> [    9.801761] sd 1:0:1:0: [sdc] 143374744 512-byte hardware sectors (73408 MB)
>> [    9.673388] sd 1:0:1:0: [sdc] Write Protect is off
>> [    9.673395] sd 1:0:1:0: [sdc] Mode Sense: ab 00 10 08
>> [    9.806210] sd 1:0:1:0: [sdc] Write cache: enabled, read cache: enabled,
>> supports DPO and FUA
>> [    9.806220]  sdc: sdc1
>> [    9.682136] sd 1:0:1:0: [sdc] Attached SCSI disk
>> [   13.786405] SGI XFS with large block numbers, no debug enabled
>> [   13.633457] XFS mounting filesystem sdb2
>> [   13.724345] Starting XFS recovery on filesystem: sdb2 (logdev: internal)
>> [   14.251356] Ending XFS recovery on filesystem: sdb2 (logdev: internal)
>> [   15.379298] XFS mounting filesystem sdc1
>> [   15.468255] Starting XFS recovery on filesystem: sdc1 (logdev: internal)
>> [   14.514314] Ending XFS recovery on filesystem: sdc1 (logdev: internal)
>> [   14.767260] warning: `squid' uses 32-bit capabilities (legacy support in use)
>> [   17.589751] e1000: eth0: e1000_watchdog: NIC Link is Up 1000 Mbps Full
>> Duplex, Flow Control: RX/TX
>> 
>
> whoa, that's weird.  We've seen timestamps jump forward a single hop of
> ~100000 seconds, but that's all over the place.

No it's expected since printk uses sched_clock() and sched clock is not synchronous
between CPUs on systems without synchronized/invariant TSC (like Opteron)
All sched_clock() users are expected to handle it.

I always advocated just always using jiffies for printk. The only drawback would
be that it won't increase in interrupt off sections, but if you have
one that is longer than a jiffie then you have enough other problems.

-Andi