Add scripts for using cygprofile to repository

tools/cygprofile/mergetraces.py

+#!/usr/bin/python
+# Copyright (c) 2011 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
+    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
+    offset of the symbol in the library and 3) the virtual end address
+  """
+  call_lines = []
+  vm_start = 0
+  vm_end = 0
+  dash_index = lines[0].find ('-')
+  space_index = lines[0].find (' ')
+  vm_start = int (lines[0][:dash_index], 16)
+  vm_end = int (lines[0][dash_index+1:space_index], 16)
+  for line in lines[2:]:
+    line = line.strip()
+    # print hex (vm_start)
+    fields = line.split()
+    call_lines.append (fields)
+
+  return (call_lines, vm_start, vm_end)
+
+def HasDuplicates(calls):
+  """Funcition is a sanity check to make sure that calls are only logged once.
+
+  Args:
+    calls: list of calls logged
+
+  Returns:
+    boolean indicating if calls has duplicate calls
+  """
+  seen = []
+  for call in calls:
+    if call[3] in seen:
+      return true
+    else:
+      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
+  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
+    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")
+    last_timestamp_secs = timestamp_secs
+    last_timestamp_ms = timestamp_ms
+    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)
+  """
+  converted_calls = []
+  call_addresses = []
+  for fields in call_lines:
+    secs = int (fields[0])
+    msecs = 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)))
+      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
+  the tracemap. If the calls already exist in the tracemap then they will be
+  replaced if they happened sooner in the new trace.
+
+  Args:
+    tracemap: the tracemap
+    trace: the trace
+
+  """
+  for trace_entry in trace:
+    call = trace_entry[3]
+    if (not call in tracemap) or (
+        Timestamp(tracemap[call]) > Timestamp(trace_entry)):
+      tracemap[call] = trace_entry
+
+def main():
+  """Merge two traces for code in specified library and write to stdout.
+
+  Merges the two traces and coverts the virtual addresses to the offsets in the
+  library.  First line of merged trace has dummy virtual address of 0-ffffffff
+  so that symbolizing the addresses uses the addresses in the log, since the
+  addresses have already been converted to static offsets.
+  """
+  parser = optparse.OptionParser('usage: %prog trace1 ... traceN')
+  (_, args) = parser.parse_args()
+  if len(args) <= 1:
+    parser.error('expected at least the following args: trace1 trace2')
+
+  step = 0
+  tracemap = dict()
+  for trace_file in args:
+    step += 1
+    sys.stderr.write("    " + str(step) + "/" + str(len(args)) +
+                     ": " + trace_file + ":\n")
+
+    trace_lines = map(string.rstrip, open(trace_file).readlines())
+    (trace_calls, trace_start, trace_end) = ParseLogLines(trace_lines)
+    CheckTimestamps(trace_calls)
+    sys.stderr.write("Len: " + str(len(trace_calls)) +
+                     ". Start: " + hex(trace_start) +
+                     ", end: " + hex(trace_end) + '\n')
+
+    trace_calls = Convert(trace_calls, trace_start, trace_end)
+    sys.stderr.write("Converted len: " + str(len(trace_calls)) + "\n")
+
+    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"
+  for call in merged_trace:
+    print (str(call[0]) + "\t" + str(call[1]) + "\t" + call[2] + "\t" +
+           hex(call[3]))
+
+if __name__ == '__main__':
+  main()