[tools][system-analyzer] Speed up log parsing

Reduce the dispatching overhead in the hottest loop when parsing log-lines.

- Using a JSMap we can avoid internalizing strings
- Preprocess the dispatch table and only have varArgs or functions as
  parsers
- string[] seems to be slightly faster than string.charAt()

Bug: v8:10644
Change-Id: I03b13bdeecda1ad037191ff74e05142ceeb6533c
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3571890
Reviewed-by: Patrick Thier <pthier@chromium.org>
Commit-Queue: Camillo Bruni <cbruni@chromium.org>
Cr-Commit-Position: refs/heads/main@{#79816}

tools/csvparser.mjs

@@ -42,7 +42,7 @@ export class CsvParser {
     // Escape sequences of the form \x00 and \u0000;
     let pos = 0;
     while (nextPos !== -1) {
-      const escapeIdentifier = string.charAt(nextPos + 1);
+      const escapeIdentifier = string[nextPos + 1];
       pos = nextPos + 2;
       if (escapeIdentifier === 'n') {
         result += '\n';

tools/dumpcpp.mjs

@@ -12,13 +12,13 @@ export {
 
 export class CppProcessor extends LogReader {
   constructor(cppEntriesProvider, timedRange, pairwiseTimedRange) {
-    super({}, timedRange, pairwiseTimedRange);
-    this.dispatchTable_ = {
+    super(timedRange, pairwiseTimedRange);
+    this.setDispatchTable({
          __proto__: null,
         'shared-library': {
           parsers: [parseString, parseInt, parseInt, parseInt],
           processor: this.processSharedLibrary }
-    };
+    });
     this.cppEntriesProvider_ = cppEntriesProvider;
     this.codeMap_ = new CodeMap();
     this.lastLogFileName_ = null;

tools/logreader.mjs

@@ -32,64 +32,65 @@
 
 
 // Parses dummy variable for readability;
-export const parseString = 'parse-string';
+export function parseString(field) { return field };
 export const parseVarArgs = 'parse-var-args';
 
 /**
  * Base class for processing log files.
  *
- * @param {Array.<Object>} dispatchTable A table used for parsing and processing
- *     log records.
  * @param {boolean} timedRange Ignore ticks outside timed range.
  * @param {boolean} pairwiseTimedRange Ignore ticks outside pairs of timer
  *     markers.
  * @constructor
  */
 export class LogReader {
-  constructor (dispatchTable, timedRange, pairwiseTimedRange) {
-    /**
-     * @type {Array.<Object>}
-     */
-    this.dispatchTable_ = dispatchTable;
-
-    /**
-     * @type {boolean}
-     */
+  constructor (timedRange, pairwiseTimedRange) {
+    this.dispatchTable_ = new Map();
     this.timedRange_ = timedRange;
-
-    /**
-     * @type {boolean}
-     */
     this.pairwiseTimedRange_ = pairwiseTimedRange;
-    if (pairwiseTimedRange) {
-      this.timedRange_ = true;
-    }
-
-    /**
-     * Current line.
-     * @type {number}
-     */
+    if (pairwiseTimedRange) this.timedRange_ = true;
     this.lineNum_ = 0;
-
-    /**
-     * CSV lines parser.
-     * @type {CsvParser}
-     */
     this.csvParser_ = new CsvParser();
-
-    /**
-     * Keeps track of whether we've seen a "current-time" tick yet.
-     * @type {boolean}
-     */
+    // Variables for tracking of 'current-time' log entries:
     this.hasSeenTimerMarker_ = false;
-
-    /**
-     * List of log lines seen since last "current-time" tick.
-     * @type {Array.<String>}
-     */
     this.logLinesSinceLastTimerMarker_ = [];
   }
 
+/**
+ * @param {Object} table A table used for parsing and processing
+ *     log records.
+ *     exampleDispatchTable = {
+ *       "log-entry-XXX": {
+ *          parser: [parseString, parseInt, ..., parseVarArgs],
+ *          processor: this.processXXX.bind(this)
+ *        },
+ *        ...
+ *      }
+ */
+  setDispatchTable(table) {
+    if (Object.getPrototypeOf(table) !== null) {
+      throw new Error("Dispatch expected table.__proto__=null for speedup");
+    }
+    for (let name in table) {
+      const parser = table[name];
+      if (parser === undefined) continue;
+      if (!parser.isAsync) parser.isAsync = false;
+      if (!Array.isArray(parser.parsers)) {
+        throw new Error(`Invalid parsers: dispatchTable['${
+            name}'].parsers should be an Array.`);
+      }
+      let type = typeof parser.processor;
+      if (type !== 'function') {
+       throw new Error(`Invalid processor: typeof dispatchTable['${
+          name}'].processor is '${type}' instead of 'function'`);
+      }
+      if (!parser.processor.name.startsWith('bound ')) {
+        parser.processor = parser.processor.bind(this);
+      }
+      this.dispatchTable_.set(name, parser);
+    }
+  }
+
 
   /**
    * A thin wrapper around shell's 'read' function showing a file name on error.
@@ -118,7 +119,18 @@ export class LogReader {
    * @param {string} chunk A portion of log.
    */
   async processLogChunk(chunk) {
-    await this.processLog_(chunk.split('\n'));
+    let end = chunk.length;
+    let current = 0;
+    // Kept for debugging in case of parsing errors.
+    let lineNumber = 0;
+    while (current < end) {
+      const next = chunk.indexOf("\n", current);
+      if (next === -1) break;
+      lineNumber++;
+      const line = chunk.substring(current, next);
+      current = next + 1;
+      await this.processLogLine(line);
+    }
   }
 
   /**
@@ -162,18 +174,19 @@ export class LogReader {
   processStack(pc, func, stack) {
     const fullStack = func ? [pc, func] : [pc];
     let prevFrame = pc;
-    for (let i = 0, n = stack.length; i < n; ++i) {
+    const length = stack.length;
+    for (let i = 0, n = length; i < n; ++i) {
       const frame = stack[i];
-      const firstChar = frame.charAt(0);
-      if (firstChar == '+' || firstChar == '-') {
+      const firstChar = frame[0];
+      if (firstChar === '+' || firstChar === '-') {
         // An offset from the previous frame.
         prevFrame += parseInt(frame, 16);
         fullStack.push(prevFrame);
       // Filter out possible 'overflow' string.
-      } else if (firstChar != 'o') {
+      } else if (firstChar !== 'o') {
         fullStack.push(parseInt(frame, 16));
       } else {
-        console.error(`dropping: ${frame}`);
+        console.error(`Dropping unknown tick frame: ${frame}`);
       }
     }
     return fullStack;
@@ -188,29 +201,23 @@ export class LogReader {
   async dispatchLogRow_(fields) {
     // Obtain the dispatch.
     const command = fields[0];
-    const dispatch = this.dispatchTable_[command];
+    const dispatch = this.dispatchTable_.get(command);
     if (dispatch === undefined) return;
     const parsers = dispatch.parsers;
     const length = parsers.length;
     // Parse fields.
-    const parsedFields = [];
+    const parsedFields = new Array(length);
     for (let i = 0; i < length; ++i) {
       const parser = parsers[i];
-      if (parser === parseString) {
-        parsedFields.push(fields[1 + i]);
-      } else if (typeof parser == 'function') {
-        parsedFields.push(parser(fields[1 + i]));
-      } else if (parser === parseVarArgs) {
-        // var-args
-        parsedFields.push(fields.slice(1 + i));
+      if (parser === parseVarArgs) {
+        parsedFields[i] = fields.slice(1 + i);
         break;
       } else {
-        throw new Error(`Invalid log field parser: ${parser}`);
+        parsedFields[i] = parser(fields[1 + i]);
       }
     }
-
     // Run the processor.
-    await dispatch.processor.apply(this, parsedFields);
+    await dispatch.processor(...parsedFields);
   }
 
   /**

tools/parse-processor.mjs

@@ -746,7 +746,7 @@ function startOf(timestamp, time) {
 export class ParseProcessor extends LogReader {
   constructor() {
     super();
-    this.dispatchTable_ = {
+    this.setDispatchTable({
       // Avoid accidental leaking of __proto__ properties and force this object
       // to be in dictionary-mode.
       __proto__: null,
@@ -780,7 +780,7 @@ export class ParseProcessor extends LogReader {
         parsers: [parseInt, parseString, parseString],
         processor: this.processScriptSource
       },
-    };
+    });
     this.functionEventDispatchTable_ = {
       // Avoid accidental leaking of __proto__ properties and force this object
       // to be in dictionary-mode.
@@ -820,20 +820,7 @@ export class ParseProcessor extends LogReader {
   }
 
   processString(string) {
-    let end = string.length;
-    let current = 0;
-    let next = 0;
-    let line;
-    let i = 0;
-    let entry;
-    while (current < end) {
-      next = string.indexOf("\n", current);
-      if (next === -1) break;
-      i++;
-      line = string.substring(current, next);
-      current = next + 1;
-      this.processLogLine(line);
-    }
+    this.processLogChunk(string);
     this.postProcess();
   }
 

tools/system-analyzer/processor.mjs

@@ -71,18 +71,19 @@ export class Processor extends LogReader {
       parseInt, parseInt, parseInt, parseInt, parseString, parseString,
       parseString, parseString, parseString, parseString
     ];
-    this.dispatchTable_ = {
+    this.setDispatchTable({
       __proto__: null,
       'v8-version': {
         parsers: [
           parseInt,
           parseInt,
         ],
-        processor: this.processV8Version
+        processor: this.processV8Version,
       },
       'shared-library': {
         parsers: [parseString, parseInt, parseInt, parseInt],
-        processor: this.processSharedLibrary
+        processor: this.processSharedLibrary.bind(this),
+        isAsync: true,
       },
       'code-creation': {
         parsers: [
@@ -190,7 +191,7 @@ export class Processor extends LogReader {
         parsers: [parseString, parseVarArgs],
         processor: this.processApiEvent
       },
-    };
+    });
     // TODO(cbruni): Choose correct cpp entries provider
     this._cppEntriesProvider = new RemoteLinuxCppEntriesProvider();
   }
@@ -209,6 +210,7 @@ export class Processor extends LogReader {
     let current = 0;
     let next = 0;
     let line;
+    let lineNumber = 1;
     try {
       while (current < end) {
         next = chunk.indexOf('\n', current);
@@ -222,10 +224,12 @@ export class Processor extends LogReader {
           this._chunkRemainder = '';
         }
         current = next + 1;
+        lineNumber++;
         await this.processLogLine(line);
       }
     } catch (e) {
-      console.error(`Error occurred during parsing, trying to continue: ${e}`);
+      console.error(
+          `Could not parse log line ${lineNumber}, trying to continue: ${e}`);
     }
   }
 

tools/system-analyzer/view/timeline/timeline-track-tick.mjs

@@ -74,7 +74,6 @@ DOM.defineCustomElement(
         const flameStack = [];
         const ticks = this._timeline.values;
         let maxDepth = 0;
-
         for (let tickIndex = 0; tickIndex < ticks.length; tickIndex++) {
           const tick = ticks[tickIndex];
           const tickStack = tick.stack;

tools/tickprocessor.mjs

@@ -510,10 +510,8 @@ export class TickProcessor extends LogReader {
     onlySummary,
     runtimeTimerFilter,
     preprocessJson) {
-    super({},
-      timedRange,
-      pairwiseTimedRange);
-    this.dispatchTable_ = {
+    super(timedRange, pairwiseTimedRange);
+    this.setDispatchTable({
       __proto__: null,
       'shared-library': {
         parsers: [parseString, parseInt, parseInt, parseInt],
@@ -586,7 +584,7 @@ export class TickProcessor extends LogReader {
       'code-allocate': undefined,
       'begin-code-region': undefined,
       'end-code-region': undefined
-    };
+    });
 
     this.preprocessJson = preprocessJson;
     this.cppEntriesProvider_ = cppEntriesProvider;