| OLD | NEW |
| 1 #!/usr/bin/env python | 1 #!/usr/bin/env python |
| 2 # | 2 # |
| 3 # Copyright 2010 the V8 project authors. All rights reserved. | 3 # Copyright 2010 the V8 project authors. All rights reserved. |
| 4 # Redistribution and use in source and binary forms, with or without | 4 # Redistribution and use in source and binary forms, with or without |
| 5 # modification, are permitted provided that the following conditions are | 5 # modification, are permitted provided that the following conditions are |
| 6 # met: | 6 # met: |
| 7 # | 7 # |
| 8 # * Redistributions of source code must retain the above copyright | 8 # * Redistributions of source code must retain the above copyright |
| 9 # notice, this list of conditions and the following disclaimer. | 9 # notice, this list of conditions and the following disclaimer. |
| 10 # * Redistributions in binary form must reproduce the above | 10 # * Redistributions in binary form must reproduce the above |
| (...skipping 12 matching lines...) Expand all Loading... |
| 23 # SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT | 23 # SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT |
| 24 # LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, | 24 # LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, |
| 25 # DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY | 25 # DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY |
| 26 # THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT | 26 # THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT |
| 27 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE | 27 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE |
| 28 # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. | 28 # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. |
| 29 | 29 |
| 30 import bisect | 30 import bisect |
| 31 import collections | 31 import collections |
| 32 import ctypes | 32 import ctypes |
| 33 import disasm |
| 33 import mmap | 34 import mmap |
| 34 import optparse | 35 import optparse |
| 35 import os | 36 import os |
| 36 import re | 37 import re |
| 37 import subprocess | 38 import subprocess |
| 38 import sys | 39 import sys |
| 39 import tempfile | |
| 40 import time | 40 import time |
| 41 | 41 |
| 42 | 42 |
| 43 USAGE="""usage: %prog [OPTION]... | 43 USAGE="""usage: %prog [OPTION]... |
| 44 | 44 |
| 45 Analyses V8 and perf logs to produce profiles. | 45 Analyses V8 and perf logs to produce profiles. |
| 46 | 46 |
| 47 Perf logs can be collected using a command like: | 47 Perf logs can be collected using a command like: |
| 48 $ perf record -R -e cycles -c 10000 -f -i ./shell bench.js --ll-prof | 48 $ perf record -R -e cycles -c 10000 -f -i ./shell bench.js --ll-prof |
| 49 # -R: collect all data | 49 # -R: collect all data |
| (...skipping 17 matching lines...) Expand all Loading... |
| 67 $ %prog --log=foo.log --snapshot-log=snap-foo.log --trace=foo.data --snapshot | 67 $ %prog --log=foo.log --snapshot-log=snap-foo.log --trace=foo.data --snapshot |
| 68 """ | 68 """ |
| 69 | 69 |
| 70 | 70 |
| 71 # Must match kGcFakeMmap. | 71 # Must match kGcFakeMmap. |
| 72 V8_GC_FAKE_MMAP = "/tmp/__v8_gc__" | 72 V8_GC_FAKE_MMAP = "/tmp/__v8_gc__" |
| 73 | 73 |
| 74 JS_ORIGIN = "js" | 74 JS_ORIGIN = "js" |
| 75 JS_SNAPSHOT_ORIGIN = "js-snapshot" | 75 JS_SNAPSHOT_ORIGIN = "js-snapshot" |
| 76 | 76 |
| 77 # Avoid using the slow (google-specific) wrapper around objdump. | 77 OBJDUMP_BIN = disasm.OBJDUMP_BIN |
| 78 OBJDUMP_BIN = "/usr/bin/objdump" | |
| 79 if not os.path.exists(OBJDUMP_BIN): | |
| 80 OBJDUMP_BIN = "objdump" | |
| 81 | 78 |
| 82 | 79 |
| 83 class Code(object): | 80 class Code(object): |
| 84 """Code object.""" | 81 """Code object.""" |
| 85 | 82 |
| 86 _COMMON_DISASM_OPTIONS = ["-M", "intel-mnemonic", "-C"] | |
| 87 | |
| 88 _DISASM_HEADER_RE = re.compile(r"[a-f0-9]+\s+<.*:$") | |
| 89 _DISASM_LINE_RE = re.compile(r"\s*([a-f0-9]+):.*") | |
| 90 | |
| 91 # Keys must match constants in Logger::LogCodeInfo. | |
| 92 _ARCH_MAP = { | |
| 93 "ia32": "-m i386", | |
| 94 "x64": "-m i386 -M x86-64", | |
| 95 "arm": "-m arm" # Not supported by our objdump build. | |
| 96 } | |
| 97 | |
| 98 _id = 0 | 83 _id = 0 |
| 99 | 84 |
| 100 def __init__(self, name, start_address, end_address, origin, origin_offset): | 85 def __init__(self, name, start_address, end_address, origin, origin_offset): |
| 101 self.id = Code._id | 86 self.id = Code._id |
| 102 Code._id += 1 | 87 Code._id += 1 |
| 103 self.name = name | 88 self.name = name |
| 104 self.other_names = None | 89 self.other_names = None |
| 105 self.start_address = start_address | 90 self.start_address = start_address |
| 106 self.end_address = end_address | 91 self.end_address = end_address |
| 107 self.origin = origin | 92 self.origin = origin |
| (...skipping 35 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 143 if self.self_ticks_map is None: | 128 if self.self_ticks_map is None: |
| 144 ticks_map = [] | 129 ticks_map = [] |
| 145 else: | 130 else: |
| 146 ticks_map = self.self_ticks_map.items() | 131 ticks_map = self.self_ticks_map.items() |
| 147 # Convert the ticks map to offsets and counts arrays so that later | 132 # Convert the ticks map to offsets and counts arrays so that later |
| 148 # we can do binary search in the offsets array. | 133 # we can do binary search in the offsets array. |
| 149 ticks_map.sort(key=lambda t: t[0]) | 134 ticks_map.sort(key=lambda t: t[0]) |
| 150 ticks_offsets = [t[0] for t in ticks_map] | 135 ticks_offsets = [t[0] for t in ticks_map] |
| 151 ticks_counts = [t[1] for t in ticks_map] | 136 ticks_counts = [t[1] for t in ticks_map] |
| 152 # Get a list of disassembled lines and their addresses. | 137 # Get a list of disassembled lines and their addresses. |
| 153 lines = [] | 138 lines = self._GetDisasmLines(code_info, options) |
| 154 for line in self._GetDisasmLines(code_info, options): | |
| 155 match = Code._DISASM_LINE_RE.match(line) | |
| 156 if match: | |
| 157 line_address = int(match.group(1), 16) | |
| 158 lines.append((line_address, line)) | |
| 159 if len(lines) == 0: | 139 if len(lines) == 0: |
| 160 return | 140 return |
| 161 # Print annotated lines. | 141 # Print annotated lines. |
| 162 address = lines[0][0] | 142 address = lines[0][0] |
| 163 total_count = 0 | 143 total_count = 0 |
| 164 for i in xrange(len(lines)): | 144 for i in xrange(len(lines)): |
| 165 start_offset = lines[i][0] - address | 145 start_offset = lines[i][0] - address |
| 166 if i == len(lines) - 1: | 146 if i == len(lines) - 1: |
| 167 end_offset = self.end_address - self.start_address | 147 end_offset = self.end_address - self.start_address |
| 168 else: | 148 else: |
| 169 end_offset = lines[i + 1][0] - address | 149 end_offset = lines[i + 1][0] - address |
| 170 # Ticks (reported pc values) are not always precise, i.e. not | 150 # Ticks (reported pc values) are not always precise, i.e. not |
| 171 # necessarily point at instruction starts. So we have to search | 151 # necessarily point at instruction starts. So we have to search |
| 172 # for ticks that touch the current instruction line. | 152 # for ticks that touch the current instruction line. |
| 173 j = bisect.bisect_left(ticks_offsets, end_offset) | 153 j = bisect.bisect_left(ticks_offsets, end_offset) |
| 174 count = 0 | 154 count = 0 |
| 175 for offset, cnt in reversed(zip(ticks_offsets[:j], ticks_counts[:j])): | 155 for offset, cnt in reversed(zip(ticks_offsets[:j], ticks_counts[:j])): |
| 176 if offset < start_offset: | 156 if offset < start_offset: |
| 177 break | 157 break |
| 178 count += cnt | 158 count += cnt |
| 179 total_count += count | 159 total_count += count |
| 180 count = 100.0 * count / self.self_ticks | 160 count = 100.0 * count / self.self_ticks |
| 181 if count >= 0.01: | 161 if count >= 0.01: |
| 182 print "%15.2f %s" % (count, lines[i][1]) | 162 print "%15.2f %x: %s" % (count, lines[i][0], lines[i][1]) |
| 183 else: | 163 else: |
| 184 print "%s %s" % (" " * 15, lines[i][1]) | 164 print "%s %x: %s" % (" " * 15, lines[i][0], lines[i][1]) |
| 185 print | 165 print |
| 186 assert total_count == self.self_ticks, \ | 166 assert total_count == self.self_ticks, \ |
| 187 "Lost ticks (%d != %d) in %s" % (total_count, self.self_ticks, self) | 167 "Lost ticks (%d != %d) in %s" % (total_count, self.self_ticks, self) |
| 188 | 168 |
| 189 def __str__(self): | 169 def __str__(self): |
| 190 return "%s [0x%x, 0x%x) size: %d origin: %s" % ( | 170 return "%s [0x%x, 0x%x) size: %d origin: %s" % ( |
| 191 self.name, | 171 self.name, |
| 192 self.start_address, | 172 self.start_address, |
| 193 self.end_address, | 173 self.end_address, |
| 194 self.end_address - self.start_address, | 174 self.end_address - self.start_address, |
| 195 self.origin) | 175 self.origin) |
| 196 | 176 |
| 197 def _GetDisasmLines(self, code_info, options): | 177 def _GetDisasmLines(self, code_info, options): |
| 198 tmp_name = None | |
| 199 if self.origin == JS_ORIGIN or self.origin == JS_SNAPSHOT_ORIGIN: | 178 if self.origin == JS_ORIGIN or self.origin == JS_SNAPSHOT_ORIGIN: |
| 200 assert code_info.arch in Code._ARCH_MAP, \ | 179 inplace = False |
| 201 "Unsupported architecture '%s'" % arch | 180 filename = options.log + ".code" |
| 202 arch_flags = Code._ARCH_MAP[code_info.arch] | |
| 203 # Create a temporary file just with this code object. | |
| 204 tmp_name = tempfile.mktemp(".v8code") | |
| 205 size = self.end_address - self.start_address | |
| 206 command = "dd if=%s.code of=%s bs=1 count=%d skip=%d && " \ | |
| 207 "%s %s -D -b binary %s %s" % ( | |
| 208 options.log, tmp_name, size, self.origin_offset, | |
| 209 OBJDUMP_BIN, ' '.join(Code._COMMON_DISASM_OPTIONS), arch_flags, | |
| 210 tmp_name) | |
| 211 else: | 181 else: |
| 212 command = "%s %s --start-address=%d --stop-address=%d -d %s " % ( | 182 inplace = True |
| 213 OBJDUMP_BIN, ' '.join(Code._COMMON_DISASM_OPTIONS), | 183 filename = self.origin |
| 214 self.origin_offset, | 184 return disasm.GetDisasmLines(filename, |
| 215 self.origin_offset + self.end_address - self.start_address, | 185 self.origin_offset, |
| 216 self.origin) | 186 self.end_address - self.start_address, |
| 217 process = subprocess.Popen(command, | 187 code_info.arch, |
| 218 shell=True, | 188 inplace) |
| 219 stdout=subprocess.PIPE, | |
| 220 stderr=subprocess.STDOUT) | |
| 221 out, err = process.communicate() | |
| 222 lines = out.split("\n") | |
| 223 header_line = 0 | |
| 224 for i, line in enumerate(lines): | |
| 225 if Code._DISASM_HEADER_RE.match(line): | |
| 226 header_line = i | |
| 227 break | |
| 228 if tmp_name: | |
| 229 os.unlink(tmp_name) | |
| 230 return lines[header_line + 1:] | |
| 231 | 189 |
| 232 | 190 |
| 233 class CodePage(object): | 191 class CodePage(object): |
| 234 """Group of adjacent code objects.""" | 192 """Group of adjacent code objects.""" |
| 235 | 193 |
| 236 SHIFT = 12 # 4K pages | 194 SHIFT = 12 # 4K pages |
| 237 SIZE = (1 << SHIFT) | 195 SIZE = (1 << SHIFT) |
| 238 MASK = ~(SIZE - 1) | 196 MASK = ~(SIZE - 1) |
| 239 | 197 |
| 240 @staticmethod | 198 @staticmethod |
| (...skipping 105 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 346 self.header_size = header_size | 304 self.header_size = header_size |
| 347 | 305 |
| 348 | 306 |
| 349 class CodeLogReader(object): | 307 class CodeLogReader(object): |
| 350 """V8 code event log reader.""" | 308 """V8 code event log reader.""" |
| 351 | 309 |
| 352 _CODE_INFO_RE = re.compile( | 310 _CODE_INFO_RE = re.compile( |
| 353 r"code-info,([^,]+),(\d+)") | 311 r"code-info,([^,]+),(\d+)") |
| 354 | 312 |
| 355 _CODE_CREATE_RE = re.compile( | 313 _CODE_CREATE_RE = re.compile( |
| 356 r"code-creation,([^,]+),(0x[a-f0-9]+),(\d+),\"(.*)\"(?:,(\d+))?") | 314 r"code-creation,([^,]+),(0x[a-f0-9]+),(\d+),\"(.*)\"(?:,(0x[a-f0-9]+),([~*])
?)?(?:,(\d+))?") |
| 357 | 315 |
| 358 _CODE_MOVE_RE = re.compile( | 316 _CODE_MOVE_RE = re.compile( |
| 359 r"code-move,(0x[a-f0-9]+),(0x[a-f0-9]+)") | 317 r"code-move,(0x[a-f0-9]+),(0x[a-f0-9]+)") |
| 360 | 318 |
| 361 _CODE_DELETE_RE = re.compile( | 319 _CODE_DELETE_RE = re.compile( |
| 362 r"code-delete,(0x[a-f0-9]+)") | 320 r"code-delete,(0x[a-f0-9]+)") |
| 363 | 321 |
| 364 _SNAPSHOT_POS_RE = re.compile( | 322 _SNAPSHOT_POS_RE = re.compile( |
| 365 r"snapshot-pos,(0x[a-f0-9]+),(\d+)") | 323 r"snapshot-pos,(0x[a-f0-9]+),(\d+)") |
| 366 | 324 |
| (...skipping 26 matching lines...) Expand all Loading... |
| 393 return made_progress | 351 return made_progress |
| 394 | 352 |
| 395 match = CodeLogReader._CODE_CREATE_RE.match(line) | 353 match = CodeLogReader._CODE_CREATE_RE.match(line) |
| 396 if match: | 354 if match: |
| 397 start_address = int(match.group(2), 16) + code_header_size | 355 start_address = int(match.group(2), 16) + code_header_size |
| 398 end_address = start_address + int(match.group(3)) - code_header_size | 356 end_address = start_address + int(match.group(3)) - code_header_size |
| 399 if start_address in self.address_to_snapshot_name: | 357 if start_address in self.address_to_snapshot_name: |
| 400 name = self.address_to_snapshot_name[start_address] | 358 name = self.address_to_snapshot_name[start_address] |
| 401 origin = JS_SNAPSHOT_ORIGIN | 359 origin = JS_SNAPSHOT_ORIGIN |
| 402 else: | 360 else: |
| 403 name = "%s:%s" % (match.group(1), match.group(4)) | 361 tag = match.group(1) |
| 362 optimization_status = match.group(6) |
| 363 func_name = match.group(4) |
| 364 if optimization_status: |
| 365 name = "%s:%s%s" % (tag, optimization_status, func_name) |
| 366 else: |
| 367 name = "%s:%s" % (tag, func_name) |
| 404 origin = JS_ORIGIN | 368 origin = JS_ORIGIN |
| 405 if self.is_snapshot: | 369 if self.is_snapshot: |
| 406 origin_offset = 0 | 370 origin_offset = 0 |
| 407 else: | 371 else: |
| 408 origin_offset = int(match.group(5)) | 372 origin_offset = int(match.group(7)) |
| 409 code = Code(name, start_address, end_address, origin, origin_offset) | 373 code = Code(name, start_address, end_address, origin, origin_offset) |
| 410 conficting_code = self.code_map.Find(start_address) | 374 conficting_code = self.code_map.Find(start_address) |
| 411 if conficting_code: | 375 if conficting_code: |
| 412 CodeLogReader._HandleCodeConflict(conficting_code, code) | 376 CodeLogReader._HandleCodeConflict(conficting_code, code) |
| 413 # TODO(vitalyr): this warning is too noisy because of our | 377 # TODO(vitalyr): this warning is too noisy because of our |
| 414 # attempts to reconstruct code log from the snapshot. | 378 # attempts to reconstruct code log from the snapshot. |
| 415 # print >>sys.stderr, \ | 379 # print >>sys.stderr, \ |
| 416 # "Warning: Skipping duplicate code log entry %s" % code | 380 # "Warning: Skipping duplicate code log entry %s" % code |
| 417 continue | 381 continue |
| 418 self.code_map.Add(code) | 382 self.code_map.Add(code) |
| (...skipping 527 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 946 print "%10d total ticks" % ticks | 910 print "%10d total ticks" % ticks |
| 947 print "%10d ticks not in symbols" % missed_ticks | 911 print "%10d ticks not in symbols" % missed_ticks |
| 948 print "%10d unaccounted ticks" % really_missed_ticks | 912 print "%10d unaccounted ticks" % really_missed_ticks |
| 949 print "%10d total symbols" % len([c for c in code_map.AllCode()]) | 913 print "%10d total symbols" % len([c for c in code_map.AllCode()]) |
| 950 print "%10d used symbols" % len([c for c in code_map.UsedCode()]) | 914 print "%10d used symbols" % len([c for c in code_map.UsedCode()]) |
| 951 print "%9.2fs library processing time" % mmap_time | 915 print "%9.2fs library processing time" % mmap_time |
| 952 print "%9.2fs tick processing time" % sample_time | 916 print "%9.2fs tick processing time" % sample_time |
| 953 | 917 |
| 954 log_reader.Dispose() | 918 log_reader.Dispose() |
| 955 trace_reader.Dispose() | 919 trace_reader.Dispose() |
| OLD | NEW |