Skip to content

gethrtime and the real time of day

July 24, 2009

Seeing Katsumi Inoue blogging about Oracle 10g reporting timestamps using the output from gethrtime() reminded me that I have had on occasion wished I had a log to map hrtime to the current time. As Katsumi points out the output of gethrtime() is not absolutely tied to the current time. So there is no way to take the output from it and tell when in real time the output was generated unless you have some reference point. To make things more complex the output is reset each time the system reboots.

For this reason it is useful to keep a file that contains a history of the hrtime and the real time so that any logs can be retrospectively coerced back into a readable format.

There are lots of ways to do this but since on this blog we seem to be in Dtrace mode here is how using dtrace

pfexec /usr/sbin/dtrace -o /var/log/hrtime.log -qn ‘BEGIN,tick-1hour,END { printf("%d:%d.%9.9d:%Y\n",         timestamp, walltimestamp/1000000000,         walltimestamp%1000000000, walltimestamp); }’ 


Then you get a nice file that contains three columns. The hrtime, the time in seconds since January 1st 1970 and a human readable representation of the time in the current timezone:

: s4u-10-gmp03.eu TS 39 $; cat /var/log/hrtime.log     5638545510919736:1248443226.350000625:2009 Jul 24 14:47:06 5642145449325180:1248446826.279995332:2009 Jul 24 15:47:06 

I have to confess however that using Dtrace for this does not feel right, not least as you need to be root for this to be reliable and also the C code is trivial to write, compile and run from cron and send the output to syslog:

: exdev.eu FSS 39 $; cat  ./gethrtime_base.c #include <sys/time.h> #include <stdio.h>  int main(int argc, char **argv) { 	hrtime_t hrt = gethrtime(); 	struct timeval tv; 	gettimeofday(&tv, NULL);  	printf("%lld:%d.%6.6d:%s", hrt, tv.tv_sec, tv.tv_usec, 			ctime(&tv.tv_sec)); } : exdev.eu FSS 40 $; make ./gethrtime_base cc    -o gethrtime_base gethrtime_base.c  : exdev.eu FSS 41 $;  ./gethrtime_base 11013365852133078:1248444379.163215:Fri Jul 24 15:06:19 2009 : exdev.eu FSS 42 $;  ./gethrtime_base | logger -p daemon.notice -t hrtime : exdev.eu FSS 43 $;  tail -10 /var/adm/messages | grep hrtime Jul 24 15:32:33 exdev hrtime: [ID 702911 daemon.notice] 11014939896174861:1248445953.109855:Fri Jul 24 15:32:33 2009 Jul 24 16:09:21 exdev hrtime: [ID 702911 daemon.notice] 11017148054584749:1248448161.131675:Fri Jul 24 16:09:21 2009 : exdev.eu FSS 50 $;  

Advertisements

From → Solaris

3 Comments
  1. Thanks, my fellow fixie rider(I used to ride one, known as keirin bikes in Japan).
    I know somebody will write this small program someday. At least, it will tell how much your system clock drifts.

  2. Thanks, my fellow fixie rider(I used to ride one, known as keirin bikes in Japan).
    I know somebody will write this small program someday. At least, it will tell how much your system clock drifts.

  3. Thanks, my fellow fixie rider(I used to ride one, known as keirin bikes in Japan).
    I know somebody will write this small program someday. At least, it will tell how much your system clock drifts.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: