Index: tools/cygprofile/mergetraces.py |
diff --git a/tools/cygprofile/mergetraces.py b/tools/cygprofile/mergetraces.py |
new file mode 100755 |
index 0000000000000000000000000000000000000000..b5b32a97da3bf422a173a847340f2e6e8c6937ab |
--- /dev/null |
+++ b/tools/cygprofile/mergetraces.py |
@@ -0,0 +1,186 @@ |
+#!/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() |