Add source map support to tick processor.

Added a console parameter for source map to the tick processor.
The tickprocesspor reads in the source maps and uses it to output the original filename, line number and column in the profile.
Modified d8 to output column numbers into the log, since this is needed to do source mapping.

R=jkummerow@chromium.org

Review URL: https://codereview.chromium.org/22897021

Patch from Daniel Kurka <dankurka@google.com>.

git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@16307 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/compiler.cc

@@ -1209,6 +1209,8 @@ void Compiler::RecordFunctionCompilation(Logger::LogEventsAndTags tag,
     if (*code == info->isolate()->builtins()->builtin(Builtins::kLazyCompile))
       return;
     int line_num = GetScriptLineNumber(script, shared->start_position()) + 1;
+    int column_num =
+        GetScriptColumnNumber(script, shared->start_position()) + 1;
     USE(line_num);
     if (script->name()->IsString()) {
       PROFILE(info->isolate(),
@@ -1217,7 +1219,8 @@ void Compiler::RecordFunctionCompilation(Logger::LogEventsAndTags tag,
                               *shared,
                               info,
                               String::cast(script->name()),
-                              line_num));
+                              line_num,
+                              column_num));
     } else {
       PROFILE(info->isolate(),
               CodeCreateEvent(Logger::ToNativeByScript(tag, *script),
@@ -1225,7 +1228,8 @@ void Compiler::RecordFunctionCompilation(Logger::LogEventsAndTags tag,
                               *shared,
                               info,
                               info->isolate()->heap()->empty_string(),
-                              line_num));
+                              line_num,
+                              column_num));
     }
   }
 

src/log.cc

@@ -1233,7 +1233,7 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              SharedFunctionInfo* shared,
                              CompilationInfo* info,
-                             Name* source, int line) {
+                             Name* source, int line, int column) {
   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, source, line));
 
   if (!is_logging_code_events()) return;
@@ -1252,7 +1252,7 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag,
   } else {
     msg.AppendSymbolName(Symbol::cast(source));
   }
-  msg.Append(":%d\",", line);
+  msg.Append(":%d:%d\",", line, column);
   msg.AppendAddress(shared->address());
   msg.Append(",%s", ComputeMarker(code));
   msg.Append('\n');
@@ -1712,6 +1712,8 @@ void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
   if (shared->script()->IsScript()) {
     Handle<Script> script(Script::cast(shared->script()));
     int line_num = GetScriptLineNumber(script, shared->start_position()) + 1;
+    int column_num =
+        GetScriptColumnNumber(script, shared->start_position()) + 1;
     if (script->name()->IsString()) {
       Handle<String> script_name(String::cast(script->name()));
       if (line_num > 0) {
@@ -1719,7 +1721,7 @@ void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
                 CodeCreateEvent(
                     Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
                     *code, *shared, NULL,
-                    *script_name, line_num));
+                    *script_name, line_num, column_num));
       } else {
         // Can't distinguish eval and script here, so always use Script.
         PROFILE(isolate_,
@@ -1732,7 +1734,7 @@ void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
               CodeCreateEvent(
                   Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
                   *code, *shared, NULL,
-                  isolate_->heap()->empty_string(), line_num));
+                  isolate_->heap()->empty_string(), line_num, column_num));
     }
   } else if (shared->IsApiFunction()) {
     // API function.

src/log.h

@@ -248,7 +248,7 @@ class Logger {
                        Code* code,
                        SharedFunctionInfo* shared,
                        CompilationInfo* info,
-                       Name* source, int line);
+                       Name* source, int line, int column);
   void CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count);
   void CodeMovingGCEvent();
   // Emits a code create event for a RegExp.

tools/linux-tick-processor

@@ -37,4 +37,5 @@ cat $log_file | $d8_exec $tools_path/splaytree.js $tools_path/codemap.js \
   $tools_path/csvparser.js $tools_path/consarray.js \
   $tools_path/profile.js $tools_path/profile_view.js \
   $tools_path/logreader.js $tools_path/tickprocessor.js \
+  $tools_path/SourceMap.js \
   $tools_path/tickprocessor-driver.js -- $@ 2>/dev/null

tools/tickprocessor-driver.js

@@ -37,6 +37,18 @@ function processArguments(args) {
   }
 }
 
+function initSourceMapSupport() {
+  // Pull dev tools source maps  into our name space.
+  SourceMap = WebInspector.SourceMap;
+
+  // Overwrite the load function to load scripts synchronously.
+  SourceMap.load = function(sourceMapURL) {
+    var content = readFile(sourceMapURL);
+    var sourceMapObject = (JSON.parse(content));
+    return new SourceMap(sourceMapURL, sourceMapObject);
+  };
+}
+
 var entriesProviders = {
   'unix': UnixCppEntriesProvider,
   'windows': WindowsCppEntriesProvider,
@@ -44,6 +56,11 @@ var entriesProviders = {
 };
 
 var params = processArguments(arguments);
+var sourceMap = null;
+if (params.sourceMap) {
+  initSourceMapSupport();
+  sourceMap = SourceMap.load(params.sourceMap);
+}
 var snapshotLogProcessor;
 if (params.snapshotLogFileName) {
   snapshotLogProcessor = new SnapshotLogProcessor();
@@ -57,6 +74,7 @@ var tickProcessor = new TickProcessor(
   params.stateFilter,
   snapshotLogProcessor,
   params.distortion,
-  params.range);
+  params.range,
+  sourceMap);
 tickProcessor.processLogFile(params.logFileName);
 tickProcessor.printStatistics();

tools/tickprocessor.js

@@ -153,7 +153,8 @@ function TickProcessor(
     stateFilter,
     snapshotLogProcessor,
     distortion,
-    range) {
+    range,
+    sourceMap) {
   LogReader.call(this, {
       'shared-library': { parsers: [null, parseInt, parseInt],
           processor: this.processSharedLibrary },
@@ -196,6 +197,7 @@ function TickProcessor(
   this.ignoreUnknown_ = ignoreUnknown;
   this.stateFilter_ = stateFilter;
   this.snapshotLogProcessor_ = snapshotLogProcessor;
+  this.sourceMap = sourceMap;
   this.deserializedEntriesNames_ = [];
   var ticks = this.ticks_ =
     { total: 0, unaccounted: 0, excluded: 0, gc: 0 };
@@ -544,17 +546,52 @@ TickProcessor.prototype.processProfile = function(
   }
 };
 
+TickProcessor.prototype.getLineAndColumn = function(name) {
+  var re = /:([0-9]+):([0-9]+)$/;
+  var array = re.exec(name);
+  if (!array) {
+    return null;
+  }
+  return {line: array[1], column: array[2]};
+}
+
+TickProcessor.prototype.hasSourceMap = function() {
+  return this.sourceMap != null;
+};
+
+
+TickProcessor.prototype.formatFunctionName = function(funcName) {
+  if (!this.hasSourceMap()) {
+    return funcName;
+  }
+  var lc = this.getLineAndColumn(funcName);
+  if (lc == null) {
+    return funcName;
+  }
+  // in source maps lines and columns are zero based
+  var lineNumber = lc.line - 1;
+  var column = lc.column - 1;
+  var entry = this.sourceMap.findEntry(lineNumber, column);
+  var sourceFile = entry[2];
+  var sourceLine = entry[3] + 1;
+  var sourceColumn = entry[4] + 1;
+
+  return sourceFile + ':' + sourceLine + ':' + sourceColumn + ' -> ' + funcName;
+};
 
 TickProcessor.prototype.printEntries = function(
     profile, nonLibTicks, filterP) {
+  var that = this;
   this.processProfile(profile, filterP, function (rec) {
     if (rec.selfTime == 0) return;
     var nonLibPct = nonLibTicks != null ?
         rec.selfTime * 100.0 / nonLibTicks : 0.0;
+    var funcName = that.formatFunctionName(rec.internalFuncName);
+
     print('  ' + padLeft(rec.selfTime, 5) + '  ' +
           padLeft(rec.selfPercent.toFixed(1), 5) + '%  ' +
           padLeft(nonLibPct.toFixed(1), 5) + '%  ' +
-          rec.internalFuncName);
+          funcName);
   });
 };
 
@@ -566,9 +603,10 @@ TickProcessor.prototype.printHeavyProfile = function(profile, opt_indent) {
   this.processProfile(profile, function() { return true; }, function (rec) {
     // Cut off too infrequent callers.
     if (rec.parentTotalPercent < TickProcessor.CALL_PROFILE_CUTOFF_PCT) return;
+    var funcName = self.formatFunctionName(rec.internalFuncName);
     print('  ' + padLeft(rec.totalTime, 5) + '  ' +
           padLeft(rec.parentTotalPercent.toFixed(1), 5) + '%  ' +
-          indentStr + rec.internalFuncName);
+          indentStr + funcName);
     // Limit backtrace depth.
     if (indent < 2 * self.callGraphSize_) {
       self.printHeavyProfile(rec.children, indent + 2);
@@ -823,9 +861,11 @@ function ArgumentsProcessor(args) {
     '--snapshot-log': ['snapshotLogFileName', 'snapshot.log',
         'Specify snapshot log file to use (e.g. --snapshot-log=snapshot.log)'],
     '--range': ['range', 'auto,auto',
-                'Specify the range limit as [start],[end]'],
+        'Specify the range limit as [start],[end]'],
     '--distortion': ['distortion', 0,
-                     'Specify the logging overhead in picoseconds']
+        'Specify the logging overhead in picoseconds'],
+    '--source-map': ['sourceMap', null,
+        'Specify the source map that should be used for output']
   };
   this.argsDispatch_['--js'] = this.argsDispatch_['-j'];
   this.argsDispatch_['--gc'] = this.argsDispatch_['-g'];

tools/windows-tick-processor.bat

@@ -27,4 +27,4 @@ IF NOT %arg8:~0,2% == 8 (IF NOT %arg8:~0,2% == 8- SET log_file=%8)
 SET arg9=9%9
 IF NOT %arg9:~0,2% == 9 (IF NOT %arg9:~0,2% == 9- SET log_file=%9)
 
-type %log_file% | %D8_PATH%\d8 %tools_dir%splaytree.js %tools_dir%codemap.js %tools_dir%csvparser.js %tools_dir%consarray.js %tools_dir%profile.js %tools_dir%profile_view.js %tools_dir%logreader.js %tools_dir%tickprocessor.js %tools_dir%tickprocessor-driver.js -- --windows %*
+type %log_file% | %D8_PATH%\d8 %tools_dir%splaytree.js %tools_dir%codemap.js %tools_dir%csvparser.js %tools_dir%consarray.js %tools_dir%profile.js %tools_dir%profile_view.js %tools_dir%logreader.js %tools_dir%SourceMap.js %tools_dir%tickprocessor.js %tools_dir%tickprocessor-driver.js -- --windows %*