parse-processor.mjs 37.4 KB
Newer Older
1 2 3
// Copyright 2017 the V8 project authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
4 5
import { LogReader, parseString } from "./logreader.mjs";
import { BaseArgumentsProcessor } from "./arguments.mjs";
6
import { formatBytes, formatMillis} from "./js/helper.mjs";
7 8 9 10 11 12 13

// ===========================================================================

// This is the only true formatting, why? For an international audience the
// confusion between the decimal and thousands separator is big (alternating
// between comma "," vs dot "."). The Swiss formatting uses "'" as a thousands
// separator, dropping most of that confusion.
14
const numberFormat = new Intl.NumberFormat('de-CH', {
15 16 17 18 19
  maximumFractionDigits: 2,
  minimumFractionDigits: 2,
});

function formatNumber(value) {
20
  return numberFormat.format(value);
21 22
}

23
export function BYTES(bytes, total) {
24
  let result = formatBytes(bytes)
25
  if (total !== undefined && total != 0) {
26 27 28 29 30
    result += PERCENT(bytes, total).padStart(5);
  }
  return result;
}

31 32 33 34
export function TIME(millis) {
  return formatMillis(millis, 1);
}

35
export function PERCENT(value, total) {
36 37 38 39
  return Math.round(value / total * 100) + "%";
}

// ===========================================================================
40 41 42 43 44 45 46 47 48 49 50
const kNoTimeMetrics = {
  __proto__: null,
  executionDuration: 0,
  firstEventTimestamp: 0,
  firstParseEventTimestamp: 0,
  lastParseEventTimestamp: 0,
  lastEventTimestamp: 0
};

class CompilationUnit {
  constructor() {
51
    this.isEval = false;
52
    this.isDeserialized = false;
53

54 55 56
    // Lazily computed properties.
    this.firstEventTimestamp = -1;
    this.firstParseEventTimestamp = -1;
57
    this.firstCompileEventTimestamp = -1;
58 59
    this.lastParseEventTimestamp = -1;
    this.lastEventTimestamp = -1;
60
    this.deserializationTimestamp = -1;
61 62 63 64 65 66

    this.preparseTimestamp = -1;
    this.parseTimestamp = -1;
    this.parse2Timestamp = -1;
    this.resolutionTimestamp = -1;
    this.compileTimestamp = -1;
67
    this.lazyCompileTimestamp = -1;
68
    this.executionTimestamp = -1;
69 70
    this.baselineTimestamp = -1;
    this.optimizeTimestamp = -1;
71

72
    this.deserializationDuration = -0.0;
73 74 75 76 77 78 79
    this.preparseDuration = -0.0;
    this.parseDuration = -0.0;
    this.parse2Duration = -0.0;
    this.resolutionDuration = -0.0;
    this.scopeResolutionDuration = -0.0;
    this.lazyCompileDuration = -0.0;
    this.compileDuration = -0.0;
80
    this.baselineDuration = -0.0;
81
    this.optimizeDuration = -0.0;
82 83

    this.ownBytes = -1;
84 85 86 87 88 89 90 91 92 93 94 95 96 97 98
    this.compilationCacheHits = [];
  }

  finalize() {
    this.firstEventTimestamp = this.timestampMin(
        this.deserializationTimestamp, this.parseTimestamp,
        this.preparseTimestamp, this.resolutionTimestamp,
        this.executionTimestamp);

    this.firstParseEventTimestamp = this.timestampMin(
        this.deserializationTimestamp, this.parseTimestamp,
        this.preparseTimestamp, this.resolutionTimestamp);

    this.firstCompileEventTimestamp = this.rawTimestampMin(
        this.deserializationTimestamp, this.compileTimestamp,
99
        this.baselineTimestamp, this.lazyCompileTimestamp);
100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145
    // Any excuted script needs to be compiled.
    if (this.hasBeenExecuted() &&
        (this.firstCompileEventTimestamp <= 0 ||
         this.executionTimestamp < this.firstCompileTimestamp)) {
      console.error('Compile < execution timestamp', this);
    }

    if (this.ownBytes < 0) console.error(this, 'Own bytes must be positive');
  }

  hasBeenExecuted() {
    return this.executionTimestamp > 0;
  }

  addCompilationCacheHit(timestamp) {
    this.compilationCacheHits.push(timestamp);
  }

  // Returns the smallest timestamp from the given list, ignoring
  // uninitialized (-1) values.
  rawTimestampMin(...timestamps) {
    timestamps = timestamps.length == 1 ? timestamps[0] : timestamps;
    let result = timestamps.reduce((min, item) => {
      return item == -1 ? min : (min == -1 ? item : Math.min(item, item));
    }, -1);
    return result;
  }
  timestampMin(...timestamps) {
    let result = this.rawTimestampMin(...timestamps);
    if (Number.isNaN(result) || result < 0) {
      console.error(
          'Invalid timestamp min:', {result, timestamps, script: this});
      return 0;
    }
    return result;
  }

  timestampMax(...timestamps) {
    timestamps = timestamps.length == 1 ? timestamps[0] : timestamps;
    let result = Math.max(...timestamps);
    if (Number.isNaN(result) || result < 0) {
      console.error(
          'Invalid timestamp max:', {result, timestamps, script: this});
      return 0;
    }
    return result;
146 147 148 149 150
  }
}

// ===========================================================================
class Script extends CompilationUnit {
151
  constructor(id) {
152
    super();
153
    if (id === undefined || id <= 0) {
154
      throw new Error(`Invalid id=${id} for script`);
155
    }
156 157 158 159 160
    this.file = '';
    this.id = id;

    this.isNative = false;
    this.isBackgroundCompiled = false;
161
    this.isStreamingCompiled = false;
162

163 164 165 166 167
    this.funktions = [];
    this.metrics = new Map();
    this.maxNestingLevel = 0;

    this.width = 0;
168
    this.bytesTotal = -1;
169 170
    this.finalized = false;
    this.summary = '';
171
    this.source = '';
172 173 174 175 176 177 178 179
  }

  setFile(name) {
    this.file = name;
    this.isNative = name.startsWith('native ');
  }

  isEmpty() {
180
    return this.funktions.length === 0;
181 182
  }

183
  getFunktionAtStartPosition(start) {
184 185 186
    if (!this.isEval && start === 0) {
      throw 'position 0 is reserved for the script';
    }
187 188 189
    if (this.finalized) {
      return this.funktions.find(funktion => funktion.start == start);
    }
190 191 192
    return this.funktions[start];
  }

193 194 195 196 197 198 199 200 201 202
  // Return the innermost function at the given source position.
  getFunktionForPosition(position) {
    if (!this.finalized) throw 'Incomplete script';
    for (let i = this.funktions.length - 1; i >= 0; i--) {
      let funktion = this.funktions[i];
      if (funktion.containsPosition(position)) return funktion;
    }
    return undefined;
  }

203 204 205
  addMissingFunktions(list) {
    if (this.finalized) throw 'script is finalized!';
    list.forEach(fn => {
206
      if (this.funktions[fn.start] === undefined) {
207 208 209 210 211 212 213
        this.addFunktion(fn);
      }
    });
  }

  addFunktion(fn) {
    if (this.finalized) throw 'script is finalized!';
214 215
    if (fn.start === undefined) throw "Funktion has no start position";
    if (this.funktions[fn.start] !== undefined) {
216 217 218 219 220 221 222 223 224 225 226 227 228 229
      fn.print();
      throw "adding same function twice to script";
    }
    this.funktions[fn.start] = fn;
  }

  finalize() {
    this.finalized = true;
    // Compact funktions as we no longer need access via start byte position.
    this.funktions = this.funktions.filter(each => true);
    let parent = null;
    let maxNesting = 0;
    // Iterate over the Funktions in byte position order.
    this.funktions.forEach(fn => {
230
      fn.isEval = this.isEval;
231 232 233 234 235 236 237 238 239 240 241 242 243
      if (parent === null) {
        parent = fn;
      } else {
        // Walk up the nested chain of Funktions to find the parent.
        while (parent !== null && !fn.isNestedIn(parent)) {
          parent = parent.parent;
        }
        fn.parent = parent;
        if (parent) {
          maxNesting = Math.max(maxNesting, parent.addNestedFunktion(fn));
        }
        parent = fn;
      }
244 245 246 247 248 249 250 251 252 253 254 255 256 257 258
    });
    // Sanity checks to ensure that scripts are executed and parsed before any
    // of its funktions.
    let funktionFirstParseEventTimestamp = -1;
    // Second iteration step to finalize the funktions once the proper
    // hierarchy has been set up.
    this.funktions.forEach(fn => {
      fn.finalize();

      funktionFirstParseEventTimestamp = this.timestampMin(
          funktionFirstParseEventTimestamp, fn.firstParseEventTimestamp);

      this.lastParseEventTimestamp = this.timestampMax(
          this.lastParseEventTimestamp, fn.lastParseEventTimestamp);

259
      this.lastEventTimestamp =
260
          this.timestampMax(this.lastEventTimestamp, fn.lastEventTimestamp);
261 262
    });
    this.maxNestingLevel = maxNesting;
263 264

    // Initialize sizes.
265
    if (this.ownBytes === -1) console.error('Invalid ownBytes');
266 267 268 269 270 271
    if (this.funktions.length == 0) {
      this.bytesTotal = this.ownBytes = 0;
      return;
    }
    let toplevelFunktionBytes = this.funktions.reduce(
        (bytes, each) => bytes + (each.isToplevel() ? each.getBytes() : 0), 0);
272
    if (this.isDeserialized || this.isEval || this.isStreamingCompiled) {
273 274 275 276 277
      if (this.getBytes() === -1) {
        this.bytesTotal = toplevelFunktionBytes;
      }
    }
    this.ownBytes = this.bytesTotal - toplevelFunktionBytes;
278 279 280 281 282 283 284
    // Initialize common properties.
    super.finalize();
    // Sanity checks after the minimum timestamps have been computed.
    if (funktionFirstParseEventTimestamp < this.firstParseEventTimestamp) {
      console.error(
          'invalid firstCompileEventTimestamp', this,
          funktionFirstParseEventTimestamp, this.firstParseEventTimestamp);
285
    }
286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309
  }

  print() {
    console.log(this.toString());
  }

  toString() {
    let str = `SCRIPT id=${this.id} file=${this.file}\n` +
      `functions[${this.funktions.length}]:`;
    this.funktions.forEach(fn => str += fn.toString());
    return str;
  }

  getBytes() {
    return this.bytesTotal;
  }

  getOwnBytes() {
    return this.ownBytes;
  }

  // Also see Funktion.prototype.getMetricBytes
  getMetricBytes(name) {
    if (name == 'lazyCompileTimestamp') return this.getOwnBytes();
310
    return this.getOwnBytes();
311 312
  }

313
  getMetricDuration(name) {
314 315 316 317 318 319 320 321 322 323 324 325 326 327 328
    return this[name];
  }

  forEach(fn) {
    fn(this);
    this.funktions.forEach(fn);
  }

  // Container helper for TotalScript / Script.
  getScripts() {
    return [this];
  }

  calculateMetrics(printSummary) {
    let log = (str) => this.summary += str + '\n';
329
    log(`SCRIPT: ${this.id}`);
330 331 332 333 334 335 336 337 338 339 340
    let all = this.funktions;
    if (all.length === 0) return;

    let nofFunktions = all.length;
    let ownBytesSum = list => {
      return list.reduce((bytes, each) => bytes + each.getOwnBytes(), 0)
    };

    let info = (name, funktions) => {
      let ownBytes = ownBytesSum(funktions);
      let nofPercent = Math.round(funktions.length / nofFunktions * 100);
341
      let value = (funktions.length + "#").padStart(7) +
342
        (nofPercent + "%").padStart(5) +
343
        BYTES(ownBytes, this.bytesTotal).padStart(16);
344
      log((`  - ${name}`).padEnd(20) + value);
345 346 347 348 349 350 351
      this.metrics.set(name + "-bytes", ownBytes);
      this.metrics.set(name + "-count", funktions.length);
      this.metrics.set(name + "-count-percent", nofPercent);
      this.metrics.set(name + "-bytes-percent",
        Math.round(ownBytes / this.bytesTotal * 100));
    };

352
    log(`  - file:         ${this.file}`);
353 354
    log('  - details:      ' +
        'isEval=' + this.isEval + ' deserialized=' + this.isDeserialized +
355
        ' streamed=' + this.isStreamingCompiled);
356
    log("    Category               Count           Bytes");
357 358
    info("scripts", this.getScripts());
    info("functions", all);
359
    info("toplevel fns", all.filter(each => each.isToplevel()));
360
    info('preparsed', all.filter(each => each.preparseDuration > 0));
361

362 363 364
    info('fully parsed', all.filter(each => each.parseDuration > 0));
    // info("fn parsed", all.filter(each => each.parse2Duration > 0));
    // info("resolved", all.filter(each => each.resolutionDuration > 0));
365
    info("executed", all.filter(each => each.executionTimestamp > 0));
366
    info('eval', all.filter(each => each.isEval));
367 368 369
    info("lazy compiled", all.filter(each => each.lazyCompileTimestamp > 0));
    info("eager compiled", all.filter(each => each.compileTimestamp > 0));

370 371 372
    info("baseline", all.filter(each => each.baselineTimestamp > 0));
    info("optimized", all.filter(each => each.optimizeTimestamp > 0));

373
    log("    Cost split: executed vs non-executed functions, max = longest single event");
374 375 376 377 378 379 380 381 382 383 384 385 386 387
    const costs = [
      ['parse', each => each.parseDuration],
      ['preparse', each => each.preparseDuration],
      ['resolution', each => each.resolutionDuration],
      ['compile-eager',  each => each.compileDuration],
      ['compile-lazy',  each => each.lazyCompileDuration],
      ['baseline',  each => each.baselineDuration],
      ['optimize', each => each.optimizeDuration],
    ];
    for (let [name, fn] of costs) {
      const executionCost = new ExecutionCost(name, all, fn);
      executionCost.setMetrics(this.metrics);
      log(executionCost.toString());
    }
388 389 390

    let nesting = new NestingDistribution(all);
    nesting.setMetrics(this.metrics);
391
    log(nesting.toString());
392 393 394 395

    if (printSummary) console.log(this.summary);
  }

396 397
  getAccumulatedTimeMetrics(
      metrics, start, end, delta, cumulative = true, useDuration = false) {
398
    // Returns an array of the following format:
399 400
    // [ [start,         acc(metric0, start, start), acc(metric1, ...), ...],
    //   [start+delta,   acc(metric0, start, start+delta), ...],
401 402 403
    //   [start+delta*2, acc(metric0, start, start+delta*2), ...],
    //   ...
    // ]
404
    if (end <= start) throw `Invalid ranges [${start},${end}]`;
405 406 407 408 409
    const timespan = end - start;
    const kSteps = Math.ceil(timespan / delta);
    // To reduce the time spent iterating over the funktions of this script
    // we iterate once over all funktions and add the metric changes to each
    // timepoint:
410
    // [ [0, 300, ...], [1,  15, ...], [2, 100, ...], [3,   0, ...] ... ]
411 412 413 414 415 416 417 418 419
    // In a second step we accumulate all values:
    // [ [0, 300, ...], [1, 315, ...], [2, 415, ...], [3, 415, ...] ... ]
    //
    // To limit the number of data points required in the resulting graphs,
    // only the rows for entries with actual changes are created.

    const metricProperties = ["time"];
    metrics.forEach(each => {
      metricProperties.push(each + 'Timestamp');
420
      if (useDuration) metricProperties.push(each + 'Duration');
421 422 423 424 425 426 427 428 429 430 431
    });
    // Create a packed {rowTemplate} which is copied later-on.
    let indexToTime = (t) => (start + t * delta) / kSecondsToMillis;
    let rowTemplate = [indexToTime(0)];
    for (let i = 1; i < metricProperties.length; i++) rowTemplate.push(0.0);
    // Create rows with 0-time entry.
    let rows = new Array(rowTemplate.slice());
    for (let t = 1; t <= kSteps; t++) rows.push(null);
    // Create the real metric's property name on the Funktion object.
    // Add the increments of each Funktion's metric to the result.
    this.forEach(funktionOrScript => {
432 433
      // Iterate over the Funktion's metric names, skipping position 0 which
      // is the time.
434 435
      const kMetricIncrement = useDuration ? 2 : 1;
      for (let i = 1; i < metricProperties.length; i += kMetricIncrement) {
436 437
        let timestampPropertyName = metricProperties[i];
        let timestamp = funktionOrScript[timestampPropertyName];
438
        if (timestamp === undefined) continue;
439 440
        if (timestamp < start || end < timestamp) continue;
        timestamp -= start;
441 442 443 444 445 446 447 448 449
        let index = Math.floor(timestamp / delta);
        let row = rows[index];
        if (row === null) {
          // Add a new row if it didn't exist,
          row = rows[index] = rowTemplate.slice();
          // .. add the time offset.
          row[0] = indexToTime(index);
        }
        // Add the metric value.
450
        row[i] += funktionOrScript.getMetricBytes(timestampPropertyName);
451
        if (!useDuration) continue;
452 453
        let durationPropertyName = metricProperties[i + 1];
        row[i + 1] += funktionOrScript.getMetricDuration(durationPropertyName);
454 455 456 457 458 459 460 461 462 463 464
      }
    });
    // Create a packed array again with only the valid entries.
    // Accumulate the incremental results by adding the metric values from
    // the previous time window.
    let previous = rows[0];
    let result = [previous];
    for (let t = 1; t < rows.length; t++) {
      let current = rows[t];
      if (current === null) {
        // Ensure a zero data-point after each non-zero point.
465
        if (!cumulative && rows[t - 1] !== null) {
466 467 468 469 470 471
          let duplicate = rowTemplate.slice();
          duplicate[0] = indexToTime(t);
          result.push(duplicate);
        }
        continue;
      }
472
      if (cumulative) {
473 474 475 476 477 478 479
        // Skip i==0 where the corresponding time value in seconds is.
        for (let i = 1; i < metricProperties.length; i++) {
          current[i] += previous[i];
        }
      }
      // Make sure we have a data-point in time right before the current one.
      if (rows[t - 1] === null) {
480
        let duplicate = (!cumulative ? rowTemplate : previous).slice();
481 482 483 484 485 486 487 488 489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544 545 546 547 548 549 550 551 552 553
        duplicate[0] = indexToTime(t - 1);
        result.push(duplicate);
      }
      previous = current;
      result.push(current);
    }
    // Make sure there is an entry at the last position to make sure all graphs
    // have the same width.
    const lastIndex = rows.length - 1;
    if (rows[lastIndex] === null) {
      let duplicate = previous.slice();
      duplicate[0] = indexToTime(lastIndex);
      result.push(duplicate);
    }
    return result;
  }

  getFunktionsAtTime(time, delta, metric) {
    // Returns a list of Funktions whose metric changed in the
    // [time-delta, time+delta] range.
    return this.funktions.filter(
      funktion => funktion.didMetricChange(time, delta, metric));
  }
}


class TotalScript extends Script {
  constructor() {
    super('all files', 'all files');
    this.scripts = [];
  }

  addAllFunktions(script) {
    // funktions is indexed by byte offset and as such not packed. Add every
    // Funktion one by one to keep this.funktions packed.
    script.funktions.forEach(fn => this.funktions.push(fn));
    this.scripts.push(script);
    this.bytesTotal += script.bytesTotal;
  }

  // Iterate over all Scripts and nested Funktions.
  forEach(fn) {
    this.scripts.forEach(script => script.forEach(fn));
  }

  getScripts() {
    return this.scripts;
  }
}


// ===========================================================================

class NestingDistribution {
  constructor(funktions) {
    // Stores the nof bytes per function nesting level.
    this.accumulator = [0, 0, 0, 0, 0];
    // Max nof bytes encountered at any nesting level.
    this.max = 0;
    // avg bytes per nesting level.
    this.avg = 0;
    this.totalBytes = 0;

    funktions.forEach(each => each.accumulateNestingLevel(this.accumulator));
    this.max = this.accumulator.reduce((max, each) => Math.max(max, each), 0);
    this.totalBytes = this.accumulator.reduce((sum, each) => sum + each, 0);
    for (let i = 0; i < this.accumulator.length; i++) {
      this.avg += this.accumulator[i] * i;
    }
    this.avg /= this.totalBytes;
  }

  print() {
554
    console.log(this.toString());
555 556 557 558 559 560 561 562 563 564 565 566
  }

  toString() {
    let ticks = " ▁▂▃▄▅▆▇█";
    let accString = this.accumulator.reduce((str, each) => {
      let index = Math.round(each / this.max * (ticks.length - 1));
      return str + ticks[index];
    }, '');
    let percent0 = this.accumulator[0]
    let percent1 = this.accumulator[1];
    let percent2plus = this.accumulator.slice(2)
      .reduce((sum, each) => sum + each, 0);
567
    return "  - fn nesting level:     " +
568 569 570 571
      ' avg=' + formatNumber(this.avg) +
      ' l0=' + PERCENT(percent0, this.totalBytes) +
      ' l1=' + PERCENT(percent1, this.totalBytes) +
      ' l2+=' + PERCENT(percent2plus, this.totalBytes) +
572
      ' nesting-histogram=[' + accString + ']';
573 574 575 576 577 578 579 580 581 582

  }

  setMetrics(dict) {}
}

class ExecutionCost {
  constructor(prefix, funktions, time_fn) {
    this.prefix = prefix;
    // Time spent on executed functions.
583
    this.executedCost = 0;
584 585
    // Time spent on not executed functions.
    this.nonExecutedCost = 0;
586
    this.maxDuration = 0;
587

588 589 590 591 592 593 594 595 596 597
    for (let i = 0; i < funktions.length; i++) {
      const funktion = funktions[i];
      const value = time_fn(funktion);
      if (funktion.hasBeenExecuted()) {
        this.executedCost +=  value;
      } else {
        this.nonExecutedCost += value;
      }
      this.maxDuration = Math.max(this.maxDuration, value);
    }
598 599 600 601 602 603 604
  }

  print() {
    console.log(this.toString())
  }

  toString() {
605
    return `  - ${this.prefix}-time:`.padEnd(24) +
606 607 608
      ` Σ executed=${TIME(this.executedCost)}`.padEnd(20) +
      ` Σ non-executed=${TIME(this.nonExecutedCost)}`.padEnd(24) +
      ` max=${TIME(this.maxDuration)}`;
609 610 611 612 613 614 615 616 617 618
  }

  setMetrics(dict) {
    dict.set('parseMetric', this.executionCost);
    dict.set('parseMetricNegative', this.nonExecutionCost);
  }
}

// ===========================================================================

619
class Funktion extends CompilationUnit {
620
  constructor(name, start, end, script) {
621
    super();
622
    if (start < 0) throw `invalid start position: ${start}`;
623 624 625
    if (script.isEval) {
      if (end < start) throw 'invalid start end positions';
    } else {
626
      if (end <= 0) throw `invalid end position: ${end}`;
627 628
      if (end < start) throw 'invalid start end positions';
      if (end == start) console.error("Possibly invalid start/end position")
629
    }
630 631 632 633 634 635 636 637 638 639 640 641

    this.name = name;
    this.start = start;
    this.end = end;
    this.script = script;
    this.parent = null;
    this.nested = [];
    this.nestingLevel = 0;

    if (script) this.script.addFunktion(this);
  }

642 643 644 645 646 647 648 649 650 651 652 653 654 655 656 657 658
  finalize() {
    this.lastParseEventTimestamp = Math.max(
        this.preparseTimestamp + this.preparseDuration,
        this.parseTimestamp + this.parseDuration,
        this.resolutionTimestamp + this.resolutionDuration);
    if (!(this.lastParseEventTimestamp > 0)) this.lastParseEventTimestamp = 0;

    this.lastEventTimestamp =
        Math.max(this.lastParseEventTimestamp, this.executionTimestamp);
    if (!(this.lastEventTimestamp > 0)) this.lastEventTimestamp = 0;

    this.ownBytes = this.nested.reduce(
        (bytes, each) => bytes - each.getBytes(), this.getBytes());

    super.finalize();
  }

659 660
  getMetricBytes(name) {
    if (name == 'lazyCompileTimestamp') return this.getOwnBytes();
661
    return this.getOwnBytes();
662 663
  }

664
  getMetricDuration(name) {
665 666 667 668 669 670 671 672 673 674
    if (name in kNoTimeMetrics) return 0;
    return this[name];
  }

  isNestedIn(funktion) {
    if (this.script != funktion.script) throw "Incompatible script";
    return funktion.start < this.start && this.end <= funktion.end;
  }

  isToplevel() {
675
    return this.parent === null;
676 677
  }

678 679
  containsPosition(position) {
    return this.start <= position && position <= this.end;
680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707 708 709 710 711 712 713 714 715 716 717 718 719 720 721
  }

  accumulateNestingLevel(accumulator) {
    let value = accumulator[this.nestingLevel] || 0;
    accumulator[this.nestingLevel] = value + this.getOwnBytes();
  }

  addNestedFunktion(child) {
    if (this.script != child.script) throw "Incompatible script";
    if (child == null) throw "Nesting non child";
    this.nested.push(child);
    if (this.nested.length > 1) {
      // Make sure the nested children don't overlap and have been inserted in
      // byte start position order.
      let last = this.nested[this.nested.length - 2];
      if (last.end > child.start || last.start > child.start ||
        last.end > child.end || last.start > child.end) {
        throw "Wrongly nested child added";
      }
    }
    child.nestingLevel = this.nestingLevel + 1;
    return child.nestingLevel;
  }

  getBytes() {
    return this.end - this.start;
  }

  getOwnBytes() {
    return this.ownBytes;
  }

  didMetricChange(time, delta, name) {
    let value = this[name + 'Timestamp'];
    return (time - delta) <= value && value <= (time + delta);
  }

  print() {
    console.log(this.toString());
  }

  toString(details = true) {
722
    let result = `function${this.name ? ` ${this.name}` : ''}` +
723
        `() range=${this.start}-${this.end}`;
724 725 726 727 728 729 730 731
    if (details) result += ` script=${this.script ? this.script.id : 'X'}`;
    return result;
  }
}


// ===========================================================================

732 733
export const kTimestampFactor = 1000;
export const kSecondsToMillis = 1000;
734 735 736 737 738 739 740

function toTimestamp(microseconds) {
  return microseconds / kTimestampFactor
}

function startOf(timestamp, time) {
  let result = toTimestamp(timestamp) - time;
741
  if (result < 0) throw "start timestamp cannot be negative";
742 743 744 745
  return result;
}


746
export class ParseProcessor extends LogReader {
747 748
  constructor() {
    super();
749
    this.setDispatchTable({
750 751 752
      // Avoid accidental leaking of __proto__ properties and force this object
      // to be in dictionary-mode.
      __proto__: null,
753 754 755
      // "function",{event type},
      // {script id},{start position},{end position},{time},{timestamp},
      // {function name}
756 757
      'function': {
        parsers: [
758 759
          parseString, parseInt, parseInt, parseInt, parseFloat, parseInt,
          parseString
760 761
        ],
        processor: this.processFunctionEvent
762
      },
763 764
      // "compilation-cache","hit"|"put",{type},{scriptid},{start position},
      // {end position},{timestamp}
765
      'compilation-cache': {
766 767
        parsers:
            [parseString, parseString, parseInt, parseInt, parseInt, parseInt],
768
        processor: this.processCompilationCacheEvent
769 770
      },
      'script': {
771
        parsers: [parseString, parseInt, parseInt],
772 773 774 775 776 777
        processor: this.processScriptEvent
      },
      // "script-details", {script_id}, {file}, {line}, {column}, {size}
      'script-details': {
        parsers: [parseInt, parseString, parseInt, parseInt, parseInt],
        processor: this.processScriptDetails
778 779 780 781 782
      },
      'script-source': {
        parsers: [parseInt, parseString, parseString],
        processor: this.processScriptSource
      },
783
    });
784 785 786 787 788
    this.functionEventDispatchTable_ = {
      // Avoid accidental leaking of __proto__ properties and force this object
      // to be in dictionary-mode.
      __proto__: null,
      'full-parse': this.processFull.bind(this),
789 790 791 792
      'parse-function': this.processParseFunction.bind(this),
      // TODO(cbruni): make sure arrow functions emit a normal parse-function
      // event.
      'parse': this.processParseFunction.bind(this),
793 794
      'parse-script': this.processParseScript.bind(this),
      'parse-eval': this.processParseEval.bind(this),
795 796 797
      'preparse-no-resolution': this.processPreparseNoResolution.bind(this),
      'preparse-resolution': this.processPreparseResolution.bind(this),
      'first-execution': this.processFirstExecution.bind(this),
798 799 800
      'interpreter-lazy': this.processCompileLazy.bind(this),
      'interpreter': this.processCompile.bind(this),
      'interpreter-eval': this.processCompileEval.bind(this),
801 802
      'baseline': this.processBaselineLazy.bind(this),
      'baseline-lazy': this.processBaselineLazy.bind(this),
803 804
      'optimize-lazy': this.processOptimizeLazy.bind(this),
      'deserialize': this.processDeserialize.bind(this),
805 806 807 808 809 810 811
    };

    this.idToScript = new Map();
    this.fileToScript = new Map();
    this.nameToFunction = new Map();
    this.scripts = [];
    this.totalScript = new TotalScript();
812 813 814
    this.firstEventTimestamp = -1;
    this.lastParseEventTimestamp = -1;
    this.lastEventTimestamp = -1;
815 816 817 818 819 820 821
  }

  print() {
    console.log("scripts:");
    this.idToScript.forEach(script => script.print());
  }

822 823
  async processString(string) {
    await this.processLogChunk(string);
824 825 826
    this.postProcess();
  }

827
  async processLogFile(fileName) {
828 829
    this.collectEntries = true
    this.lastLogFileName_ = fileName;
830
    let line;
831
    while (line = readline()) {
832
      await this.processLogLine(line);
833 834 835 836 837 838 839 840
    }
    this.postProcess();
  }

  postProcess() {
    this.scripts = Array.from(this.idToScript.values())
      .filter(each => !each.isNative);

841 842 843 844 845
    if (this.scripts.length == 0) {
      console.error("Could not find any scripts!");
      return false;
    }

846 847
    this.scripts.forEach(script => {
      script.finalize();
848
      script.calculateMetrics(false);
849
    });
850 851 852

    this.scripts.forEach(script => this.totalScript.addAllFunktions(script));
    this.totalScript.calculateMetrics(true);
853 854 855 856 857 858 859 860

    this.firstEventTimestamp = this.totalScript.timestampMin(
        this.scripts.map(each => each.firstEventTimestamp));
    this.lastParseEventTimestamp = this.totalScript.timestampMax(
        this.scripts.map(each => each.lastParseEventTimestamp));
    this.lastEventTimestamp = this.totalScript.timestampMax(
        this.scripts.map(each => each.lastEventTimestamp));

861 862 863 864 865 866 867 868 869 870
    const series = {
      firstParseEvent: 'Any Parse Event',
      parse: 'Parsing',
      preparse: 'Preparsing',
      resolution: 'Preparsing with Var. Resolution',
      lazyCompile: 'Lazy Compilation',
      compile: 'Eager Compilation',
      execution: 'First Execution',
    };
    let metrics = Object.keys(series);
871 872
    this.totalScript.getAccumulatedTimeMetrics(
        metrics, 0, this.lastEventTimestamp, 10);
873 874 875
  }

  processFunctionEvent(
876 877
      eventName, scriptId, startPosition, endPosition, duration, timestamp,
      functionName) {
878 879
    let handlerFn = this.functionEventDispatchTable_[eventName];
    if (handlerFn === undefined) {
880
      console.error(`Couldn't find handler for function event:${eventName}`);
881 882
    }
    handlerFn(
883
        scriptId, startPosition, endPosition, duration, timestamp,
884 885
        functionName);
  }
886 887 888 889 890

  addEntry(entry) {
    this.entries.push(entry);
  }

891 892
  lookupScript(id) {
    return this.idToScript.get(id);
893 894
  }

895 896 897
  getOrCreateFunction(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    if (scriptId == -1) {
898 899
      return this.lookupFunktionByRange(startPosition, endPosition);
    }
900
    let script = this.lookupScript(scriptId);
901
    let funktion = script.getFunktionAtStartPosition(startPosition);
902
    if (funktion === undefined) {
903 904 905 906 907
      funktion = new Funktion(functionName, startPosition, endPosition, script);
    }
    return funktion;
  }

908 909 910 911 912
  // Iterates over all functions and tries to find matching ones.
  lookupFunktionsByRange(start, end) {
    let results = [];
    this.idToScript.forEach(script => {
      script.forEach(funktion => {
913
        if (funktion.startPosition == start && funktion.endPosition == end) {
914 915 916 917 918 919 920 921 922 923 924 925
          results.push(funktion);
        }
      });
    });
    return results;
  }
  lookupFunktionByRange(start, end) {
    let results = this.lookupFunktionsByRange(start, end);
    if (results.length != 1) throw "Could not find unique function by range";
    return results[0];
  }

926 927 928 929 930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946 947 948 949 950 951 952 953 954 955 956 957 958
  processScriptEvent(eventName, scriptId, timestamp) {
    let script = this.idToScript.get(scriptId);
    switch (eventName) {
      case 'create':
      case 'reserve-id':
      case 'deserialize': {
        if (script !== undefined) return;
        script = new Script(scriptId);
        this.idToScript.set(scriptId, script);
        if (eventName == 'deserialize') {
          script.deserializationTimestamp = toTimestamp(timestamp);
        }
        return;
      }
      case 'background-compile':
        if (script.isBackgroundCompiled) {
          throw 'Cannot background-compile twice';
        }
        script.isBackgroundCompiled = true;
        // TODO(cbruni): remove once backwards compatibility is no longer needed.
        script.isStreamingCompiled = true;
        // TODO(cbruni): fix parse events for background compilation scripts
        script.preparseTimestamp = toTimestamp(timestamp);
        return;
      case 'streaming-compile':
        if (script.isStreamingCompiled) throw 'Cannot stream-compile twice';
        // TODO(cbruni): remove once backwards compatibility is no longer needed.
        script.isBackgroundCompiled = true;
        script.isStreamingCompiled = true;
        // TODO(cbruni): fix parse events for background compilation scripts
        script.preparseTimestamp = toTimestamp(timestamp);
        return;
      default:
959
        console.error(`Unhandled script event: ${eventName}`);
960 961 962 963 964 965 966 967
    }
  }

  processScriptDetails(scriptId, file, startLine, startColumn, size) {
    let script = this.lookupScript(scriptId);
    script.setFile(file);
  }

968 969 970 971 972
  processScriptSource(scriptId, url, source) {
    let script = this.lookupScript(scriptId);
    script.source = source;
  }

973
  processParseEval(
974
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
975 976 977 978
    if (startPosition != 0 && startPosition != -1) {
      console.error('Invalid start position for parse-eval', arguments);
    }
    let script = this.processParseScript(...arguments);
979 980 981
    script.isEval = true;
  }

982 983
  processFull(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
984 985
    if (startPosition == 0) {
      // This should only happen for eval.
986
      let script = this.lookupScript(scriptId);
987 988 989
      script.isEval = true;
      return;
    }
990
    let funktion = this.getOrCreateFunction(...arguments);
991 992 993
    // TODO(cbruni): this should never happen, emit differen event from the
    // parser.
    if (funktion.parseTimestamp > 0) return;
994
    funktion.parseTimestamp = startOf(timestamp, duration);
995
    funktion.parseDuration = duration;
996 997
  }

998 999 1000
  processParseFunction(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let funktion = this.getOrCreateFunction(...arguments);
1001
    funktion.parseTimestamp = startOf(timestamp, duration);
1002
    funktion.parseDuration = duration;
1003 1004
  }

1005
  processParseScript(
1006
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
1007
    // TODO timestamp and duration
1008
    let script = this.lookupScript(scriptId);
1009
    let ts = startOf(timestamp, duration);
1010
    script.parseTimestamp = ts;
1011
    script.parseDuration = duration;
1012
    return script;
1013 1014
  }

1015 1016 1017
  processPreparseResolution(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let funktion = this.getOrCreateFunction(...arguments);
1018 1019 1020
    // TODO(cbruni): this should never happen, emit different event from the
    // parser.
    if (funktion.resolutionTimestamp > 0) return;
1021
    funktion.resolutionTimestamp = startOf(timestamp, duration);
1022
    funktion.resolutionDuration = duration;
1023 1024
  }

1025 1026 1027
  processPreparseNoResolution(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let funktion = this.getOrCreateFunction(...arguments);
1028
    funktion.preparseTimestamp = startOf(timestamp, duration);
1029
    funktion.preparseDuration = duration;
1030 1031
  }

1032 1033 1034
  processFirstExecution(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let script = this.lookupScript(scriptId);
1035 1036 1037 1038 1039 1040
    if (startPosition === 0) {
      // undefined = eval fn execution
      if (script) {
        script.executionTimestamp = toTimestamp(timestamp);
      }
    } else {
1041
      let funktion = script.getFunktionAtStartPosition(startPosition);
1042 1043
      if (funktion) {
        funktion.executionTimestamp = toTimestamp(timestamp);
1044 1045
      } else {
        // TODO(cbruni): handle funktions from  compilation-cache hits.
1046 1047 1048 1049
      }
    }
  }

1050 1051 1052
  processCompileLazy(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let funktion = this.getOrCreateFunction(...arguments);
1053
    funktion.lazyCompileTimestamp = startOf(timestamp, duration);
1054
    funktion.lazyCompileDuration = duration;
1055 1056
  }

1057 1058 1059
  processCompile(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let script = this.lookupScript(scriptId);
1060
    if (startPosition === 0) {
1061
      script.compileTimestamp = startOf(timestamp, duration);
1062
      script.compileDuration = duration;
1063
      script.bytesTotal = endPosition;
1064
      return script;
1065
    } else {
1066
      let funktion = script.getFunktionAtStartPosition(startPosition);
1067 1068
      if (funktion === undefined) {
        // This should not happen since any funktion has to be parsed first.
1069 1070
        console.error('processCompile funktion not found', ...arguments);
        return;
1071 1072
      }
      funktion.compileTimestamp = startOf(timestamp, duration);
1073
      funktion.compileDuration = duration;
1074
      return funktion;
1075 1076
    }
  }
1077

1078 1079
  processCompileEval(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
1080 1081
    let compilationUnit = this.processCompile(...arguments);
    compilationUnit.isEval = true;
1082 1083
  }

1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097 1098 1099
  processBaselineLazy(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let compilationUnit = this.lookupScript(scriptId);
    if (startPosition > 0) {
      compilationUnit =
          compilationUnit.getFunktionAtStartPosition(startPosition);
      if (compilationUnit === undefined) {
        // This should not happen since any funktion has to be parsed first.
        console.error('processBaselineLazy funktion not found', ...arguments);
        return;
      }
    }
    compilationUnit.baselineTimestamp = startOf(timestamp, duration);
    compilationUnit.baselineDuration = duration;
  }

1100 1101
  processOptimizeLazy(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
1102 1103 1104 1105 1106 1107 1108 1109 1110 1111
    let compilationUnit = this.lookupScript(scriptId);
    if (startPosition > 0) {
      compilationUnit =
          compilationUnit.getFunktionAtStartPosition(startPosition);
      if (compilationUnit === undefined) {
        // This should not happen since any funktion has to be parsed first.
        console.error('processOptimizeLazy funktion not found', ...arguments);
        return;
      }
    }
1112 1113
    compilationUnit.optimizeTimestamp = startOf(timestamp, duration);
    compilationUnit.optimizeDuration = duration;
1114 1115
  }

1116 1117 1118 1119 1120 1121 1122 1123 1124 1125
  processDeserialize(
      scriptId, startPosition, endPosition, duration, timestamp, functionName) {
    let compilationUnit = this.lookupScript(scriptId);
    if (startPosition === 0) {
      compilationUnit.bytesTotal = endPosition;
    } else {
      compilationUnit = this.getOrCreateFunction(...arguments);
    }
    compilationUnit.deserializationTimestamp = startOf(timestamp, duration);
    compilationUnit.deserializationDuration = duration;
1126
    compilationUnit.isDeserialized = true;
1127 1128 1129 1130 1131 1132 1133 1134 1135 1136 1137
  }

  processCompilationCacheEvent(
      eventType, cacheType, scriptId, startPosition, endPosition, timestamp) {
    if (eventType !== 'hit') return;
    let compilationUnit = this.lookupScript(scriptId);
    if (startPosition > 0) {
      compilationUnit =
          compilationUnit.getFunktionAtStartPosition(startPosition);
    }
    compilationUnit.addCompilationCacheHit(toTimestamp(timestamp));
1138 1139
  }

1140 1141 1142
}


1143
export class ArgumentsProcessor extends BaseArgumentsProcessor {
1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154
  getArgsDispatch() {
    return {};
  }

  getDefaultResults() {
    return {
      logFileName: 'v8.log',
      range: 'auto,auto',
    };
  }
}