| OLD | NEW |
| 1 #!/usr/bin/python | 1 #!/usr/bin/python |
| 2 # Copyright 2013 The Chromium Authors. All rights reserved. | 2 # Copyright 2013 The Chromium Authors. All rights reserved. |
| 3 # Use of this source code is governed by a BSD-style license that can be | 3 # Use of this source code is governed by a BSD-style license that can be |
| 4 # found in the LICENSE file. | 4 # found in the LICENSE file. |
| 5 | 5 |
| 6 # Use: ../mergetraces.py `ls cyglog.* -Sr` > merged_cyglog | 6 # Use: ../mergetraces.py `ls cyglog.* -Sr` > merged_cyglog |
| 7 | 7 |
| 8 """"Merge multiple logs files from different processes into a single log. | 8 """"Merge multiple logs files from different processes into a single log. |
| 9 | 9 |
| 10 Given two log files of execution traces, merge the traces into a single trace. | 10 Given two log files of execution traces, merge the traces into a single trace. |
| 11 Merging will use timestamps (i.e. the first two columns of logged calls) to | 11 Merging will use timestamps (i.e. the first two columns of logged calls) to |
| 12 create a single log that is an ordered trace of calls by both processes. | 12 create a single log that is an ordered trace of calls by both processes. |
| 13 """ | 13 """ |
| 14 | 14 |
| 15 import optparse | 15 import optparse |
| 16 import os | 16 import os |
| 17 import string | 17 import string |
| 18 import subprocess | 18 import subprocess |
| 19 import sys | 19 import sys |
| 20 | 20 |
| 21 def ParseLogLines(lines): | 21 def ParseLogLines(lines): |
| 22 """Parse log file lines. | 22 """Parse log file lines. |
| 23 | 23 |
| 24 Args: | 24 Args: |
| 25 lines: lines from log file produced by profiled run | 25 lines: lines from log file produced by profiled run |
| 26 | 26 |
| 27 Below is an example of a small log file: | 27 Below is an example of a small log file: |
| 28 5086e000-52e92000 r-xp 00000000 b3:02 51276 libchromeview.so | 28 5086e000-52e92000 r-xp 00000000 b3:02 51276 libchromeview.so |
| 29 secs msecs pid:threadid func | 29 secs usecs pid:threadid func |
| 30 START | 30 START |
| 31 1314897086 795828 3587:1074648168 0x509e105c | 31 1314897086 795828 3587:1074648168 0x509e105c |
| 32 1314897086 795874 3587:1074648168 0x509e0eb4 | 32 1314897086 795874 3587:1074648168 0x509e0eb4 |
| 33 1314897086 796326 3587:1074648168 0x509e0e3c | 33 1314897086 796326 3587:1074648168 0x509e0e3c |
| 34 1314897086 796552 3587:1074648168 0x509e07bc | 34 1314897086 796552 3587:1074648168 0x509e07bc |
| 35 END | 35 END |
| 36 | 36 |
| 37 Returns: | 37 Returns: |
| 38 tuple conisiting of 1) an ordered list of the logged calls, as an array of | 38 tuple conisiting of 1) an ordered list of the logged calls, as an array of |
| 39 fields, 2) the virtual start address of the library, used to compute the | 39 fields, 2) the virtual start address of the library, used to compute the |
| (...skipping 31 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 71 seen.append(call[3]) | 71 seen.append(call[3]) |
| 72 | 72 |
| 73 def CheckTimestamps(calls): | 73 def CheckTimestamps(calls): |
| 74 """Prints warning to stderr if the call timestamps are not in order. | 74 """Prints warning to stderr if the call timestamps are not in order. |
| 75 | 75 |
| 76 Args: | 76 Args: |
| 77 calls: list of calls logged | 77 calls: list of calls logged |
| 78 """ | 78 """ |
| 79 index = 0 | 79 index = 0 |
| 80 last_timestamp_secs = -1 | 80 last_timestamp_secs = -1 |
| 81 last_timestamp_ms = -1 | 81 last_timestamp_us = -1 |
| 82 while (index < len (calls)): | 82 while (index < len (calls)): |
| 83 timestamp_secs = int (calls[index][0]) | 83 timestamp_secs = int (calls[index][0]) |
| 84 timestamp_ms = int (calls[index][1]) | 84 timestamp_us = int (calls[index][1]) |
| 85 timestamp = (timestamp_secs * 1000000) + timestamp_ms | 85 timestamp = (timestamp_secs * 1000000) + timestamp_us |
| 86 last_timestamp = (last_timestamp_secs * 1000000) + last_timestamp_ms | 86 last_timestamp = (last_timestamp_secs * 1000000) + last_timestamp_us |
| 87 if (timestamp < last_timestamp): | 87 if (timestamp < last_timestamp): |
| 88 sys.stderr.write("WARNING: last_timestamp: " + str(last_timestamp_secs) | 88 raise Exception("last_timestamp: " + str(last_timestamp_secs) |
| 89 + " " + str(last_timestamp_ms) + " timestamp: " | 89 + " " + str(last_timestamp_us) + " timestamp: " |
| 90 + str(timestamp_secs) + " " + str(timestamp_ms) + "\n") | 90 + str(timestamp_secs) + " " + str(timestamp_us) + "\n") |
| 91 last_timestamp_secs = timestamp_secs | 91 last_timestamp_secs = timestamp_secs |
| 92 last_timestamp_ms = timestamp_ms | 92 last_timestamp_us = timestamp_us |
| 93 index = index + 1 | 93 index = index + 1 |
| 94 | 94 |
| 95 def Convert (call_lines, startAddr, endAddr): | 95 def Convert (call_lines, startAddr, endAddr): |
| 96 """Converts the call addresses to static offsets and removes invalid calls. | 96 """Converts the call addresses to static offsets and removes invalid calls. |
| 97 | 97 |
| 98 Removes profiled calls not in shared library using start and end virtual | 98 Removes profiled calls not in shared library using start and end virtual |
| 99 addresses, converts strings to integer values, coverts virtual addresses to | 99 addresses, converts strings to integer values, coverts virtual addresses to |
| 100 address in shared library. | 100 address in shared library. |
| 101 | 101 |
| 102 Returns: | 102 Returns: |
| 103 list of calls as tuples (sec, msec, pid:tid, callee) | 103 list of calls as tuples (sec, usec, pid:tid, callee) |
| 104 """ | 104 """ |
| 105 converted_calls = [] | 105 converted_calls = [] |
| 106 call_addresses = [] | 106 call_addresses = [] |
| 107 for fields in call_lines: | 107 for fields in call_lines: |
| 108 secs = int (fields[0]) | 108 secs = int (fields[0]) |
| 109 msecs = int (fields[1]) | 109 usecs = int (fields[1]) |
| 110 callee = int (fields[3], 16) | 110 callee = int (fields[3], 16) |
| 111 # print ("callee: " + hex (callee) + " start: " + hex (startAddr) + " end: " | 111 # print ("callee: " + hex (callee) + " start: " + hex (startAddr) + " end: " |
| 112 # + hex (endAddr)) | 112 # + hex (endAddr)) |
| 113 if (callee >= startAddr and callee < endAddr | 113 if (callee >= startAddr and callee < endAddr |
| 114 and (not callee in call_addresses)): | 114 and (not callee in call_addresses)): |
| 115 converted_calls.append((secs, msecs, fields[2], (callee - startAddr))) | 115 converted_calls.append((secs, usecs, fields[2], (callee - startAddr))) |
| 116 call_addresses.append(callee) | 116 call_addresses.append(callee) |
| 117 return converted_calls | 117 return converted_calls |
| 118 | 118 |
| 119 def Timestamp(trace_entry): | 119 def Timestamp(trace_entry): |
| 120 return int (trace_entry[0]) * 1000000 + int(trace_entry[1]) | 120 return int (trace_entry[0]) * 1000000 + int(trace_entry[1]) |
| 121 | 121 |
| 122 def AddTrace (tracemap, trace): | 122 def AddTrace (tracemap, trace): |
| 123 """Adds a trace to the tracemap. | 123 """Adds a trace to the tracemap. |
| 124 | 124 |
| 125 Adds entries in the trace to the tracemap. All new calls will be added to | 125 Adds entries in the trace to the tracemap. All new calls will be added to |
| (...skipping 44 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 170 AddTrace(tracemap, trace_calls) | 170 AddTrace(tracemap, trace_calls) |
| 171 sys.stderr.write("Merged len: " + str(len(tracemap)) + "\n") | 171 sys.stderr.write("Merged len: " + str(len(tracemap)) + "\n") |
| 172 | 172 |
| 173 # Extract the resulting trace from the tracemap | 173 # Extract the resulting trace from the tracemap |
| 174 merged_trace = [] | 174 merged_trace = [] |
| 175 for call in tracemap: | 175 for call in tracemap: |
| 176 merged_trace.append(tracemap[call]) | 176 merged_trace.append(tracemap[call]) |
| 177 merged_trace.sort(key=Timestamp) | 177 merged_trace.sort(key=Timestamp) |
| 178 | 178 |
| 179 print "0-ffffffff r-xp 00000000 xx:00 00000 ./" | 179 print "0-ffffffff r-xp 00000000 xx:00 00000 ./" |
| 180 print "secs\tmsecs\tpid:threadid\tfunc" | 180 print "secs\tusecs\tpid:threadid\tfunc" |
| 181 for call in merged_trace: | 181 for call in merged_trace: |
| 182 print (str(call[0]) + "\t" + str(call[1]) + "\t" + call[2] + "\t" + | 182 print (str(call[0]) + "\t" + str(call[1]) + "\t" + call[2] + "\t" + |
| 183 hex(call[3])) | 183 hex(call[3])) |
| 184 | 184 |
| 185 if __name__ == '__main__': | 185 if __name__ == '__main__': |
| 186 main() | 186 main() |
| OLD | NEW |