Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 1 | #!/usr/bin/env python |
| 2 | # |
Ben Murdoch | 85b7179 | 2012-04-11 18:30:58 +0100 | [diff] [blame^] | 3 | # Copyright 2010 the V8 project authors. All rights reserved. |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 4 | # Redistribution and use in source and binary forms, with or without |
| 5 | # modification, are permitted provided that the following conditions are |
| 6 | # met: |
| 7 | # |
| 8 | # * Redistributions of source code must retain the above copyright |
| 9 | # notice, this list of conditions and the following disclaimer. |
| 10 | # * Redistributions in binary form must reproduce the above |
| 11 | # copyright notice, this list of conditions and the following |
| 12 | # disclaimer in the documentation and/or other materials provided |
| 13 | # with the distribution. |
| 14 | # * Neither the name of Google Inc. nor the names of its |
| 15 | # contributors may be used to endorse or promote products derived |
| 16 | # from this software without specific prior written permission. |
| 17 | # |
| 18 | # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS |
| 19 | # "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT |
| 20 | # LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR |
| 21 | # A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT |
| 22 | # OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, |
| 23 | # SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT |
| 24 | # LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, |
| 25 | # DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY |
| 26 | # THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT |
| 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. |
| 29 | |
| 30 | import bisect |
| 31 | import collections |
| 32 | import ctypes |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 33 | import disasm |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 34 | import mmap |
| 35 | import optparse |
| 36 | import os |
| 37 | import re |
| 38 | import subprocess |
| 39 | import sys |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 40 | import time |
| 41 | |
| 42 | |
| 43 | USAGE="""usage: %prog [OPTION]... |
| 44 | |
| 45 | Analyses V8 and perf logs to produce profiles. |
| 46 | |
| 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 |
| 49 | # -R: collect all data |
| 50 | # -e cycles: use cpu-cycles event (run "perf list" for details) |
| 51 | # -c 10000: write a sample after each 10000 events |
| 52 | # -f: force output file overwrite |
| 53 | # -i: limit profiling to our process and the kernel |
| 54 | # --ll-prof shell flag enables the right V8 logs |
| 55 | This will produce a binary trace file (perf.data) that %prog can analyse. |
| 56 | |
| 57 | Examples: |
| 58 | # Print flat profile with annotated disassembly for the 10 top |
| 59 | # symbols. Use default log names and include the snapshot log. |
| 60 | $ %prog --snapshot --disasm-top=10 |
| 61 | |
| 62 | # Print flat profile with annotated disassembly for all used symbols. |
| 63 | # Use default log names and include kernel symbols into analysis. |
| 64 | $ %prog --disasm-all --kernel |
| 65 | |
| 66 | # Print flat profile. Use custom log names. |
| 67 | $ %prog --log=foo.log --snapshot-log=snap-foo.log --trace=foo.data --snapshot |
| 68 | """ |
| 69 | |
| 70 | |
| 71 | # Must match kGcFakeMmap. |
| 72 | V8_GC_FAKE_MMAP = "/tmp/__v8_gc__" |
| 73 | |
| 74 | JS_ORIGIN = "js" |
| 75 | JS_SNAPSHOT_ORIGIN = "js-snapshot" |
| 76 | |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 77 | OBJDUMP_BIN = disasm.OBJDUMP_BIN |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 78 | |
| 79 | |
| 80 | class Code(object): |
| 81 | """Code object.""" |
| 82 | |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 83 | _id = 0 |
| 84 | |
| 85 | def __init__(self, name, start_address, end_address, origin, origin_offset): |
| 86 | self.id = Code._id |
| 87 | Code._id += 1 |
| 88 | self.name = name |
| 89 | self.other_names = None |
| 90 | self.start_address = start_address |
| 91 | self.end_address = end_address |
| 92 | self.origin = origin |
| 93 | self.origin_offset = origin_offset |
| 94 | self.self_ticks = 0 |
| 95 | self.self_ticks_map = None |
| 96 | self.callee_ticks = None |
| 97 | |
| 98 | def AddName(self, name): |
| 99 | assert self.name != name |
| 100 | if self.other_names is None: |
| 101 | self.other_names = [name] |
| 102 | return |
| 103 | if not name in self.other_names: |
| 104 | self.other_names.append(name) |
| 105 | |
| 106 | def FullName(self): |
| 107 | if self.other_names is None: |
| 108 | return self.name |
| 109 | self.other_names.sort() |
| 110 | return "%s (aka %s)" % (self.name, ", ".join(self.other_names)) |
| 111 | |
| 112 | def IsUsed(self): |
| 113 | return self.self_ticks > 0 or self.callee_ticks is not None |
| 114 | |
| 115 | def Tick(self, pc): |
| 116 | self.self_ticks += 1 |
| 117 | if self.self_ticks_map is None: |
| 118 | self.self_ticks_map = collections.defaultdict(lambda: 0) |
| 119 | offset = pc - self.start_address |
| 120 | self.self_ticks_map[offset] += 1 |
| 121 | |
| 122 | def CalleeTick(self, callee): |
| 123 | if self.callee_ticks is None: |
| 124 | self.callee_ticks = collections.defaultdict(lambda: 0) |
| 125 | self.callee_ticks[callee] += 1 |
| 126 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 127 | def PrintAnnotated(self, arch, options): |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 128 | if self.self_ticks_map is None: |
| 129 | ticks_map = [] |
| 130 | else: |
| 131 | ticks_map = self.self_ticks_map.items() |
| 132 | # Convert the ticks map to offsets and counts arrays so that later |
| 133 | # we can do binary search in the offsets array. |
| 134 | ticks_map.sort(key=lambda t: t[0]) |
| 135 | ticks_offsets = [t[0] for t in ticks_map] |
| 136 | ticks_counts = [t[1] for t in ticks_map] |
| 137 | # Get a list of disassembled lines and their addresses. |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 138 | lines = self._GetDisasmLines(arch, options) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 139 | if len(lines) == 0: |
| 140 | return |
| 141 | # Print annotated lines. |
| 142 | address = lines[0][0] |
| 143 | total_count = 0 |
| 144 | for i in xrange(len(lines)): |
| 145 | start_offset = lines[i][0] - address |
| 146 | if i == len(lines) - 1: |
| 147 | end_offset = self.end_address - self.start_address |
| 148 | else: |
| 149 | end_offset = lines[i + 1][0] - address |
| 150 | # Ticks (reported pc values) are not always precise, i.e. not |
| 151 | # necessarily point at instruction starts. So we have to search |
| 152 | # for ticks that touch the current instruction line. |
| 153 | j = bisect.bisect_left(ticks_offsets, end_offset) |
| 154 | count = 0 |
| 155 | for offset, cnt in reversed(zip(ticks_offsets[:j], ticks_counts[:j])): |
| 156 | if offset < start_offset: |
| 157 | break |
| 158 | count += cnt |
| 159 | total_count += count |
| 160 | count = 100.0 * count / self.self_ticks |
| 161 | if count >= 0.01: |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 162 | print "%15.2f %x: %s" % (count, lines[i][0], lines[i][1]) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 163 | else: |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 164 | print "%s %x: %s" % (" " * 15, lines[i][0], lines[i][1]) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 165 | print |
| 166 | assert total_count == self.self_ticks, \ |
| 167 | "Lost ticks (%d != %d) in %s" % (total_count, self.self_ticks, self) |
| 168 | |
| 169 | def __str__(self): |
| 170 | return "%s [0x%x, 0x%x) size: %d origin: %s" % ( |
| 171 | self.name, |
| 172 | self.start_address, |
| 173 | self.end_address, |
| 174 | self.end_address - self.start_address, |
| 175 | self.origin) |
| 176 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 177 | def _GetDisasmLines(self, arch, options): |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 178 | if self.origin == JS_ORIGIN or self.origin == JS_SNAPSHOT_ORIGIN: |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 179 | inplace = False |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 180 | filename = options.log + ".ll" |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 181 | else: |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 182 | inplace = True |
| 183 | filename = self.origin |
| 184 | return disasm.GetDisasmLines(filename, |
| 185 | self.origin_offset, |
| 186 | self.end_address - self.start_address, |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 187 | arch, |
Ben Murdoch | e0cee9b | 2011-05-25 10:26:03 +0100 | [diff] [blame] | 188 | inplace) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 189 | |
| 190 | |
| 191 | class CodePage(object): |
| 192 | """Group of adjacent code objects.""" |
| 193 | |
| 194 | SHIFT = 12 # 4K pages |
| 195 | SIZE = (1 << SHIFT) |
| 196 | MASK = ~(SIZE - 1) |
| 197 | |
| 198 | @staticmethod |
| 199 | def PageAddress(address): |
| 200 | return address & CodePage.MASK |
| 201 | |
| 202 | @staticmethod |
| 203 | def PageId(address): |
| 204 | return address >> CodePage.SHIFT |
| 205 | |
| 206 | @staticmethod |
| 207 | def PageAddressFromId(id): |
| 208 | return id << CodePage.SHIFT |
| 209 | |
| 210 | def __init__(self, address): |
| 211 | self.address = address |
| 212 | self.code_objects = [] |
| 213 | |
| 214 | def Add(self, code): |
| 215 | self.code_objects.append(code) |
| 216 | |
| 217 | def Remove(self, code): |
| 218 | self.code_objects.remove(code) |
| 219 | |
| 220 | def Find(self, pc): |
| 221 | code_objects = self.code_objects |
| 222 | for i, code in enumerate(code_objects): |
| 223 | if code.start_address <= pc < code.end_address: |
| 224 | code_objects[0], code_objects[i] = code, code_objects[0] |
| 225 | return code |
| 226 | return None |
| 227 | |
| 228 | def __iter__(self): |
| 229 | return self.code_objects.__iter__() |
| 230 | |
| 231 | |
| 232 | class CodeMap(object): |
| 233 | """Code object map.""" |
| 234 | |
| 235 | def __init__(self): |
| 236 | self.pages = {} |
| 237 | self.min_address = 1 << 64 |
| 238 | self.max_address = -1 |
| 239 | |
| 240 | def Add(self, code, max_pages=-1): |
| 241 | page_id = CodePage.PageId(code.start_address) |
| 242 | limit_id = CodePage.PageId(code.end_address + CodePage.SIZE - 1) |
| 243 | pages = 0 |
| 244 | while page_id < limit_id: |
| 245 | if max_pages >= 0 and pages > max_pages: |
| 246 | print >>sys.stderr, \ |
| 247 | "Warning: page limit (%d) reached for %s [%s]" % ( |
| 248 | max_pages, code.name, code.origin) |
| 249 | break |
| 250 | if page_id in self.pages: |
| 251 | page = self.pages[page_id] |
| 252 | else: |
| 253 | page = CodePage(CodePage.PageAddressFromId(page_id)) |
| 254 | self.pages[page_id] = page |
| 255 | page.Add(code) |
| 256 | page_id += 1 |
| 257 | pages += 1 |
| 258 | self.min_address = min(self.min_address, code.start_address) |
| 259 | self.max_address = max(self.max_address, code.end_address) |
| 260 | |
| 261 | def Remove(self, code): |
| 262 | page_id = CodePage.PageId(code.start_address) |
| 263 | limit_id = CodePage.PageId(code.end_address + CodePage.SIZE - 1) |
| 264 | removed = False |
| 265 | while page_id < limit_id: |
| 266 | if page_id not in self.pages: |
| 267 | page_id += 1 |
| 268 | continue |
| 269 | page = self.pages[page_id] |
| 270 | page.Remove(code) |
| 271 | removed = True |
| 272 | page_id += 1 |
| 273 | return removed |
| 274 | |
| 275 | def AllCode(self): |
| 276 | for page in self.pages.itervalues(): |
| 277 | for code in page: |
| 278 | if CodePage.PageAddress(code.start_address) == page.address: |
| 279 | yield code |
| 280 | |
| 281 | def UsedCode(self): |
| 282 | for code in self.AllCode(): |
| 283 | if code.IsUsed(): |
| 284 | yield code |
| 285 | |
| 286 | def Print(self): |
| 287 | for code in self.AllCode(): |
| 288 | print code |
| 289 | |
| 290 | def Find(self, pc): |
| 291 | if pc < self.min_address or pc >= self.max_address: |
| 292 | return None |
| 293 | page_id = CodePage.PageId(pc) |
| 294 | if page_id not in self.pages: |
| 295 | return None |
| 296 | return self.pages[page_id].Find(pc) |
| 297 | |
| 298 | |
| 299 | class CodeInfo(object): |
| 300 | """Generic info about generated code objects.""" |
| 301 | |
| 302 | def __init__(self, arch, header_size): |
| 303 | self.arch = arch |
| 304 | self.header_size = header_size |
| 305 | |
| 306 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 307 | class SnapshotLogReader(object): |
| 308 | """V8 snapshot log reader.""" |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 309 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 310 | _SNAPSHOT_CODE_NAME_RE = re.compile( |
| 311 | r"snapshot-code-name,(\d+),\"(.*)\"") |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 312 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 313 | def __init__(self, log_name): |
| 314 | self.log_name = log_name |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 315 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 316 | def ReadNameMap(self): |
| 317 | log = open(self.log_name, "r") |
| 318 | try: |
| 319 | snapshot_pos_to_name = {} |
| 320 | for line in log: |
| 321 | match = SnapshotLogReader._SNAPSHOT_CODE_NAME_RE.match(line) |
| 322 | if match: |
| 323 | pos = int(match.group(1)) |
| 324 | name = match.group(2) |
| 325 | snapshot_pos_to_name[pos] = name |
| 326 | finally: |
| 327 | log.close() |
| 328 | return snapshot_pos_to_name |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 329 | |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 330 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 331 | class LogReader(object): |
| 332 | """V8 low-level (binary) log reader.""" |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 333 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 334 | _ARCH_TO_POINTER_TYPE_MAP = { |
| 335 | "ia32": ctypes.c_uint32, |
| 336 | "arm": ctypes.c_uint32, |
| 337 | "x64": ctypes.c_uint64 |
| 338 | } |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 339 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 340 | _CODE_CREATE_TAG = "C" |
| 341 | _CODE_MOVE_TAG = "M" |
| 342 | _CODE_DELETE_TAG = "D" |
| 343 | _SNAPSHOT_POSITION_TAG = "P" |
| 344 | _CODE_MOVING_GC_TAG = "G" |
| 345 | |
| 346 | def __init__(self, log_name, code_map, snapshot_pos_to_name): |
| 347 | self.log_file = open(log_name, "r") |
| 348 | self.log = mmap.mmap(self.log_file.fileno(), 0, mmap.MAP_PRIVATE) |
| 349 | self.log_pos = 0 |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 350 | self.code_map = code_map |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 351 | self.snapshot_pos_to_name = snapshot_pos_to_name |
| 352 | self.address_to_snapshot_name = {} |
| 353 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 354 | self.arch = self.log[:self.log.find("\0")] |
| 355 | self.log_pos += len(self.arch) + 1 |
| 356 | assert self.arch in LogReader._ARCH_TO_POINTER_TYPE_MAP, \ |
| 357 | "Unsupported architecture %s" % self.arch |
| 358 | pointer_type = LogReader._ARCH_TO_POINTER_TYPE_MAP[self.arch] |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 359 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 360 | self.code_create_struct = LogReader._DefineStruct([ |
| 361 | ("name_size", ctypes.c_int32), |
| 362 | ("code_address", pointer_type), |
| 363 | ("code_size", ctypes.c_int32)]) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 364 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 365 | self.code_move_struct = LogReader._DefineStruct([ |
| 366 | ("from_address", pointer_type), |
| 367 | ("to_address", pointer_type)]) |
| 368 | |
| 369 | self.code_delete_struct = LogReader._DefineStruct([ |
| 370 | ("address", pointer_type)]) |
| 371 | |
| 372 | self.snapshot_position_struct = LogReader._DefineStruct([ |
| 373 | ("address", pointer_type), |
| 374 | ("position", ctypes.c_int32)]) |
| 375 | |
| 376 | def ReadUpToGC(self): |
| 377 | while self.log_pos < self.log.size(): |
| 378 | tag = self.log[self.log_pos] |
| 379 | self.log_pos += 1 |
| 380 | |
| 381 | if tag == LogReader._CODE_MOVING_GC_TAG: |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 382 | self.address_to_snapshot_name.clear() |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 383 | return |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 384 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 385 | if tag == LogReader._CODE_CREATE_TAG: |
| 386 | event = self.code_create_struct.from_buffer(self.log, self.log_pos) |
| 387 | self.log_pos += ctypes.sizeof(event) |
| 388 | start_address = event.code_address |
| 389 | end_address = start_address + event.code_size |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 390 | if start_address in self.address_to_snapshot_name: |
| 391 | name = self.address_to_snapshot_name[start_address] |
| 392 | origin = JS_SNAPSHOT_ORIGIN |
| 393 | else: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 394 | name = self.log[self.log_pos:self.log_pos + event.name_size] |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 395 | origin = JS_ORIGIN |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 396 | self.log_pos += event.name_size |
| 397 | origin_offset = self.log_pos |
| 398 | self.log_pos += event.code_size |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 399 | code = Code(name, start_address, end_address, origin, origin_offset) |
| 400 | conficting_code = self.code_map.Find(start_address) |
| 401 | if conficting_code: |
Ben Murdoch | 85b7179 | 2012-04-11 18:30:58 +0100 | [diff] [blame^] | 402 | LogReader._HandleCodeConflict(conficting_code, code) |
| 403 | # TODO(vitalyr): this warning is too noisy because of our |
| 404 | # attempts to reconstruct code log from the snapshot. |
| 405 | # print >>sys.stderr, \ |
| 406 | # "Warning: Skipping duplicate code log entry %s" % code |
| 407 | continue |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 408 | self.code_map.Add(code) |
| 409 | continue |
| 410 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 411 | if tag == LogReader._CODE_MOVE_TAG: |
| 412 | event = self.code_move_struct.from_buffer(self.log, self.log_pos) |
| 413 | self.log_pos += ctypes.sizeof(event) |
| 414 | old_start_address = event.from_address |
| 415 | new_start_address = event.to_address |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 416 | if old_start_address == new_start_address: |
| 417 | # Skip useless code move entries. |
| 418 | continue |
| 419 | code = self.code_map.Find(old_start_address) |
| 420 | if not code: |
| 421 | print >>sys.stderr, "Warning: Not found %x" % old_start_address |
| 422 | continue |
| 423 | assert code.start_address == old_start_address, \ |
| 424 | "Inexact move address %x for %s" % (old_start_address, code) |
| 425 | self.code_map.Remove(code) |
| 426 | size = code.end_address - code.start_address |
| 427 | code.start_address = new_start_address |
| 428 | code.end_address = new_start_address + size |
| 429 | self.code_map.Add(code) |
| 430 | continue |
| 431 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 432 | if tag == LogReader._CODE_DELETE_TAG: |
| 433 | event = self.code_delete_struct.from_buffer(self.log, self.log_pos) |
| 434 | self.log_pos += ctypes.sizeof(event) |
| 435 | old_start_address = event.address |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 436 | code = self.code_map.Find(old_start_address) |
| 437 | if not code: |
| 438 | print >>sys.stderr, "Warning: Not found %x" % old_start_address |
| 439 | continue |
| 440 | assert code.start_address == old_start_address, \ |
| 441 | "Inexact delete address %x for %s" % (old_start_address, code) |
| 442 | self.code_map.Remove(code) |
| 443 | continue |
| 444 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 445 | if tag == LogReader._SNAPSHOT_POSITION_TAG: |
| 446 | event = self.snapshot_position_struct.from_buffer(self.log, |
| 447 | self.log_pos) |
| 448 | self.log_pos += ctypes.sizeof(event) |
| 449 | start_address = event.address |
| 450 | snapshot_pos = event.position |
| 451 | if snapshot_pos in self.snapshot_pos_to_name: |
| 452 | self.address_to_snapshot_name[start_address] = \ |
| 453 | self.snapshot_pos_to_name[snapshot_pos] |
| 454 | continue |
| 455 | |
| 456 | assert False, "Unknown tag %s" % tag |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 457 | |
| 458 | def Dispose(self): |
| 459 | self.log.close() |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 460 | self.log_file.close() |
| 461 | |
| 462 | @staticmethod |
| 463 | def _DefineStruct(fields): |
| 464 | class Struct(ctypes.Structure): |
| 465 | _fields_ = fields |
| 466 | return Struct |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 467 | |
| 468 | @staticmethod |
| 469 | def _HandleCodeConflict(old_code, new_code): |
| 470 | assert (old_code.start_address == new_code.start_address and |
| 471 | old_code.end_address == new_code.end_address), \ |
| 472 | "Conficting code log entries %s and %s" % (old_code, new_code) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 473 | if old_code.name == new_code.name: |
| 474 | return |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 475 | # Code object may be shared by a few functions. Collect the full |
| 476 | # set of names. |
| 477 | old_code.AddName(new_code.name) |
| 478 | |
| 479 | |
| 480 | class Descriptor(object): |
| 481 | """Descriptor of a structure in the binary trace log.""" |
| 482 | |
| 483 | CTYPE_MAP = { |
| 484 | "u16": ctypes.c_uint16, |
| 485 | "u32": ctypes.c_uint32, |
| 486 | "u64": ctypes.c_uint64 |
| 487 | } |
| 488 | |
| 489 | def __init__(self, fields): |
| 490 | class TraceItem(ctypes.Structure): |
| 491 | _fields_ = Descriptor.CtypesFields(fields) |
| 492 | |
| 493 | def __str__(self): |
| 494 | return ", ".join("%s: %s" % (field, self.__getattribute__(field)) |
| 495 | for field, _ in TraceItem._fields_) |
| 496 | |
| 497 | self.ctype = TraceItem |
| 498 | |
| 499 | def Read(self, trace, offset): |
| 500 | return self.ctype.from_buffer(trace, offset) |
| 501 | |
| 502 | @staticmethod |
| 503 | def CtypesFields(fields): |
| 504 | return [(field, Descriptor.CTYPE_MAP[format]) for (field, format) in fields] |
| 505 | |
| 506 | |
| 507 | # Please see http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=tree;f=tools/perf |
| 508 | # for the gory details. |
| 509 | |
| 510 | |
| 511 | TRACE_HEADER_DESC = Descriptor([ |
| 512 | ("magic", "u64"), |
| 513 | ("size", "u64"), |
| 514 | ("attr_size", "u64"), |
| 515 | ("attrs_offset", "u64"), |
| 516 | ("attrs_size", "u64"), |
| 517 | ("data_offset", "u64"), |
| 518 | ("data_size", "u64"), |
| 519 | ("event_types_offset", "u64"), |
| 520 | ("event_types_size", "u64") |
| 521 | ]) |
| 522 | |
| 523 | |
| 524 | PERF_EVENT_ATTR_DESC = Descriptor([ |
| 525 | ("type", "u32"), |
| 526 | ("size", "u32"), |
| 527 | ("config", "u64"), |
| 528 | ("sample_period_or_freq", "u64"), |
| 529 | ("sample_type", "u64"), |
| 530 | ("read_format", "u64"), |
| 531 | ("flags", "u64"), |
| 532 | ("wakeup_events_or_watermark", "u32"), |
| 533 | ("bt_type", "u32"), |
| 534 | ("bp_addr", "u64"), |
| 535 | ("bp_len", "u64"), |
| 536 | ]) |
| 537 | |
| 538 | |
| 539 | PERF_EVENT_HEADER_DESC = Descriptor([ |
| 540 | ("type", "u32"), |
| 541 | ("misc", "u16"), |
| 542 | ("size", "u16") |
| 543 | ]) |
| 544 | |
| 545 | |
| 546 | PERF_MMAP_EVENT_BODY_DESC = Descriptor([ |
| 547 | ("pid", "u32"), |
| 548 | ("tid", "u32"), |
| 549 | ("addr", "u64"), |
| 550 | ("len", "u64"), |
| 551 | ("pgoff", "u64") |
| 552 | ]) |
| 553 | |
| 554 | |
| 555 | # perf_event_attr.sample_type bits control the set of |
| 556 | # perf_sample_event fields. |
| 557 | PERF_SAMPLE_IP = 1 << 0 |
| 558 | PERF_SAMPLE_TID = 1 << 1 |
| 559 | PERF_SAMPLE_TIME = 1 << 2 |
| 560 | PERF_SAMPLE_ADDR = 1 << 3 |
| 561 | PERF_SAMPLE_READ = 1 << 4 |
| 562 | PERF_SAMPLE_CALLCHAIN = 1 << 5 |
| 563 | PERF_SAMPLE_ID = 1 << 6 |
| 564 | PERF_SAMPLE_CPU = 1 << 7 |
| 565 | PERF_SAMPLE_PERIOD = 1 << 8 |
| 566 | PERF_SAMPLE_STREAM_ID = 1 << 9 |
| 567 | PERF_SAMPLE_RAW = 1 << 10 |
| 568 | |
| 569 | |
| 570 | PERF_SAMPLE_EVENT_BODY_FIELDS = [ |
| 571 | ("ip", "u64", PERF_SAMPLE_IP), |
| 572 | ("pid", "u32", PERF_SAMPLE_TID), |
| 573 | ("tid", "u32", PERF_SAMPLE_TID), |
| 574 | ("time", "u64", PERF_SAMPLE_TIME), |
| 575 | ("addr", "u64", PERF_SAMPLE_ADDR), |
| 576 | ("id", "u64", PERF_SAMPLE_ID), |
| 577 | ("stream_id", "u64", PERF_SAMPLE_STREAM_ID), |
| 578 | ("cpu", "u32", PERF_SAMPLE_CPU), |
| 579 | ("res", "u32", PERF_SAMPLE_CPU), |
| 580 | ("period", "u64", PERF_SAMPLE_PERIOD), |
| 581 | # Don't want to handle read format that comes after the period and |
| 582 | # before the callchain and has variable size. |
| 583 | ("nr", "u64", PERF_SAMPLE_CALLCHAIN) |
| 584 | # Raw data follows the callchain and is ignored. |
| 585 | ] |
| 586 | |
| 587 | |
| 588 | PERF_SAMPLE_EVENT_IP_FORMAT = "u64" |
| 589 | |
| 590 | |
| 591 | PERF_RECORD_MMAP = 1 |
| 592 | PERF_RECORD_SAMPLE = 9 |
| 593 | |
| 594 | |
| 595 | class TraceReader(object): |
| 596 | """Perf (linux-2.6/tools/perf) trace file reader.""" |
| 597 | |
| 598 | _TRACE_HEADER_MAGIC = 4993446653023372624 |
| 599 | |
| 600 | def __init__(self, trace_name): |
| 601 | self.trace_file = open(trace_name, "r") |
| 602 | self.trace = mmap.mmap(self.trace_file.fileno(), 0, mmap.MAP_PRIVATE) |
| 603 | self.trace_header = TRACE_HEADER_DESC.Read(self.trace, 0) |
| 604 | if self.trace_header.magic != TraceReader._TRACE_HEADER_MAGIC: |
| 605 | print >>sys.stderr, "Warning: unsupported trace header magic" |
| 606 | self.offset = self.trace_header.data_offset |
| 607 | self.limit = self.trace_header.data_offset + self.trace_header.data_size |
| 608 | assert self.limit <= self.trace.size(), \ |
| 609 | "Trace data limit exceeds trace file size" |
| 610 | self.header_size = ctypes.sizeof(PERF_EVENT_HEADER_DESC.ctype) |
| 611 | assert self.trace_header.attrs_size != 0, \ |
| 612 | "No perf event attributes found in the trace" |
| 613 | perf_event_attr = PERF_EVENT_ATTR_DESC.Read(self.trace, |
| 614 | self.trace_header.attrs_offset) |
| 615 | self.sample_event_body_desc = self._SampleEventBodyDesc( |
| 616 | perf_event_attr.sample_type) |
| 617 | self.callchain_supported = \ |
| 618 | (perf_event_attr.sample_type & PERF_SAMPLE_CALLCHAIN) != 0 |
| 619 | if self.callchain_supported: |
| 620 | self.ip_struct = Descriptor.CTYPE_MAP[PERF_SAMPLE_EVENT_IP_FORMAT] |
| 621 | self.ip_size = ctypes.sizeof(self.ip_struct) |
| 622 | |
| 623 | def ReadEventHeader(self): |
| 624 | if self.offset >= self.limit: |
| 625 | return None, 0 |
| 626 | offset = self.offset |
| 627 | header = PERF_EVENT_HEADER_DESC.Read(self.trace, self.offset) |
| 628 | self.offset += header.size |
| 629 | return header, offset |
| 630 | |
| 631 | def ReadMmap(self, header, offset): |
| 632 | mmap_info = PERF_MMAP_EVENT_BODY_DESC.Read(self.trace, |
| 633 | offset + self.header_size) |
Ben Murdoch | 3fb3ca8 | 2011-12-02 17:19:32 +0000 | [diff] [blame] | 634 | # Read null-terminated filename. |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 635 | filename = self.trace[offset + self.header_size + ctypes.sizeof(mmap_info): |
Ben Murdoch | 3fb3ca8 | 2011-12-02 17:19:32 +0000 | [diff] [blame] | 636 | offset + header.size] |
| 637 | mmap_info.filename = filename[:filename.find(chr(0))] |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 638 | return mmap_info |
| 639 | |
| 640 | def ReadSample(self, header, offset): |
| 641 | sample = self.sample_event_body_desc.Read(self.trace, |
| 642 | offset + self.header_size) |
| 643 | if not self.callchain_supported: |
| 644 | return sample |
| 645 | sample.ips = [] |
| 646 | offset += self.header_size + ctypes.sizeof(sample) |
| 647 | for _ in xrange(sample.nr): |
| 648 | sample.ips.append( |
| 649 | self.ip_struct.from_buffer(self.trace, offset).value) |
| 650 | offset += self.ip_size |
| 651 | return sample |
| 652 | |
| 653 | def Dispose(self): |
| 654 | self.trace.close() |
| 655 | self.trace_file.close() |
| 656 | |
| 657 | def _SampleEventBodyDesc(self, sample_type): |
| 658 | assert (sample_type & PERF_SAMPLE_READ) == 0, \ |
| 659 | "Can't hande read format in samples" |
| 660 | fields = [(field, format) |
| 661 | for (field, format, bit) in PERF_SAMPLE_EVENT_BODY_FIELDS |
| 662 | if (bit & sample_type) != 0] |
| 663 | return Descriptor(fields) |
| 664 | |
| 665 | |
| 666 | OBJDUMP_SECTION_HEADER_RE = re.compile( |
| 667 | r"^\s*\d+\s(\.\S+)\s+[a-f0-9]") |
| 668 | OBJDUMP_SYMBOL_LINE_RE = re.compile( |
| 669 | r"^([a-f0-9]+)\s(.{7})\s(\S+)\s+([a-f0-9]+)\s+(?:\.hidden\s+)?(.*)$") |
| 670 | OBJDUMP_DYNAMIC_SYMBOLS_START_RE = re.compile( |
Ben Murdoch | 85b7179 | 2012-04-11 18:30:58 +0100 | [diff] [blame^] | 671 | r"^DYNAMIC SYMBOL TABLE") |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 672 | KERNEL_ALLSYMS_FILE = "/proc/kallsyms" |
| 673 | PERF_KERNEL_ALLSYMS_RE = re.compile( |
| 674 | r".*kallsyms.*") |
| 675 | KERNEL_ALLSYMS_LINE_RE = re.compile( |
| 676 | r"^([a-f0-9]+)\s(?:t|T)\s(\S+)$") |
| 677 | |
| 678 | |
| 679 | class LibraryRepo(object): |
| 680 | def __init__(self): |
| 681 | self.infos = [] |
| 682 | self.names = set() |
| 683 | self.ticks = {} |
| 684 | |
| 685 | def Load(self, mmap_info, code_map, options): |
| 686 | # Skip kernel mmaps when requested using the fact that their tid |
| 687 | # is 0. |
| 688 | if mmap_info.tid == 0 and not options.kernel: |
| 689 | return True |
| 690 | if PERF_KERNEL_ALLSYMS_RE.match(mmap_info.filename): |
| 691 | return self._LoadKernelSymbols(code_map) |
| 692 | self.infos.append(mmap_info) |
| 693 | mmap_info.ticks = 0 |
| 694 | mmap_info.unique_name = self._UniqueMmapName(mmap_info) |
| 695 | if not os.path.exists(mmap_info.filename): |
| 696 | return True |
| 697 | # Request section headers (-h), symbols (-t), and dynamic symbols |
| 698 | # (-T) from objdump. |
| 699 | # Unfortunately, section headers span two lines, so we have to |
| 700 | # keep the just seen section name (from the first line in each |
| 701 | # section header) in the after_section variable. |
| 702 | process = subprocess.Popen( |
| 703 | "%s -h -t -T -C %s" % (OBJDUMP_BIN, mmap_info.filename), |
| 704 | shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT) |
| 705 | pipe = process.stdout |
| 706 | after_section = None |
| 707 | code_sections = set() |
| 708 | reloc_sections = set() |
| 709 | dynamic = False |
| 710 | try: |
| 711 | for line in pipe: |
| 712 | if after_section: |
| 713 | if line.find("CODE") != -1: |
| 714 | code_sections.add(after_section) |
| 715 | if line.find("RELOC") != -1: |
| 716 | reloc_sections.add(after_section) |
| 717 | after_section = None |
| 718 | continue |
| 719 | |
| 720 | match = OBJDUMP_SECTION_HEADER_RE.match(line) |
| 721 | if match: |
| 722 | after_section = match.group(1) |
| 723 | continue |
| 724 | |
| 725 | if OBJDUMP_DYNAMIC_SYMBOLS_START_RE.match(line): |
| 726 | dynamic = True |
| 727 | continue |
| 728 | |
| 729 | match = OBJDUMP_SYMBOL_LINE_RE.match(line) |
| 730 | if match: |
| 731 | start_address = int(match.group(1), 16) |
| 732 | origin_offset = start_address |
| 733 | flags = match.group(2) |
| 734 | section = match.group(3) |
| 735 | if section in code_sections: |
| 736 | if dynamic or section in reloc_sections: |
| 737 | start_address += mmap_info.addr |
| 738 | size = int(match.group(4), 16) |
| 739 | name = match.group(5) |
| 740 | origin = mmap_info.filename |
| 741 | code_map.Add(Code(name, start_address, start_address + size, |
| 742 | origin, origin_offset)) |
| 743 | finally: |
| 744 | pipe.close() |
| 745 | assert process.wait() == 0, "Failed to objdump %s" % mmap_info.filename |
| 746 | |
| 747 | def Tick(self, pc): |
| 748 | for i, mmap_info in enumerate(self.infos): |
| 749 | if mmap_info.addr <= pc < (mmap_info.addr + mmap_info.len): |
| 750 | mmap_info.ticks += 1 |
| 751 | self.infos[0], self.infos[i] = mmap_info, self.infos[0] |
| 752 | return True |
| 753 | return False |
| 754 | |
| 755 | def _UniqueMmapName(self, mmap_info): |
| 756 | name = mmap_info.filename |
| 757 | index = 1 |
| 758 | while name in self.names: |
| 759 | name = "%s-%d" % (mmap_info.filename, index) |
| 760 | index += 1 |
| 761 | self.names.add(name) |
| 762 | return name |
| 763 | |
| 764 | def _LoadKernelSymbols(self, code_map): |
| 765 | if not os.path.exists(KERNEL_ALLSYMS_FILE): |
| 766 | print >>sys.stderr, "Warning: %s not found" % KERNEL_ALLSYMS_FILE |
| 767 | return False |
| 768 | kallsyms = open(KERNEL_ALLSYMS_FILE, "r") |
| 769 | code = None |
| 770 | for line in kallsyms: |
| 771 | match = KERNEL_ALLSYMS_LINE_RE.match(line) |
| 772 | if match: |
| 773 | start_address = int(match.group(1), 16) |
| 774 | end_address = start_address |
| 775 | name = match.group(2) |
| 776 | if code: |
| 777 | code.end_address = start_address |
| 778 | code_map.Add(code, 16) |
| 779 | code = Code(name, start_address, end_address, "kernel", 0) |
| 780 | return True |
| 781 | |
| 782 | |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 783 | def PrintReport(code_map, library_repo, arch, ticks, options): |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 784 | print "Ticks per symbol:" |
| 785 | used_code = [code for code in code_map.UsedCode()] |
| 786 | used_code.sort(key=lambda x: x.self_ticks, reverse=True) |
| 787 | for i, code in enumerate(used_code): |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 788 | code_ticks = code.self_ticks |
| 789 | print "%10d %5.1f%% %s [%s]" % (code_ticks, 100. * code_ticks / ticks, |
| 790 | code.FullName(), code.origin) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 791 | if options.disasm_all or i < options.disasm_top: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 792 | code.PrintAnnotated(arch, options) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 793 | print |
| 794 | print "Ticks per library:" |
| 795 | mmap_infos = [m for m in library_repo.infos] |
| 796 | mmap_infos.sort(key=lambda m: m.ticks, reverse=True) |
| 797 | for mmap_info in mmap_infos: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 798 | mmap_ticks = mmap_info.ticks |
| 799 | print "%10d %5.1f%% %s" % (mmap_ticks, 100. * mmap_ticks / ticks, |
| 800 | mmap_info.unique_name) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 801 | |
| 802 | |
| 803 | def PrintDot(code_map, options): |
| 804 | print "digraph G {" |
| 805 | for code in code_map.UsedCode(): |
| 806 | if code.self_ticks < 10: |
| 807 | continue |
| 808 | print "n%d [shape=box,label=\"%s\"];" % (code.id, code.name) |
| 809 | if code.callee_ticks: |
| 810 | for callee, ticks in code.callee_ticks.iteritems(): |
| 811 | print "n%d -> n%d [label=\"%d\"];" % (code.id, callee.id, ticks) |
| 812 | print "}" |
| 813 | |
| 814 | |
| 815 | if __name__ == "__main__": |
| 816 | parser = optparse.OptionParser(USAGE) |
| 817 | parser.add_option("--snapshot-log", |
| 818 | default="obj/release/snapshot.log", |
| 819 | help="V8 snapshot log file name [default: %default]") |
| 820 | parser.add_option("--log", |
| 821 | default="v8.log", |
| 822 | help="V8 log file name [default: %default]") |
| 823 | parser.add_option("--snapshot", |
| 824 | default=False, |
| 825 | action="store_true", |
| 826 | help="process V8 snapshot log [default: %default]") |
| 827 | parser.add_option("--trace", |
| 828 | default="perf.data", |
| 829 | help="perf trace file name [default: %default]") |
| 830 | parser.add_option("--kernel", |
| 831 | default=False, |
| 832 | action="store_true", |
| 833 | help="process kernel entries [default: %default]") |
| 834 | parser.add_option("--disasm-top", |
| 835 | default=0, |
| 836 | type="int", |
| 837 | help=("number of top symbols to disassemble and annotate " |
| 838 | "[default: %default]")) |
| 839 | parser.add_option("--disasm-all", |
| 840 | default=False, |
| 841 | action="store_true", |
| 842 | help=("disassemble and annotate all used symbols " |
| 843 | "[default: %default]")) |
| 844 | parser.add_option("--dot", |
| 845 | default=False, |
| 846 | action="store_true", |
| 847 | help="produce dot output (WIP) [default: %default]") |
| 848 | parser.add_option("--quiet", "-q", |
| 849 | default=False, |
| 850 | action="store_true", |
| 851 | help="no auxiliary messages [default: %default]") |
| 852 | options, args = parser.parse_args() |
| 853 | |
| 854 | if not options.quiet: |
| 855 | if options.snapshot: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 856 | print "V8 logs: %s, %s, %s.ll" % (options.snapshot_log, |
| 857 | options.log, |
| 858 | options.log) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 859 | else: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 860 | print "V8 log: %s, %s.ll (no snapshot)" % (options.log, options.log) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 861 | print "Perf trace file: %s" % options.trace |
| 862 | |
| 863 | # Stats. |
| 864 | events = 0 |
| 865 | ticks = 0 |
| 866 | missed_ticks = 0 |
| 867 | really_missed_ticks = 0 |
| 868 | mmap_time = 0 |
| 869 | sample_time = 0 |
| 870 | |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 871 | # Process the snapshot log to fill the snapshot name map. |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 872 | snapshot_name_map = {} |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 873 | if options.snapshot: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 874 | snapshot_log_reader = SnapshotLogReader(log_name=options.snapshot_log) |
| 875 | snapshot_name_map = snapshot_log_reader.ReadNameMap() |
| 876 | |
| 877 | # Initialize the log reader. |
| 878 | code_map = CodeMap() |
| 879 | log_reader = LogReader(log_name=options.log + ".ll", |
| 880 | code_map=code_map, |
| 881 | snapshot_pos_to_name=snapshot_name_map) |
| 882 | if not options.quiet: |
| 883 | print "Generated code architecture: %s" % log_reader.arch |
| 884 | print |
| 885 | sys.stdout.flush() |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 886 | |
| 887 | # Process the code and trace logs. |
| 888 | library_repo = LibraryRepo() |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 889 | log_reader.ReadUpToGC() |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 890 | trace_reader = TraceReader(options.trace) |
| 891 | while True: |
| 892 | header, offset = trace_reader.ReadEventHeader() |
| 893 | if not header: |
| 894 | break |
| 895 | events += 1 |
| 896 | if header.type == PERF_RECORD_MMAP: |
| 897 | start = time.time() |
| 898 | mmap_info = trace_reader.ReadMmap(header, offset) |
| 899 | if mmap_info.filename == V8_GC_FAKE_MMAP: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 900 | log_reader.ReadUpToGC() |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 901 | else: |
| 902 | library_repo.Load(mmap_info, code_map, options) |
| 903 | mmap_time += time.time() - start |
| 904 | elif header.type == PERF_RECORD_SAMPLE: |
| 905 | ticks += 1 |
| 906 | start = time.time() |
| 907 | sample = trace_reader.ReadSample(header, offset) |
| 908 | code = code_map.Find(sample.ip) |
| 909 | if code: |
| 910 | code.Tick(sample.ip) |
| 911 | else: |
| 912 | missed_ticks += 1 |
| 913 | if not library_repo.Tick(sample.ip) and not code: |
| 914 | really_missed_ticks += 1 |
| 915 | if trace_reader.callchain_supported: |
| 916 | for ip in sample.ips: |
| 917 | caller_code = code_map.Find(ip) |
| 918 | if caller_code: |
| 919 | if code: |
| 920 | caller_code.CalleeTick(code) |
| 921 | code = caller_code |
| 922 | sample_time += time.time() - start |
| 923 | |
| 924 | if options.dot: |
| 925 | PrintDot(code_map, options) |
| 926 | else: |
Ben Murdoch | 257744e | 2011-11-30 15:57:28 +0000 | [diff] [blame] | 927 | PrintReport(code_map, library_repo, log_reader.arch, ticks, options) |
Ben Murdoch | f87a203 | 2010-10-22 12:50:53 +0100 | [diff] [blame] | 928 | |
| 929 | if not options.quiet: |
| 930 | print |
| 931 | print "Stats:" |
| 932 | print "%10d total trace events" % events |
| 933 | print "%10d total ticks" % ticks |
| 934 | print "%10d ticks not in symbols" % missed_ticks |
| 935 | print "%10d unaccounted ticks" % really_missed_ticks |
| 936 | print "%10d total symbols" % len([c for c in code_map.AllCode()]) |
| 937 | print "%10d used symbols" % len([c for c in code_map.UsedCode()]) |
| 938 | print "%9.2fs library processing time" % mmap_time |
| 939 | print "%9.2fs tick processing time" % sample_time |
| 940 | |
| 941 | log_reader.Dispose() |
| 942 | trace_reader.Dispose() |