Added the simplest call stack sampling and call profile in tick processor output.

tools/tickprocessor.py

 # 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
+from operator import itemgetter
 
 
 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):
+  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
 
@@ skipping 12 matching lines @@
 
 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
 
-  def Tick(self, pc):
-    super(JSCodeEntry, self).Tick(pc)
+  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():
@@ skipping 71 matching lines @@
     self.log_file = filename
     self.included_state = included_state
     try:
       logfile = open(filename, 'rb')
     except IOError:
       sys.exit("Could not open logfile: " + filename)
     try:
       logreader = csv.reader(logfile)
       for row in logreader:
         if row[0] == 'tick':
-          self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3]))
+          self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3]), row[4:])
         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] == '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':
@@ skipping 54 matching lines @@
 
   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 ProcessTick(self, pc, sp, 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 and pc > min.key:
+      return self.js_entries.FindGreatestsLessThan(pc).value
+    return None
+
+  def ProcessStack(self, stack):
+    result = []
+    for frame in stack:
+      if frame.startswith('0x'):
+        entry = self.FindEntry(int(frame, 16))
+        if entry != None:
+          result.append(entry.ToString())
+    return result
+
+  def ProcessTick(self, pc, sp, state, stack):
     if not self.IncludeTick(pc, sp, state):
       self.excluded_number_of_ticks += 1;
       return
     self.total_number_of_ticks += 1
-    page = pc >> 12
-    if page in self.vm_extent:
-      entry = self.cpp_entries.FindGreatestsLessThan(pc).value
-      if entry.IsSharedLibraryEntry():
-        self.number_of_library_ticks += 1
-      entry.Tick(None)
+    entry = self.FindEntry(pc)
+    if entry == None:
+      self.unaccounted_number_of_ticks += 1
       return
-    max = self.js_entries.FindMax()
-    min = self.js_entries.FindMin()
-    if max != None and pc < max.key and pc > min.key:
-      code_obj = self.js_entries.FindGreatestsLessThan(pc).value
-      code_obj.Tick(pc)
-      return
-    self.unaccounted_number_of_ticks += 1
+    if entry.IsSharedLibraryEntry():
+      self.number_of_library_ticks += 1
+    entry.Tick(pc, self.ProcessStack(stack))
 
   def PrintResults(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 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 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('   total  nonlib   name')
 
   def PrintEntries(self, entries, condition):
     number_of_accounted_ticks = self.total_number_of_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, reverse=True)
     for entry in entries:
@@ skipping 13 matching lines @@
           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)
+    for stack, count in all_stacks_items:
+      total_percentage = count * 100.0 / total_stacks
+      print('  %(total)5.1f%%  %(call_path)s' % {
+        'total' : total_percentage,
+        'call_path' : stack[0] + '  <-  ' + stack[1]
+      })
+
 if __name__ == '__main__':
   sys.exit('You probably want to run windows-tick-processor.py or linux-tick-processor.py.')