OLD | NEW |
---|---|
1 #!/usr/bin/env python | 1 #!/usr/bin/env python |
2 # | 2 # |
3 # Copyright 2012 the V8 project authors. All rights reserved. | 3 # Copyright 2012 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 48 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
59 default. That's not enough for "-c 10000". Set it to some higher value: | 59 default. That's not enough for "-c 10000". Set it to some higher value: |
60 $ echo 10000000 | sudo tee /proc/sys/kernel/perf_event_max_sample_rate | 60 $ echo 10000000 | sudo tee /proc/sys/kernel/perf_event_max_sample_rate |
61 You can also make the warning about kernel address maps go away: | 61 You can also make the warning about kernel address maps go away: |
62 $ echo 0 | sudo tee /proc/sys/kernel/kptr_restrict | 62 $ echo 0 | sudo tee /proc/sys/kernel/kptr_restrict |
63 | 63 |
64 We have a convenience script that handles all of the above for you: | 64 We have a convenience script that handles all of the above for you: |
65 $ tools/run-llprof.sh ./d8 bench.js | 65 $ tools/run-llprof.sh ./d8 bench.js |
66 | 66 |
67 Examples: | 67 Examples: |
68 # Print flat profile with annotated disassembly for the 10 top | 68 # Print flat profile with annotated disassembly for the 10 top |
69 # symbols. Use default log names and include the snapshot log. | 69 # symbols. Use default log names. |
70 $ %prog --snapshot --disasm-top=10 | 70 $ %prog --disasm-top=10 |
71 | 71 |
72 # Print flat profile with annotated disassembly for all used symbols. | 72 # Print flat profile with annotated disassembly for all used symbols. |
73 # Use default log names and include kernel symbols into analysis. | 73 # Use default log names and include kernel symbols into analysis. |
74 $ %prog --disasm-all --kernel | 74 $ %prog --disasm-all --kernel |
75 | 75 |
76 # Print flat profile. Use custom log names. | 76 # Print flat profile. Use custom log names. |
77 $ %prog --log=foo.log --snapshot-log=snap-foo.log --trace=foo.data --snapshot | 77 $ %prog --log=foo.log --trace=foo.data |
78 """ | 78 """ |
79 | 79 |
80 | 80 |
81 JS_ORIGIN = "js" | 81 JS_ORIGIN = "js" |
82 JS_SNAPSHOT_ORIGIN = "js-snapshot" | 82 |
83 | 83 |
84 class Code(object): | 84 class Code(object): |
85 """Code object.""" | 85 """Code object.""" |
86 | 86 |
87 _id = 0 | 87 _id = 0 |
88 UNKNOWN = 0 | 88 UNKNOWN = 0 |
89 V8INTERNAL = 1 | 89 V8INTERNAL = 1 |
90 FULL_CODEGEN = 2 | 90 FULL_CODEGEN = 2 |
91 OPTIMIZED = 3 | 91 OPTIMIZED = 3 |
92 | 92 |
(...skipping 99 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
192 | 192 |
193 def __str__(self): | 193 def __str__(self): |
194 return "%s [0x%x, 0x%x) size: %d origin: %s" % ( | 194 return "%s [0x%x, 0x%x) size: %d origin: %s" % ( |
195 self.name, | 195 self.name, |
196 self.start_address, | 196 self.start_address, |
197 self.end_address, | 197 self.end_address, |
198 self.end_address - self.start_address, | 198 self.end_address - self.start_address, |
199 self.origin) | 199 self.origin) |
200 | 200 |
201 def _GetDisasmLines(self, arch, options): | 201 def _GetDisasmLines(self, arch, options): |
202 if self.origin == JS_ORIGIN or self.origin == JS_SNAPSHOT_ORIGIN: | 202 inplace = True |
203 inplace = False | 203 filename = self.origin |
204 filename = options.log + ".ll" | |
205 else: | |
206 inplace = True | |
207 filename = self.origin | |
208 return disasm.GetDisasmLines(filename, | 204 return disasm.GetDisasmLines(filename, |
209 self.origin_offset, | 205 self.origin_offset, |
210 self.end_address - self.start_address, | 206 self.end_address - self.start_address, |
211 arch, | 207 arch, |
212 inplace) | 208 inplace) |
213 | 209 |
214 | 210 |
215 class CodePage(object): | 211 class CodePage(object): |
216 """Group of adjacent code objects.""" | 212 """Group of adjacent code objects.""" |
217 | 213 |
(...skipping 103 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
321 | 317 |
322 | 318 |
323 class CodeInfo(object): | 319 class CodeInfo(object): |
324 """Generic info about generated code objects.""" | 320 """Generic info about generated code objects.""" |
325 | 321 |
326 def __init__(self, arch, header_size): | 322 def __init__(self, arch, header_size): |
327 self.arch = arch | 323 self.arch = arch |
328 self.header_size = header_size | 324 self.header_size = header_size |
329 | 325 |
330 | 326 |
331 class SnapshotLogReader(object): | |
332 """V8 snapshot log reader.""" | |
333 | |
334 _SNAPSHOT_CODE_NAME_RE = re.compile( | |
335 r"snapshot-code-name,(\d+),\"(.*)\"") | |
336 | |
337 def __init__(self, log_name): | |
338 self.log_name = log_name | |
339 | |
340 def ReadNameMap(self): | |
341 log = open(self.log_name, "r") | |
342 try: | |
343 snapshot_pos_to_name = {} | |
344 for line in log: | |
345 match = SnapshotLogReader._SNAPSHOT_CODE_NAME_RE.match(line) | |
346 if match: | |
347 pos = int(match.group(1)) | |
348 name = match.group(2) | |
349 snapshot_pos_to_name[pos] = name | |
350 finally: | |
351 log.close() | |
352 return snapshot_pos_to_name | |
353 | |
354 | |
355 class LogReader(object): | 327 class LogReader(object): |
356 """V8 low-level (binary) log reader.""" | 328 """V8 low-level (binary) log reader.""" |
357 | 329 |
358 _ARCH_TO_POINTER_TYPE_MAP = { | 330 _ARCH_TO_POINTER_TYPE_MAP = { |
359 "ia32": ctypes.c_uint32, | 331 "ia32": ctypes.c_uint32, |
360 "arm": ctypes.c_uint32, | 332 "arm": ctypes.c_uint32, |
361 "mips": ctypes.c_uint32, | 333 "mips": ctypes.c_uint32, |
362 "x64": ctypes.c_uint64, | 334 "x64": ctypes.c_uint64, |
363 "arm64": ctypes.c_uint64 | 335 "arm64": ctypes.c_uint64 |
364 } | 336 } |
365 | 337 |
366 _CODE_CREATE_TAG = "C" | 338 _CODE_CREATE_TAG = "C" |
367 _CODE_MOVE_TAG = "M" | 339 _CODE_MOVE_TAG = "M" |
368 _SNAPSHOT_POSITION_TAG = "P" | 340 _SNAPSHOT_POSITION_TAG = "P" |
Yang
2016/03/15 10:13:19
This is no longer necessary?
Stefano Sanfilippo
2016/04/04 16:22:30
Removed, together with all the related code.
| |
369 _CODE_MOVING_GC_TAG = "G" | 341 _CODE_MOVING_GC_TAG = "G" |
370 | 342 |
371 def __init__(self, log_name, code_map, snapshot_pos_to_name): | 343 def __init__(self, log_name, code_map): |
372 self.log_file = open(log_name, "r") | 344 self.log_file = open(log_name, "r") |
373 self.log = mmap.mmap(self.log_file.fileno(), 0, mmap.MAP_PRIVATE) | 345 self.log = mmap.mmap(self.log_file.fileno(), 0, mmap.MAP_PRIVATE) |
374 self.log_pos = 0 | 346 self.log_pos = 0 |
375 self.code_map = code_map | 347 self.code_map = code_map |
376 self.snapshot_pos_to_name = snapshot_pos_to_name | |
377 self.address_to_snapshot_name = {} | |
378 | 348 |
379 self.arch = self.log[:self.log.find("\0")] | 349 self.arch = self.log[:self.log.find("\0")] |
380 self.log_pos += len(self.arch) + 1 | 350 self.log_pos += len(self.arch) + 1 |
381 assert self.arch in LogReader._ARCH_TO_POINTER_TYPE_MAP, \ | 351 assert self.arch in LogReader._ARCH_TO_POINTER_TYPE_MAP, \ |
382 "Unsupported architecture %s" % self.arch | 352 "Unsupported architecture %s" % self.arch |
383 pointer_type = LogReader._ARCH_TO_POINTER_TYPE_MAP[self.arch] | 353 pointer_type = LogReader._ARCH_TO_POINTER_TYPE_MAP[self.arch] |
384 | 354 |
385 self.code_create_struct = LogReader._DefineStruct([ | 355 self.code_create_struct = LogReader._DefineStruct([ |
386 ("name_size", ctypes.c_int32), | 356 ("name_size", ctypes.c_int32), |
387 ("code_address", pointer_type), | 357 ("code_address", pointer_type), |
388 ("code_size", ctypes.c_int32)]) | 358 ("code_size", ctypes.c_int32)]) |
389 | 359 |
390 self.code_move_struct = LogReader._DefineStruct([ | 360 self.code_move_struct = LogReader._DefineStruct([ |
391 ("from_address", pointer_type), | 361 ("from_address", pointer_type), |
392 ("to_address", pointer_type)]) | 362 ("to_address", pointer_type)]) |
393 | 363 |
394 self.code_delete_struct = LogReader._DefineStruct([ | 364 self.code_delete_struct = LogReader._DefineStruct([ |
395 ("address", pointer_type)]) | 365 ("address", pointer_type)]) |
396 | 366 |
397 self.snapshot_position_struct = LogReader._DefineStruct([ | 367 self.snapshot_position_struct = LogReader._DefineStruct([ |
398 ("address", pointer_type), | 368 ("address", pointer_type), |
399 ("position", ctypes.c_int32)]) | 369 ("position", ctypes.c_int32)]) |
400 | 370 |
401 def ReadUpToGC(self): | 371 def ReadUpToGC(self): |
402 while self.log_pos < self.log.size(): | 372 while self.log_pos < self.log.size(): |
403 tag = self.log[self.log_pos] | 373 tag = self.log[self.log_pos] |
404 self.log_pos += 1 | 374 self.log_pos += 1 |
405 | 375 |
406 if tag == LogReader._CODE_MOVING_GC_TAG: | 376 if tag == LogReader._CODE_MOVING_GC_TAG: |
407 self.address_to_snapshot_name.clear() | |
408 return | 377 return |
409 | 378 |
410 if tag == LogReader._CODE_CREATE_TAG: | 379 if tag == LogReader._CODE_CREATE_TAG: |
411 event = self.code_create_struct.from_buffer(self.log, self.log_pos) | 380 event = self.code_create_struct.from_buffer(self.log, self.log_pos) |
412 self.log_pos += ctypes.sizeof(event) | 381 self.log_pos += ctypes.sizeof(event) |
413 start_address = event.code_address | 382 start_address = event.code_address |
414 end_address = start_address + event.code_size | 383 end_address = start_address + event.code_size |
415 if start_address in self.address_to_snapshot_name: | 384 name = self.log[self.log_pos:self.log_pos + event.name_size] |
416 name = self.address_to_snapshot_name[start_address] | 385 origin = JS_ORIGIN |
417 origin = JS_SNAPSHOT_ORIGIN | |
418 else: | |
419 name = self.log[self.log_pos:self.log_pos + event.name_size] | |
420 origin = JS_ORIGIN | |
421 self.log_pos += event.name_size | 386 self.log_pos += event.name_size |
422 origin_offset = self.log_pos | 387 origin_offset = self.log_pos |
423 self.log_pos += event.code_size | 388 self.log_pos += event.code_size |
424 code = Code(name, start_address, end_address, origin, origin_offset) | 389 code = Code(name, start_address, end_address, origin, origin_offset) |
425 conficting_code = self.code_map.Find(start_address) | 390 conficting_code = self.code_map.Find(start_address) |
426 if conficting_code: | 391 if conficting_code: |
427 if not (conficting_code.start_address == code.start_address and | 392 if not (conficting_code.start_address == code.start_address and |
428 conficting_code.end_address == code.end_address): | 393 conficting_code.end_address == code.end_address): |
429 self.code_map.Remove(conficting_code) | 394 self.code_map.Remove(conficting_code) |
430 else: | 395 else: |
(...skipping 20 matching lines...) Expand all Loading... | |
451 continue | 416 continue |
452 assert code.start_address == old_start_address, \ | 417 assert code.start_address == old_start_address, \ |
453 "Inexact move address %x for %s" % (old_start_address, code) | 418 "Inexact move address %x for %s" % (old_start_address, code) |
454 self.code_map.Remove(code) | 419 self.code_map.Remove(code) |
455 size = code.end_address - code.start_address | 420 size = code.end_address - code.start_address |
456 code.start_address = new_start_address | 421 code.start_address = new_start_address |
457 code.end_address = new_start_address + size | 422 code.end_address = new_start_address + size |
458 self.code_map.Add(code) | 423 self.code_map.Add(code) |
459 continue | 424 continue |
460 | 425 |
461 if tag == LogReader._SNAPSHOT_POSITION_TAG: | 426 if tag == LogReader._SNAPSHOT_POSITION_TAG: |
Yang
2016/03/15 10:13:19
This whole if-block could be removed?
Stefano Sanfilippo
2016/04/04 16:22:30
Done.
| |
462 event = self.snapshot_position_struct.from_buffer(self.log, | 427 event = self.snapshot_position_struct.from_buffer(self.log, |
463 self.log_pos) | 428 self.log_pos) |
464 self.log_pos += ctypes.sizeof(event) | 429 self.log_pos += ctypes.sizeof(event) |
465 start_address = event.address | 430 start_address = event.address |
466 snapshot_pos = event.position | 431 snapshot_pos = event.position |
467 if snapshot_pos in self.snapshot_pos_to_name: | |
468 self.address_to_snapshot_name[start_address] = \ | |
469 self.snapshot_pos_to_name[snapshot_pos] | |
470 continue | 432 continue |
471 | 433 |
472 assert False, "Unknown tag %s" % tag | 434 assert False, "Unknown tag %s" % tag |
473 | 435 |
474 def Dispose(self): | 436 def Dispose(self): |
475 self.log.close() | 437 self.log.close() |
476 self.log_file.close() | 438 self.log_file.close() |
477 | 439 |
478 @staticmethod | 440 @staticmethod |
479 def _DefineStruct(fields): | 441 def _DefineStruct(fields): |
(...skipping 397 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
877 continue | 839 continue |
878 print "n%d [shape=box,label=\"%s\"];" % (code.id, code.name) | 840 print "n%d [shape=box,label=\"%s\"];" % (code.id, code.name) |
879 if code.callee_ticks: | 841 if code.callee_ticks: |
880 for callee, ticks in code.callee_ticks.iteritems(): | 842 for callee, ticks in code.callee_ticks.iteritems(): |
881 print "n%d -> n%d [label=\"%d\"];" % (code.id, callee.id, ticks) | 843 print "n%d -> n%d [label=\"%d\"];" % (code.id, callee.id, ticks) |
882 print "}" | 844 print "}" |
883 | 845 |
884 | 846 |
885 if __name__ == "__main__": | 847 if __name__ == "__main__": |
886 parser = optparse.OptionParser(USAGE) | 848 parser = optparse.OptionParser(USAGE) |
887 parser.add_option("--snapshot-log", | |
888 default="obj/release/snapshot.log", | |
889 help="V8 snapshot log file name [default: %default]") | |
890 parser.add_option("--log", | 849 parser.add_option("--log", |
891 default="v8.log", | 850 default="v8.log", |
892 help="V8 log file name [default: %default]") | 851 help="V8 log file name [default: %default]") |
893 parser.add_option("--snapshot", | |
894 default=False, | |
895 action="store_true", | |
896 help="process V8 snapshot log [default: %default]") | |
897 parser.add_option("--trace", | 852 parser.add_option("--trace", |
898 default="perf.data", | 853 default="perf.data", |
899 help="perf trace file name [default: %default]") | 854 help="perf trace file name [default: %default]") |
900 parser.add_option("--kernel", | 855 parser.add_option("--kernel", |
901 default=False, | 856 default=False, |
902 action="store_true", | 857 action="store_true", |
903 help="process kernel entries [default: %default]") | 858 help="process kernel entries [default: %default]") |
904 parser.add_option("--disasm-top", | 859 parser.add_option("--disasm-top", |
905 default=0, | 860 default=0, |
906 type="int", | 861 type="int", |
(...skipping 17 matching lines...) Expand all Loading... | |
924 help="gc fake mmap file [default: %default]") | 879 help="gc fake mmap file [default: %default]") |
925 parser.add_option("--objdump", | 880 parser.add_option("--objdump", |
926 default="/usr/bin/objdump", | 881 default="/usr/bin/objdump", |
927 help="objdump tool to use [default: %default]") | 882 help="objdump tool to use [default: %default]") |
928 parser.add_option("--host-root", | 883 parser.add_option("--host-root", |
929 default="", | 884 default="", |
930 help="Path to the host root [default: %default]") | 885 help="Path to the host root [default: %default]") |
931 options, args = parser.parse_args() | 886 options, args = parser.parse_args() |
932 | 887 |
933 if not options.quiet: | 888 if not options.quiet: |
934 if options.snapshot: | 889 print "V8 log: %s, %s.ll" % (options.log, options.log) |
935 print "V8 logs: %s, %s, %s.ll" % (options.snapshot_log, | |
936 options.log, | |
937 options.log) | |
938 else: | |
939 print "V8 log: %s, %s.ll (no snapshot)" % (options.log, options.log) | |
940 print "Perf trace file: %s" % options.trace | 890 print "Perf trace file: %s" % options.trace |
941 | 891 |
942 V8_GC_FAKE_MMAP = options.gc_fake_mmap | 892 V8_GC_FAKE_MMAP = options.gc_fake_mmap |
943 HOST_ROOT = options.host_root | 893 HOST_ROOT = options.host_root |
944 if os.path.exists(options.objdump): | 894 if os.path.exists(options.objdump): |
945 disasm.OBJDUMP_BIN = options.objdump | 895 disasm.OBJDUMP_BIN = options.objdump |
946 OBJDUMP_BIN = options.objdump | 896 OBJDUMP_BIN = options.objdump |
947 else: | 897 else: |
948 print "Cannot find %s, falling back to default objdump" % options.objdump | 898 print "Cannot find %s, falling back to default objdump" % options.objdump |
949 | 899 |
950 # Stats. | 900 # Stats. |
951 events = 0 | 901 events = 0 |
952 ticks = 0 | 902 ticks = 0 |
953 missed_ticks = 0 | 903 missed_ticks = 0 |
954 really_missed_ticks = 0 | 904 really_missed_ticks = 0 |
955 optimized_ticks = 0 | 905 optimized_ticks = 0 |
956 generated_ticks = 0 | 906 generated_ticks = 0 |
957 v8_internal_ticks = 0 | 907 v8_internal_ticks = 0 |
958 mmap_time = 0 | 908 mmap_time = 0 |
959 sample_time = 0 | 909 sample_time = 0 |
960 | 910 |
961 # Process the snapshot log to fill the snapshot name map. | |
962 snapshot_name_map = {} | |
963 if options.snapshot: | |
964 snapshot_log_reader = SnapshotLogReader(log_name=options.snapshot_log) | |
965 snapshot_name_map = snapshot_log_reader.ReadNameMap() | |
966 | |
967 # Initialize the log reader. | 911 # Initialize the log reader. |
968 code_map = CodeMap() | 912 code_map = CodeMap() |
969 log_reader = LogReader(log_name=options.log + ".ll", | 913 log_reader = LogReader(log_name=options.log + ".ll", |
970 code_map=code_map, | 914 code_map=code_map) |
971 snapshot_pos_to_name=snapshot_name_map) | |
972 if not options.quiet: | 915 if not options.quiet: |
973 print "Generated code architecture: %s" % log_reader.arch | 916 print "Generated code architecture: %s" % log_reader.arch |
974 print | 917 print |
975 sys.stdout.flush() | 918 sys.stdout.flush() |
976 | 919 |
977 # Process the code and trace logs. | 920 # Process the code and trace logs. |
978 library_repo = LibraryRepo() | 921 library_repo = LibraryRepo() |
979 log_reader.ReadUpToGC() | 922 log_reader.ReadUpToGC() |
980 trace_reader = TraceReader(options.trace) | 923 trace_reader = TraceReader(options.trace) |
981 while True: | 924 while True: |
(...skipping 64 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
1046 PrintTicks(optimized_ticks, ticks, "ticks in optimized code") | 989 PrintTicks(optimized_ticks, ticks, "ticks in optimized code") |
1047 PrintTicks(generated_ticks, ticks, "ticks in other lazily compiled code") | 990 PrintTicks(generated_ticks, ticks, "ticks in other lazily compiled code") |
1048 PrintTicks(v8_internal_ticks, ticks, "ticks in v8::internal::*") | 991 PrintTicks(v8_internal_ticks, ticks, "ticks in v8::internal::*") |
1049 print "%10d total symbols" % len([c for c in code_map.AllCode()]) | 992 print "%10d total symbols" % len([c for c in code_map.AllCode()]) |
1050 print "%10d used symbols" % len([c for c in code_map.UsedCode()]) | 993 print "%10d used symbols" % len([c for c in code_map.UsedCode()]) |
1051 print "%9.2fs library processing time" % mmap_time | 994 print "%9.2fs library processing time" % mmap_time |
1052 print "%9.2fs tick processing time" % sample_time | 995 print "%9.2fs tick processing time" % sample_time |
1053 | 996 |
1054 log_reader.Dispose() | 997 log_reader.Dispose() |
1055 trace_reader.Dispose() | 998 trace_reader.Dispose() |
OLD | NEW |