On Wed, 2009-02-25 at 20:47 -0500, Yaroslav Halchenko wrote: > My today reported (and reassigned to linux2.6) bug #517122 > doesn't gimme rest. One of the problem of analysis of traces is that > some times are recorded since epoch, some are the kernel's "uptime". > what puzzles me is: > > * Difference between dmesg timestamp and /proc/uptime > > $> tcpdump -i bond0 -tt -vvv -n "(dst host raider or src host raider)" -s 192 | head -3; dmesg | tail -1; echo "/proc/uptime"; cat /proc/uptime > ... > [250851.259481] device eth1 left promiscuous mode > /proc/uptime > 241764.70 224706.33 > > so I have timestamp in kernel messages bigger than uptime > > I wonder why is that? different clock source? any other drift? Different clock source. > or may be 'kernel time' in dmesg is some kind of tick, not time per se? It's a scheduler timestamp, which is an approximation to real time but due to internal requirements of the scheduler may run slightly fast. Timestamps in the kernel log help to show how close together events occurred, but nothing more. > * Is there an easy way to convert (reliably ;)) timestamp in dmesg to > time since epoch (with mksec precision of cause), so I could easily compare > with output in strace and alike. Not really, but you can get a scheduler timestamp from /proc/sched_debug which may help in correlating them. Ben.
Attachment:
signature.asc
Description: This is a digitally signed message part