timestamping more precisely, merging logs

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

timestamping more precisely, merging logs

Jason Harris

For various reasons, I patched SKS to timestamp events more precisely.
To get output that includes microseconds:

  [db.log]
  2005-07-18 18:58:53 0.053317 Applying 2 changes
  2005-07-18 18:58:53 0.053352 Adding hash 0B2728A61F285C2273B542BC4014D679
  2005-07-18 18:58:53 0.053378 Del'ng hash 1F46050134AA477D17245DB63E044EBA
  2005-07-18 18:58:53 0.444974 Sending LogResp size 2

  [recon.log]
  2005-07-18 18:58:52 0.822811 1 keys received
  2005-07-18 18:58:53 0.655559 setting synctime to 1121713133.049091
  2005-07-18 18:58:53 0.655967 Added 2 hash-updates. Caught up to 1121713133.049091

and allows the db.log and recon.log entries to be intelligibly merged
together using sort(1):

  [recon event]
  2005-07-18 18:58:52 0.822811 1 keys received
  [db events, in their original order]
  2005-07-18 18:58:53 0.053317 Applying 2 changes
  2005-07-18 18:58:53 0.053352 Adding hash 0B2728A61F285C2273B542BC4014D679
  2005-07-18 18:58:53 0.053378 Del'ng hash 1F46050134AA477D17245DB63E044EBA
  2005-07-18 18:58:53 0.444974 Sending LogResp size 2
  [correctly followed by recon events, also in their original order]
  2005-07-18 18:58:53 0.655559 setting synctime to 1121713133.049091
  2005-07-18 18:58:53 0.655967 Added 2 hash-updates. Caught up to 1121713133.049
091

apply this patch:

--- orig/common.ml
+++ mod/common.ml
@@ -66,11 +66,13 @@
   kprintf (fun s ->
      if !Settings.debug && level  <= !Settings.debuglevel
      then  (
-       let tm = Unix.localtime (Unix.time ()) in
-       fprintf !logfile "%04d-%02d-%02d %02d:%02d:%02d "
+               let now = Unix.gettimeofday() in
+       let tm = Unix.localtime (now) in
+       let us = now -. floor now in
+       fprintf !logfile "%04d-%02d-%02d %02d:%02d:%02d %0.6f "
  (tm.Unix.tm_year + 1900) (tm.Unix.tm_mon + 1)
  tm.Unix.tm_mday (* date *)
- tm.Unix.tm_hour tm.Unix.tm_min tm.Unix.tm_sec; (* time *)
+ tm.Unix.tm_hour tm.Unix.tm_min tm.Unix.tm_sec us; (* time *)
        output_string !logfile s;
        output_string !logfile "\n";
        flush !logfile;
@@ -103,11 +105,13 @@
   kprintf (fun s ->
      if !Settings.debug && level  <= !Settings.debuglevel
      then  (
-       let tm = Unix.localtime (Unix.time ()) in
-       fprintf !logfile "%04d-%02d-%02d %02d:%02d:%02d "
+               let now = Unix.gettimeofday() in
+       let tm = Unix.localtime (now) in
+       let us = now -. floor now in
+       fprintf !logfile "%04d-%02d-%02d %02d:%02d:%02d %0.6f "
  (tm.Unix.tm_year + 1900) (tm.Unix.tm_mon + 1)
  tm.Unix.tm_mday (* date *)
- tm.Unix.tm_hour tm.Unix.tm_min tm.Unix.tm_sec;
+ tm.Unix.tm_hour tm.Unix.tm_min tm.Unix.tm_sec us;
        output_string !logfile s;
        fprintf !logfile ": %s\n" (err_to_string e);
        flush !logfile;
--- orig/wserver.ml
+++ mod/wserver.ml
@@ -211,7 +211,7 @@
   let pieces = List.map ~f:(fun (x,y) -> sprintf "%s:%s" x y)
  (Map.to_alist map)
   in
-  "\n" ^ (String.concat "\n" pieces)
+  "+" ^ (String.concat "+" pieces)
 
 let request_to_string request =
   let (kind,req,headers) =

--
Jason Harris           |  NIC:  JH329, PGP:  This _is_ PGP-signed, isn't it?
[hidden email] _|_ web:  http://keyserver.kjsl.com/~jharris/
          Got photons?   (TM), (C) 2004

_______________________________________________
Sks-devel mailing list
[hidden email]
http://lists.nongnu.org/mailman/listinfo/sks-devel

attachment0 (322 bytes) Download Attachment