# Copyright 2008 the V8 project authors. All rights reserved. # Redistribution and use in source and binary forms, with or without # modification, are permitted provided that the following conditions are # met: # # * Redistributions of source code must retain the above copyright # notice, this list of conditions and the following disclaimer. # * Redistributions in binary form must reproduce the above # copyright notice, this list of conditions and the following # disclaimer in the documentation and/or other materials provided # with the distribution. # * Neither the name of Google Inc. nor the names of its # contributors may be used to endorse or promote products derived # from this software without specific prior written permission. # # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS # "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT # LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR # A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT # OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, # SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT # LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, # DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY # THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. import csv, splaytree, sys, re from operator import itemgetter import getopt, os, string class CodeEntry(object): def __init__(self, start_addr, name): self.start_addr = start_addr self.tick_count = 0 self.name = name self.stacks = {} def Tick(self, pc, stack): self.tick_count += 1 if len(stack) > 0: stack.insert(0, self.ToString()) stack_key = tuple(stack) self.stacks[stack_key] = self.stacks.setdefault(stack_key, 0) + 1 def RegionTicks(self): return None def SetStartAddress(self, start_addr): self.start_addr = start_addr def ToString(self): return self.name def IsSharedLibraryEntry(self): return False def IsICEntry(self): return False def IsJSFunction(self): return False class SharedLibraryEntry(CodeEntry): def __init__(self, start_addr, name): CodeEntry.__init__(self, start_addr, name) def IsSharedLibraryEntry(self): return True class JSCodeEntry(CodeEntry): def __init__(self, start_addr, name, type, size, assembler): CodeEntry.__init__(self, start_addr, name) self.type = type self.size = size self.assembler = assembler self.region_ticks = None self.builtin_ic_re = re.compile('^(Keyed)?(Call|Load|Store)IC_') def Tick(self, pc, stack): super(JSCodeEntry, self).Tick(pc, stack) if not pc is None: offset = pc - self.start_addr seen = [] narrowest = None narrowest_width = None for region in self.Regions(): if region.Contains(offset): if (not region.name in seen): seen.append(region.name) if narrowest is None or region.Width() < narrowest.Width(): narrowest = region if len(seen) == 0: return if self.region_ticks is None: self.region_ticks = {} for name in seen: if not name in self.region_ticks: self.region_ticks[name] = [0, 0] self.region_ticks[name][0] += 1 if name == narrowest.name: self.region_ticks[name][1] += 1 def RegionTicks(self): return self.region_ticks def Regions(self): if self.assembler: return self.assembler.regions else: return [] def ToString(self): name = self.name if name == '': name = '<anonymous>' elif name.startswith(' '): name = '<anonymous>' + name return self.type + ': ' + name def IsICEntry(self): return self.type in ('CallIC', 'LoadIC', 'StoreIC') or \ (self.type == 'Builtin' and self.builtin_ic_re.match(self.name)) def IsJSFunction(self): return self.type in ('Function', 'LazyCompile', 'Script') class CodeRegion(object): def __init__(self, start_offset, name): self.start_offset = start_offset self.name = name self.end_offset = None def Contains(self, pc): return (self.start_offset <= pc) and (pc <= self.end_offset) def Width(self): return self.end_offset - self.start_offset class Assembler(object): def __init__(self): # Mapping from region ids to open regions self.pending_regions = {} self.regions = [] class FunctionEnumerator(object): def __init__(self): self.known_funcs = {} self.next_func_id = 0 def GetFunctionId(self, name): if not self.known_funcs.has_key(name): self.known_funcs[name] = self.next_func_id self.next_func_id += 1 return self.known_funcs[name] def GetKnownFunctions(self): known_funcs_items = self.known_funcs.items(); known_funcs_items.sort(key = itemgetter(1)) result = [] for func, id_not_used in known_funcs_items: result.append(func) return result VMStates = { 'JS': 0, 'GC': 1, 'COMPILER': 2, 'OTHER': 3, 'EXTERNAL' : 4 } class TickProcessor(object): def __init__(self): self.log_file = '' self.deleted_code = [] self.vm_extent = {} # Map from assembler ids to the pending assembler objects self.pending_assemblers = {} # Map from code addresses the have been allocated but not yet officially # created to their assemblers. self.assemblers = {} self.js_entries = splaytree.SplayTree() self.cpp_entries = splaytree.SplayTree() self.total_number_of_ticks = 0 self.number_of_library_ticks = 0 self.unaccounted_number_of_ticks = 0 self.excluded_number_of_ticks = 0 self.number_of_gc_ticks = 0 # Flag indicating whether to ignore unaccounted ticks in the report self.ignore_unknown = False self.func_enum = FunctionEnumerator() self.packed_stacks = [] def ProcessLogfile(self, filename, included_state = None, ignore_unknown = False, separate_ic = False, call_graph_json = False): self.log_file = filename self.included_state = included_state self.ignore_unknown = ignore_unknown self.separate_ic = separate_ic self.call_graph_json = call_graph_json try: logfile = open(filename, 'rb') except IOError: sys.exit("Could not open logfile: " + filename) try: try: logreader = csv.reader(logfile) row_num = 1 for row in logreader: row_num += 1 if row[0] == 'tick': self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3], 16), int(row[4]), self.PreprocessStack(row[5:])) elif row[0] == 'code-creation': self.ProcessCodeCreation(row[1], int(row[2], 16), int(row[3]), row[4]) elif row[0] == 'code-move': self.ProcessCodeMove(int(row[1], 16), int(row[2], 16)) elif row[0] == 'code-delete': self.ProcessCodeDelete(int(row[1], 16)) elif row[0] == 'function-creation': self.ProcessFunctionCreation(int(row[1], 16), int(row[2], 16)) elif row[0] == 'function-move': self.ProcessFunctionMove(int(row[1], 16), int(row[2], 16)) elif row[0] == 'function-delete': self.ProcessFunctionDelete(int(row[1], 16)) elif row[0] == 'shared-library': self.AddSharedLibraryEntry(row[1], int(row[2], 16), int(row[3], 16)) self.ParseVMSymbols(row[1], int(row[2], 16), int(row[3], 16)) elif row[0] == 'begin-code-region': self.ProcessBeginCodeRegion(int(row[1], 16), int(row[2], 16), int(row[3], 16), row[4]) elif row[0] == 'end-code-region': self.ProcessEndCodeRegion(int(row[1], 16), int(row[2], 16), int(row[3], 16)) elif row[0] == 'code-allocate': self.ProcessCodeAllocate(int(row[1], 16), int(row[2], 16)) except csv.Error: print("parse error in line " + str(row_num)) raise finally: logfile.close() def AddSharedLibraryEntry(self, filename, start, end): # Mark the pages used by this library. i = start while i < end: page = i >> 12 self.vm_extent[page] = 1 i += 4096 # Add the library to the entries so that ticks for which we do not # have symbol information is reported as belonging to the library. self.cpp_entries.Insert(start, SharedLibraryEntry(start, filename)) def ParseVMSymbols(self, filename, start, end): return def ProcessCodeAllocate(self, addr, assem): if assem in self.pending_assemblers: assembler = self.pending_assemblers.pop(assem) self.assemblers[addr] = assembler def ProcessCodeCreation(self, type, addr, size, name): if addr in self.assemblers: assembler = self.assemblers.pop(addr) else: assembler = None self.js_entries.Insert(addr, JSCodeEntry(addr, name, type, size, assembler)) def ProcessCodeMove(self, from_addr, to_addr): try: removed_node = self.js_entries.Remove(from_addr) removed_node.value.SetStartAddress(to_addr); self.js_entries.Insert(to_addr, removed_node.value) except splaytree.KeyNotFoundError: print('Code move event for unknown code: 0x%x' % from_addr) def ProcessCodeDelete(self, from_addr): try: removed_node = self.js_entries.Remove(from_addr) self.deleted_code.append(removed_node.value) except splaytree.KeyNotFoundError: print('Code delete event for unknown code: 0x%x' % from_addr) def ProcessFunctionCreation(self, func_addr, code_addr): js_entry_node = self.js_entries.Find(code_addr) if js_entry_node: js_entry = js_entry_node.value self.js_entries.Insert(func_addr, JSCodeEntry(func_addr, js_entry.name, js_entry.type, 1, None)) def ProcessFunctionMove(self, from_addr, to_addr): try: removed_node = self.js_entries.Remove(from_addr) removed_node.value.SetStartAddress(to_addr); self.js_entries.Insert(to_addr, removed_node.value) except splaytree.KeyNotFoundError: return def ProcessFunctionDelete(self, from_addr): try: removed_node = self.js_entries.Remove(from_addr) self.deleted_code.append(removed_node.value) except splaytree.KeyNotFoundError: return def ProcessBeginCodeRegion(self, id, assm, start, name): if not assm in self.pending_assemblers: self.pending_assemblers[assm] = Assembler() assembler = self.pending_assemblers[assm] assembler.pending_regions[id] = CodeRegion(start, name) def ProcessEndCodeRegion(self, id, assm, end): assm = self.pending_assemblers[assm] region = assm.pending_regions.pop(id) region.end_offset = end assm.regions.append(region) def IncludeTick(self, pc, sp, state): return (self.included_state is None) or (self.included_state == state) def FindEntry(self, pc): page = pc >> 12 if page in self.vm_extent: entry = self.cpp_entries.FindGreatestsLessThan(pc) if entry != None: return entry.value else: return entry max = self.js_entries.FindMax() min = self.js_entries.FindMin() if max != None and pc < (max.key + max.value.size) and pc > min.key: return self.js_entries.FindGreatestsLessThan(pc).value return None def PreprocessStack(self, stack): # remove all non-addresses (e.g. 'overflow') and convert to int result = [] for frame in stack: if frame.startswith('0x'): result.append(int(frame, 16)) return result def ProcessStack(self, stack): result = [] for frame in stack: entry = self.FindEntry(frame) if entry != None: result.append(entry.ToString()) return result def ProcessTick(self, pc, sp, func, state, stack): if state == VMStates['GC']: self.number_of_gc_ticks += 1 if not self.IncludeTick(pc, sp, state): self.excluded_number_of_ticks += 1; return self.total_number_of_ticks += 1 entry = self.FindEntry(pc) if entry == None: self.unaccounted_number_of_ticks += 1 return if entry.IsSharedLibraryEntry(): self.number_of_library_ticks += 1 if entry.IsICEntry() and not self.separate_ic: if len(stack) > 0: caller_pc = stack.pop(0) self.total_number_of_ticks -= 1 self.ProcessTick(caller_pc, sp, func, state, stack) else: self.unaccounted_number_of_ticks += 1 else: processed_stack = self.ProcessStack(stack) if not entry.IsSharedLibraryEntry() and not entry.IsJSFunction(): func_entry_node = self.js_entries.Find(func) if func_entry_node and func_entry_node.value.IsJSFunction(): processed_stack.insert(0, func_entry_node.value.ToString()) entry.Tick(pc, processed_stack) if self.call_graph_json: self.AddToPackedStacks(pc, stack) def AddToPackedStacks(self, pc, stack): full_stack = stack full_stack.insert(0, pc) func_names = self.ProcessStack(full_stack) func_ids = [] for func in func_names: func_ids.append(self.func_enum.GetFunctionId(func)) self.packed_stacks.append(func_ids) def PrintResults(self): if not self.call_graph_json: self.PrintStatistics() else: self.PrintCallGraphJSON() def PrintStatistics(self): print('Statistical profiling result from %s, (%d ticks, %d unaccounted, %d excluded).' % (self.log_file, self.total_number_of_ticks, self.unaccounted_number_of_ticks, self.excluded_number_of_ticks)) if self.total_number_of_ticks > 0: js_entries = self.js_entries.ExportValueList() js_entries.extend(self.deleted_code) cpp_entries = self.cpp_entries.ExportValueList() # Print the unknown ticks percentage if they are not ignored. if not self.ignore_unknown and self.unaccounted_number_of_ticks > 0: self.PrintHeader('Unknown') self.PrintCounter(self.unaccounted_number_of_ticks) # Print the library ticks. self.PrintHeader('Shared libraries') self.PrintEntries(cpp_entries, lambda e:e.IsSharedLibraryEntry()) # Print the JavaScript ticks. self.PrintHeader('JavaScript') self.PrintEntries(js_entries, lambda e:not e.IsSharedLibraryEntry()) # Print the C++ ticks. self.PrintHeader('C++') self.PrintEntries(cpp_entries, lambda e:not e.IsSharedLibraryEntry()) # Print the GC ticks. self.PrintHeader('GC') self.PrintCounter(self.number_of_gc_ticks) # Print call profile. print('\n [Call profile]:') print(' total call path') js_entries.extend(cpp_entries) self.PrintCallProfile(js_entries) def PrintHeader(self, header_title): print('\n [%s]:' % header_title) print(' ticks total nonlib name') def PrintCounter(self, ticks_count): percentage = ticks_count * 100.0 / self.total_number_of_ticks print(' %(ticks)5d %(total)5.1f%%' % { 'ticks' : ticks_count, 'total' : percentage, }) def PrintEntries(self, entries, condition): # If ignoring unaccounted ticks don't include these in percentage # calculations number_of_accounted_ticks = self.total_number_of_ticks if self.ignore_unknown: number_of_accounted_ticks -= self.unaccounted_number_of_ticks number_of_non_library_ticks = number_of_accounted_ticks - self.number_of_library_ticks entries.sort(key=lambda e: (e.tick_count, e.ToString()), reverse=True) for entry in entries: if entry.tick_count > 0 and condition(entry): total_percentage = entry.tick_count * 100.0 / number_of_accounted_ticks if entry.IsSharedLibraryEntry(): non_library_percentage = 0 else: non_library_percentage = entry.tick_count * 100.0 / number_of_non_library_ticks print(' %(ticks)5d %(total)5.1f%% %(nonlib)6.1f%% %(name)s' % { 'ticks' : entry.tick_count, 'total' : total_percentage, 'nonlib' : non_library_percentage, 'name' : entry.ToString() }) region_ticks = entry.RegionTicks() if not region_ticks is None: items = region_ticks.items() items.sort(key=lambda e: e[1][1], reverse=True) for (name, ticks) in items: print(' flat cum') print(' %(flat)5.1f%% %(accum)5.1f%% %(name)s' % { 'flat' : ticks[1] * 100.0 / entry.tick_count, 'accum' : ticks[0] * 100.0 / entry.tick_count, 'name': name }) def PrintCallProfile(self, entries): all_stacks = {} total_stacks = 0 for entry in entries: all_stacks.update(entry.stacks) for count in entry.stacks.itervalues(): total_stacks += count all_stacks_items = all_stacks.items(); all_stacks_items.sort(key = itemgetter(1), reverse=True) missing_percentage = (self.total_number_of_ticks - total_stacks) * 100.0 / self.total_number_of_ticks print(' %(ticks)5d %(total)5.1f%% <no call path information>' % { 'ticks' : self.total_number_of_ticks - total_stacks, 'total' : missing_percentage }) for stack, count in all_stacks_items: total_percentage = count * 100.0 / self.total_number_of_ticks print(' %(ticks)5d %(total)5.1f%% %(call_path)s' % { 'ticks' : count, 'total' : total_percentage, 'call_path' : stack[0] + ' <- ' + stack[1] }) def PrintCallGraphJSON(self): print('\nvar __profile_funcs = ["' + '",\n"'.join(self.func_enum.GetKnownFunctions()) + '"];') print('var __profile_ticks = [') str_packed_stacks = [] for stack in self.packed_stacks: str_packed_stacks.append('[' + ','.join(map(str, stack)) + ']') print(',\n'.join(str_packed_stacks)) print('];') class CmdLineProcessor(object): def __init__(self): self.options = ["js", "gc", "compiler", "other", "external", "ignore-unknown", "separate-ic", "call-graph-json"] # default values self.state = None self.ignore_unknown = False self.log_file = None self.separate_ic = False self.call_graph_json = False def ProcessArguments(self): try: opts, args = getopt.getopt(sys.argv[1:], "jgcoe", self.options) except getopt.GetoptError: self.PrintUsageAndExit() for key, value in opts: if key in ("-j", "--js"): self.state = VMStates['JS'] if key in ("-g", "--gc"): self.state = VMStates['GC'] if key in ("-c", "--compiler"): self.state = VMStates['COMPILER'] if key in ("-o", "--other"): self.state = VMStates['OTHER'] if key in ("-e", "--external"): self.state = VMStates['EXTERNAL'] if key in ("--ignore-unknown"): self.ignore_unknown = True if key in ("--separate-ic"): self.separate_ic = True if key in ("--call-graph-json"): self.call_graph_json = True self.ProcessRequiredArgs(args) def ProcessRequiredArgs(self, args): return def GetRequiredArgsNames(self): return def PrintUsageAndExit(self): print('Usage: %(script_name)s --{%(opts)s} %(req_opts)s' % { 'script_name': os.path.basename(sys.argv[0]), 'opts': string.join(self.options, ','), 'req_opts': self.GetRequiredArgsNames() }) sys.exit(2) def RunLogfileProcessing(self, tick_processor): tick_processor.ProcessLogfile(self.log_file, self.state, self.ignore_unknown, self.separate_ic, self.call_graph_json) if __name__ == '__main__': sys.exit('You probably want to run windows-tick-processor.py or linux-tick-processor.py.')