TickProcessor script reimplemented in JavaScript.

tools/tickprocessor.js

+// Copyright 2009 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.
+
+
+function Profile(separateIc) {
+  devtools.profiler.Profile.call(this);
+  if (!separateIc) {
+    this.skipThisFunction = function(name) { return Profile.IC_RE.test(name); };
+  }
+};
+Profile.prototype = devtools.profiler.Profile.prototype;
+
+
+Profile.IC_RE =
+    /^(?:CallIC|LoadIC|StoreIC)|(?:Builtin: (?:Keyed)?(?:Call|Load|Store)IC_)/;
+
+
+/**
+ * A thin wrapper around shell's 'read' function showing a file name on error.
+ */
+function readFile(fileName) {
+  try {
+    return read(fileName);
+  } catch (e) {
+    print(fileName + ': ' + (e.message || e));
+    throw e;
+  }
+}
+
+
+function TickProcessor(
+    cppEntriesProvider, separateIc, ignoreUnknown, stateFilter) {
+  this.cppEntriesProvider_ = cppEntriesProvider;
+  this.ignoreUnknown_ = ignoreUnknown;
+  this.stateFilter_ = stateFilter;
+  var ticks = this.ticks_ =
+    { total: 0, unaccounted: 0, excluded: 0, gc: 0 };
+
+  Profile.prototype.handleUnknownCode = function(
+      operation, addr, opt_stackPos) {
+    var op = devtools.profiler.Profile.Operation;
+    switch (operation) {
+      case op.MOVE:
+        print('Code move event for unknown code: 0x' + addr.toString(16));
+        break;
+      case op.DELETE:
+        print('Code delete event for unknown code: 0x' + addr.toString(16));
+        break;
+      case op.TICK:
+        // Only unknown PCs (the first frame) are reported as unaccounted,
+        // otherwise tick balance will be corrupted (this behavior is compatible
+        // with the original tickprocessor.py script.)
+        if (opt_stackPos == 0) {
+          ticks.unaccounted++;
+        }
+        break;
+    }
+  };
+
+  this.profile_ = new Profile(separateIc);
+  this.codeTypes_ = {};
+  // Count each tick as a time unit.
+  this.viewBuilder_ = new devtools.profiler.ViewBuilder(1);
+  this.lastLogFileName_ = null;
+};
+
+
+TickProcessor.VmStates = {
+  JS: 0,
+  GC: 1,
+  COMPILER: 2,
+  OTHER: 3,
+  EXTERNAL: 4
+};
+
+
+TickProcessor.CodeTypes = {
+  JS: 0,
+  CPP: 1,
+  SHARED_LIB: 2
+};
+
+
+TickProcessor.RecordsDispatch = {
+  'shared-library': { parsers: [null, parseInt, parseInt],
+                      processor: 'processSharedLibrary' },
+  'code-creation': { parsers: [null, parseInt, parseInt, null],
+                   processor: 'processCodeCreation' },
+  'code-move': { parsers: [parseInt, parseInt],
+                 processor: 'processCodeMove' },
+  'code-delete': { parsers: [parseInt], processor: 'processCodeDelete' },
+  'tick': { parsers: [parseInt, parseInt, parseInt, 'var-args'],
+            processor: 'processTick' },
+  'profiler': null,
+  // Obsolete row types.
+  'code-allocate': null,
+  'begin-code-region': null,
+  'end-code-region': null
+};
+
+
+TickProcessor.CALL_PROFILE_CUTOFF_PCT = 2.0;
+
+
+TickProcessor.prototype.setCodeType = function(name, type) {
+  this.codeTypes_[name] = TickProcessor.CodeTypes[type];
+};
+
+
+TickProcessor.prototype.isSharedLibrary = function(name) {
+  return this.codeTypes_[name] == TickProcessor.CodeTypes.SHARED_LIB;
+};
+
+
+TickProcessor.prototype.isCppCode = function(name) {
+  return this.codeTypes_[name] == TickProcessor.CodeTypes.CPP;
+};
+
+
+TickProcessor.prototype.isJsCode = function(name) {
+  return this.codeTypes_[name] == TickProcessor.CodeTypes.JS;
+};
+
+
+TickProcessor.prototype.processLogFile = function(fileName) {
+  this.lastLogFileName_ = fileName;
+  var contents = readFile(fileName);
+  this.processLog(contents.split('\n'));
+};
+
+
+TickProcessor.prototype.processLog = function(lines) {
+  var csvParser = new devtools.profiler.CsvParser();
+  try {
+    for (var i = 0, n = lines.length; i < n; ++i) {
+      var line = lines[i];
+      if (!line) {
+        continue;
+      }
+      var fields = csvParser.parseLine(line);
+      this.dispatchLogRow(fields);
+    }
+  } catch (e) {
+    print('line ' + (i + 1) + ': ' + (e.message || e));
+    throw e;
+  }
+};
+
+
+TickProcessor.prototype.dispatchLogRow = function(fields) {
+  // Obtain the dispatch.
+  var command = fields[0];
+  if (!(command in TickProcessor.RecordsDispatch)) {
+    throw new Error('unknown command: ' + command);
+  }
+  var dispatch = TickProcessor.RecordsDispatch[command];
+
+  if (dispatch === null) {
+    return;
+  }
+
+  // Parse fields.
+  var parsedFields = [];
+  for (var i = 0; i < dispatch.parsers.length; ++i) {
+    var parser = dispatch.parsers[i];
+    if (parser === null) {
+      parsedFields.push(fields[1 + i]);
+    } else if (typeof parser == 'function') {
+      parsedFields.push(parser(fields[1 + i]));
+    } else {
+      // var-args
+      parsedFields.push(fields.slice(1 + i));
+      break;
+    }
+  }
+
+  // Run the processor.
+  this[dispatch.processor].apply(this, parsedFields);
+};
+
+
+TickProcessor.prototype.processSharedLibrary = function(
+    name, startAddr, endAddr) {
+  var entry = this.profile_.addStaticCode(name, startAddr, endAddr);
+  this.setCodeType(entry.getName(), 'SHARED_LIB');
+
+  var self = this;
+  var libFuncs = this.cppEntriesProvider_.parseVmSymbols(
+      name, startAddr, endAddr, function(fName, fStart, fEnd) {
+    self.profile_.addStaticCode(fName, fStart, fEnd);
+    self.setCodeType(fName, 'CPP');
+  });
+};
+
+
+TickProcessor.prototype.processCodeCreation = function(
+    type, start, size, name) {
+  var entry = this.profile_.addCode(type, name, start, size);
+  this.setCodeType(entry.getName(), 'JS');
+};
+
+
+TickProcessor.prototype.processCodeMove = function(from, to) {
+  this.profile_.moveCode(from, to);
+};
+
+
+TickProcessor.prototype.processCodeDelete = function(start) {
+  this.profile_.deleteCode(start);
+};
+
+
+TickProcessor.prototype.includeTick = function(vmState) {
+  return this.stateFilter_ == null || this.stateFilter_ == vmState;
+};
+
+
+TickProcessor.prototype.processTick = function(pc, sp, vmState, stack) {
+  this.ticks_.total++;
+  if (vmState == TickProcessor.VmStates.GC) this.ticks_.gc++;
+  if (!this.includeTick(vmState)) {
+    this.ticks_.excluded++;
+    return;
+  }
+
+  var fullStack = [pc];
+  for (var i = 0, n = stack.length; i < n; ++i) {
+    var frame = stack[i];
+    // Leave only numbers starting with 0x. Filter possible 'overflow' string.
+    if (frame.charAt(0) == '0') {
+      fullStack.push(parseInt(frame, 16));
+    }
+  }
+  this.profile_.recordTick(fullStack);
+};
+
+
+TickProcessor.prototype.printStatistics = function() {
+  print('Statistical profiling result from ' + this.lastLogFileName_ +
+        ', (' + this.ticks_.total +
+        ' ticks, ' + this.ticks_.unaccounted + ' unaccounted, ' +
+        this.ticks_.excluded + ' excluded).');
+
+  if (this.ticks_.total == 0) return;
+
+  // Print the unknown ticks percentage if they are not ignored.
+  if (!this.ignoreUnknown_ && this.ticks_.unaccounted > 0) {
+    this.printHeader('Unknown');
+    this.printCounter(this.ticks_.unaccounted, this.ticks_.total);
+  }
+
+  var flatProfile = this.profile_.getFlatProfile();
+  var flatView = this.viewBuilder_.buildView(flatProfile);
+  // Sort by self time, desc, then by name, desc.
+  flatView.sort(function(rec1, rec2) {
+      return rec2.selfTime - rec1.selfTime ||
+          (rec2.internalFuncName < rec1.internalFuncName ? -1 : 1); });
+  var totalTicks = this.ticks_.total;
+  if (this.ignoreUnknown_) {
+    totalTicks -= this.ticks_.unaccounted;
+  }
+  // Our total time contains all the ticks encountered,
+  // while profile only knows about the filtered ticks.
+  flatView.head.totalTime = totalTicks;
+
+  // Count library ticks
+  var flatViewNodes = flatView.head.children;
+  var self = this;
+  var libraryTicks = 0;
+  this.processProfile(flatViewNodes,
+      function(name) { return self.isSharedLibrary(name); },
+      function(rec) { libraryTicks += rec.selfTime; });
+  var nonLibraryTicks = totalTicks - libraryTicks;
+
+  this.printHeader('Shared libraries');
+  this.printEntries(flatViewNodes, null,
+      function(name) { return self.isSharedLibrary(name); });
+
+  this.printHeader('JavaScript');
+  this.printEntries(flatViewNodes, nonLibraryTicks,
+      function(name) { return self.isJsCode(name); });
+
+  this.printHeader('C++');
+  this.printEntries(flatViewNodes, nonLibraryTicks,
+      function(name) { return self.isCppCode(name); });
+
+  this.printHeader('GC');
+  this.printCounter(this.ticks_.gc, totalTicks);
+
+  this.printHeavyProfHeader();
+  var heavyProfile = this.profile_.getBottomUpProfile();
+  var heavyView = this.viewBuilder_.buildView(heavyProfile);
+  // To show the same percentages as in the flat profile.
+  heavyView.head.totalTime = totalTicks;
+  // Sort by total time, desc, then by name, desc.
+  heavyView.sort(function(rec1, rec2) {
+      return rec2.totalTime - rec1.totalTime ||
+          (rec2.internalFuncName < rec1.internalFuncName ? -1 : 1); });
+  this.printHeavyProfile(heavyView.head.children);
+};
+
+
+function padLeft(s, len) {
+  s = s.toString();
+  if (s.length < len) {
+    s = (new Array(len - s.length + 1).join(' ')) + s;
+  }
+  return s;
+};
+
+
+TickProcessor.prototype.printHeader = function(headerTitle) {
+  print('\n [' + headerTitle + ']:');
+  print('   ticks  total  nonlib   name');
+};
+
+
+TickProcessor.prototype.printHeavyProfHeader = function() {
+  print('\n [Bottom up (heavy) profile]:');
+  print('  Note: percentage shows a share of a particular caller in the ' +
+        'total\n' +
+        '  amount of its parent calls.');
+  print('  Callers occupying less than ' +
+        TickProcessor.CALL_PROFILE_CUTOFF_PCT.toFixed(1) +
+        '% are not shown.\n');
+  print('   ticks parent  name');
+};
+
+
+TickProcessor.prototype.printCounter = function(ticksCount, totalTicksCount) {
+  var pct = ticksCount * 100.0 / totalTicksCount;
+  print('  ' + padLeft(ticksCount, 5) + '  ' + padLeft(pct.toFixed(1), 5) + '%');
+};
+
+
+TickProcessor.prototype.processProfile = function(
+    profile, filterP, func) {
+  for (var i = 0, n = profile.length; i < n; ++i) {
+    var rec = profile[i];
+    // An empty record corresponds to a tree root.
+    if (!rec.internalFuncName || !filterP(rec.internalFuncName)) {
+      continue;
+    }
+    func(rec);
+  }
+};
+
+
+TickProcessor.prototype.printEntries = function(
+    profile, nonLibTicks, filterP) {
+  this.processProfile(profile, filterP, function (rec) {
+    if (rec.selfTime == 0) return;
+    var nonLibPct = nonLibTicks != null ?
+        rec.selfTime * 100.0 / nonLibTicks : 0.0;
+    print('  ' + padLeft(rec.selfTime, 5) + '  ' +
+          padLeft(rec.selfPercent.toFixed(1), 5) + '%  ' +
+          padLeft(nonLibPct.toFixed(1), 5) + '%  ' +
+          rec.internalFuncName);
+  });
+};
+
+
+TickProcessor.prototype.printHeavyProfile = function(profile, opt_indent) {
+  var self = this;
+  var indent = opt_indent || 0;
+  var indentStr = padLeft('', indent);
+  this.processProfile(profile, function() { return true; }, function (rec) {
+    // Cut off too infrequent callers.
+    if (rec.parentTotalPercent < TickProcessor.CALL_PROFILE_CUTOFF_PCT) return;
+    print('  ' + padLeft(rec.totalTime, 5) + '  ' +
+          padLeft(rec.parentTotalPercent.toFixed(1), 5) + '%  ' +
+          indentStr + rec.internalFuncName);
+    // Limit backtrace depth.
+    if (indent < 10) {
+      self.printHeavyProfile(rec.children, indent + 2);
+    }
+    // Delimit top-level functions.
+    if (indent == 0) {
+      print('');
+    }
+  });
+};
+
+
+function CppEntriesProvider() {
+};
+
+
+CppEntriesProvider.prototype.parseVmSymbols = function(
+    libName, libStart, libEnd, processorFunc) {
+  var syms = this.loadSymbols(libName);
+  if (syms.length == 0) return;
+
+  var prevEntry;
+
+  function addPrevEntry(end) {
+    // Several functions can be mapped onto the same address. To avoid
+    // creating zero-sized entries, skip such duplicates.
+    if (prevEntry && prevEntry.start != end) {
+      processorFunc(prevEntry.name, prevEntry.start, end);
+    }
+  }
+
+  for (var i = 0, n = syms.length; i < n; ++i) {
+    var line = syms[i];
+    var funcInfo = this.parseLine(line);
+    if (!funcInfo) {
+      continue;
+    }
+    if (funcInfo.start < libStart && funcInfo.start < libEnd - libStart) {
+      funcInfo.start += libStart;
+    }
+    addPrevEntry(funcInfo.start);
+    prevEntry = funcInfo;
+  }
+  addPrevEntry(libEnd);
+};
+
+
+CppEntriesProvider.prototype.loadSymbols = function(libName) {
+  return [];
+};
+
+
+CppEntriesProvider.prototype.parseLine = function(line) {
+  return { name: '', start: 0 };
+};
+
+
+function inherits(childCtor, parentCtor) {
+  function tempCtor() {};
+  tempCtor.prototype = parentCtor.prototype;
+  childCtor.prototype = new tempCtor();
+};
+
+
+function UnixCppEntriesProvider() {
+};
+inherits(UnixCppEntriesProvider, CppEntriesProvider);
+
+
+UnixCppEntriesProvider.FUNC_RE = /^([0-9a-fA-F]{8}) . (.*)$/;
+
+
+UnixCppEntriesProvider.prototype.loadSymbols = function(libName) {
+  var normalSyms = os.system('nm', ['-C', '-n', libName], -1, -1);
+  var dynaSyms = os.system('nm', ['-C', '-n', '-D', libName], -1, -1);
+  var syms = (normalSyms + dynaSyms).split('\n');
+  return syms;
+};
+
+
+UnixCppEntriesProvider.prototype.parseLine = function(line) {
+  var fields = line.match(UnixCppEntriesProvider.FUNC_RE);
+  return fields ? { name: fields[2], start: parseInt(fields[1], 16) } : null;
+};
+
+
+function WindowsCppEntriesProvider() {
+};
+inherits(WindowsCppEntriesProvider, CppEntriesProvider);
+
+
+WindowsCppEntriesProvider.FILENAME_RE = /^(.*)\.exe$/;
+
+
+WindowsCppEntriesProvider.FUNC_RE =
+    /^ 0001:[0-9a-fA-F]{8}\s+([_\?@$0-9a-zA-Z]+)\s+([0-9a-fA-F]{8}).*$/;
+
+
+WindowsCppEntriesProvider.prototype.loadSymbols = function(libName) {
+  var fileNameFields = libName.match(WindowsCppEntriesProvider.FILENAME_RE);
+  // Only try to load symbols for the .exe file.
+  if (!fileNameFields) return [];
+  var mapFileName = fileNameFields[1] + '.map';
+  return readFile(mapFileName).split('\r\n');
+};
+
+
+WindowsCppEntriesProvider.prototype.parseLine = function(line) {
+  var fields = line.match(WindowsCppEntriesProvider.FUNC_RE);
+  return fields ?
+      { name: this.unmangleName(fields[1]), start: parseInt(fields[2], 16) } :
+      null;
+};
+
+
+/**
+ * Performs very simple unmangling of C++ names.
+ *
+ * Does not handle arguments and template arguments. The mangled names have
+ * the form:
+ *
+ *   ?LookupInDescriptor@JSObject@internal@v8@@...arguments info...
+ */
+WindowsCppEntriesProvider.prototype.unmangleName = function(name) {
+  // Empty or non-mangled name.
+  if (name.length < 1 || name.charAt(0) != '?') return name;
+  var nameEndPos = name.indexOf('@@');
+  var components = name.substring(1, nameEndPos).split('@');
+  components.reverse();
+  return components.join('::');
+};
+
+
+function padRight(s, len) {
+  s = s.toString();
+  if (s.length < len) {
+    s = s + (new Array(len - s.length + 1).join(' '));
+  }
+  return s;
+};
+
+
+function processArguments(args) {
+  var result = {
+    logFileName: 'v8.log',
+    platform: 'unix',
+    stateFilter: null,
+    ignoreUnknown: false,
+    separateIc: false
+  };
+  var argsDispatch = {
+    '-j': ['stateFilter', TickProcessor.VmStates.JS,
+        'Show only ticks from JS VM state'],
+    '-g': ['stateFilter', TickProcessor.VmStates.GC,
+        'Show only ticks from GC VM state'],
+    '-c': ['stateFilter', TickProcessor.VmStates.COMPILER,
+        'Show only ticks from COMPILER VM state'],
+    '-o': ['stateFilter', TickProcessor.VmStates.OTHER,
+        'Show only ticks from OTHER VM state'],
+    '-e': ['stateFilter', TickProcessor.VmStates.EXTERNAL,
+        'Show only ticks from EXTERNAL VM state'],
+    '--ignore-unknown': ['ignoreUnknown', true,
+        'Exclude ticks of unknown code entries from processing'],
+    '--separate-ic': ['separateIc', true,
+        'Separate IC entries'],
+    '--unix': ['platform', 'unix',
+        'Specify that we are running on *nix platform'],
+    '--windows': ['platform', 'windows',
+        'Specify that we are running on Windows platform']
+  };
+  argsDispatch['--js'] = argsDispatch['-j'];
+  argsDispatch['--gc'] = argsDispatch['-g'];
+  argsDispatch['--compiler'] = argsDispatch['-c'];
+  argsDispatch['--other'] = argsDispatch['-o'];
+  argsDispatch['--external'] = argsDispatch['-e'];
+
+  function printUsageAndExit() {
+    print('Cmdline args: [options] [log-file-name]\n' +
+          'Default log file name is "v8.log".\n');
+    print('Options:');
+    for (var arg in argsDispatch) {
+      var synonims = [arg];
+      var dispatch = argsDispatch[arg];
+      for (var synArg in argsDispatch) {
+        if (arg !== synArg && dispatch === argsDispatch[synArg]) {
+          synonims.push(synArg);
+          delete argsDispatch[synArg];
+        }
+      }
+      print('  ' + padRight(synonims.join(', '), 20) + dispatch[2]);
+    }
+    quit(2);
+  }
+
+  while (args.length) {
+    var arg = args[0];
+    if (arg.charAt(0) != '-') {
+      break;
+    }
+    args.shift();
+    if (arg in argsDispatch) {
+      var dispatch = argsDispatch[arg];
+      result[dispatch[0]] = dispatch[1];
+    } else {
+      printUsageAndExit();
+    }
+  }
+
+  if (args.length >= 1) {
+      result.logFileName = args.shift();
+  }
+  return result;
+};
+
+
+var params = processArguments(arguments);
+var tickProcessor = new TickProcessor(
+    params.platform == 'unix' ? new UnixCppEntriesProvider() :
+        new WindowsCppEntriesProvider(),
+    params.separateIc,
+    params.ignoreUnknown,
+    params.stateFilter);
+tickProcessor.processLogFile(params.logFileName);
+tickProcessor.printStatistics();