Make cygprofile use clock_gettime() instead of gettimeofday().

tools/cygprofile/mergetraces.py

 #!/usr/bin/python
 # Copyright 2013 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 # Use: ../mergetraces.py `ls cyglog.* -Sr` > merged_cyglog
 
 """"Merge multiple logs files from different processes into a single log.
 
 Given two log files of execution traces, merge the traces into a single trace.
 Merging will use timestamps (i.e. the first two columns of logged calls) to
 create a single log that is an ordered trace of calls by both processes.
 """
 
 import optparse
 import os
 import string
 import subprocess
 import sys
 
 def ParseLogLines(lines):
   """Parse log file lines.
 
   Args:
     lines: lines from log file produced by profiled run
 
     Below is an example of a small log file:
     5086e000-52e92000 r-xp 00000000 b3:02 51276      libchromeview.so
-    secs       msecs      pid:threadid    func
+    secs       usecs      pid:threadid    func
     START
     1314897086 795828     3587:1074648168 0x509e105c
     1314897086 795874     3587:1074648168 0x509e0eb4
     1314897086 796326     3587:1074648168 0x509e0e3c
     1314897086 796552     3587:1074648168 0x509e07bc
     END
 
   Returns:
     tuple conisiting of 1) an ordered list of the logged calls, as an array of
     fields, 2) the virtual start address of the library, used to compute the
@@ skipping 31 matching lines @@
       seen.append(call[3])
 
 def CheckTimestamps(calls):
   """Prints warning to stderr if the call timestamps are not in order.
 
   Args:
     calls: list of calls logged
   """
   index = 0
   last_timestamp_secs = -1
-  last_timestamp_ms = -1
+  last_timestamp_us = -1
   while (index < len (calls)):
     timestamp_secs = int (calls[index][0])
-    timestamp_ms = int (calls[index][1])
-    timestamp = (timestamp_secs * 1000000) + timestamp_ms
-    last_timestamp = (last_timestamp_secs * 1000000) + last_timestamp_ms
+    timestamp_us = int (calls[index][1])
+    timestamp = (timestamp_secs * 1000000) + timestamp_us
+    last_timestamp = (last_timestamp_secs * 1000000) + last_timestamp_us
     if (timestamp < last_timestamp):
-      sys.stderr.write("WARNING: last_timestamp: " + str(last_timestamp_secs)
-                       + " " + str(last_timestamp_ms) + " timestamp: "
-                       + str(timestamp_secs) + " " + str(timestamp_ms) + "\n")
+      raise Exception("WARNING: last_timestamp: " + str(last_timestamp_secs)

[pasko, 2014/05/12 12:09:34]

nit:

with an exception it is no longer a warning

[Philippe, 2014/05/13 09:48:10]

Yeah :)

+                       + " " + str(last_timestamp_us) + " timestamp: "
+                       + str(timestamp_secs) + " " + str(timestamp_us) + "\n")
     last_timestamp_secs = timestamp_secs
-    last_timestamp_ms = timestamp_ms
+    last_timestamp_us = timestamp_us
     index = index + 1
 
 def Convert (call_lines, startAddr, endAddr):
   """Converts the call addresses to static offsets and removes invalid calls.
 
   Removes profiled calls not in shared library using start and end virtual
   addresses, converts strings to integer values, coverts virtual addresses to
   address in shared library.
 
   Returns:
-     list of calls as tuples (sec, msec, pid:tid, callee)
+     list of calls as tuples (sec, usec, pid:tid, callee)
   """
   converted_calls = []
   call_addresses = []
   for fields in call_lines:
     secs = int (fields[0])
-    msecs = int (fields[1])
+    usecs = int (fields[1])
     callee = int (fields[3], 16)
     # print ("callee: " + hex (callee) + " start: " + hex (startAddr) + " end: "
     #        + hex (endAddr))
     if (callee >= startAddr and callee < endAddr
         and (not callee in call_addresses)):
-      converted_calls.append((secs, msecs, fields[2], (callee - startAddr)))
+      converted_calls.append((secs, usecs, fields[2], (callee - startAddr)))
       call_addresses.append(callee)
   return converted_calls
 
 def Timestamp(trace_entry):
   return int (trace_entry[0]) * 1000000 + int(trace_entry[1])
 
 def AddTrace (tracemap, trace):
   """Adds a trace to the tracemap.
 
   Adds entries in the trace to the tracemap. All new calls will be added to
@@ skipping 44 matching lines @@
     AddTrace(tracemap, trace_calls)
     sys.stderr.write("Merged len: " + str(len(tracemap)) + "\n")
 
   # Extract the resulting trace from the tracemap
   merged_trace = []
   for call in tracemap:
     merged_trace.append(tracemap[call])
   merged_trace.sort(key=Timestamp)
 
   print "0-ffffffff r-xp 00000000 xx:00 00000 ./"
-  print "secs\tmsecs\tpid:threadid\tfunc"
+  print "secs\tusecs\tpid:threadid\tfunc"
   for call in merged_trace:
     print (str(call[0]) + "\t" + str(call[1]) + "\t" + call[2] + "\t" +
            hex(call[3]))
 
 if __name__ == '__main__':
   main()