1// Copyright 2020 the V8 project authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5import {LogReader, parseString, parseVarArgs} from '../logreader.mjs';
6import {Profile} from '../profile.mjs';
7import {RemoteLinuxCppEntriesProvider, RemoteMacOSCppEntriesProvider} from '../tickprocessor.mjs'
8
9import {CodeLogEntry, DeoptLogEntry, FeedbackVectorEntry, SharedLibLogEntry} from './log/code.mjs';
10import {IcLogEntry} from './log/ic.mjs';
11import {Edge, MapLogEntry} from './log/map.mjs';
12import {TickLogEntry} from './log/tick.mjs';
13import {TimerLogEntry} from './log/timer.mjs';
14import {Timeline} from './timeline.mjs';
15
16// ===========================================================================
17
18class AsyncConsumer {
19  constructor(consumer_fn) {
20    this._chunks = [];
21    this._consumer = consumer_fn;
22    this._pendingWork = Promise.resolve();
23    this._isConsuming = false;
24  }
25
26  get pendingWork() {
27    return this._pendingWork;
28  }
29
30  push(chunk) {
31    this._chunks.push(chunk);
32    this.consumeAll();
33  }
34
35  async consumeAll() {
36    if (!this._isConsuming) this._pendingWork = this._consumeAll();
37    return await this._pendingWork;
38  }
39
40  async _consumeAll() {
41    this._isConsuming = true;
42    while (this._chunks.length > 0) {
43      await this._consumer(this._chunks.shift());
44    }
45    this._isConsuming = false;
46  }
47}
48
49export class Processor extends LogReader {
50  _profile = new Profile();
51  _codeTimeline = new Timeline();
52  _deoptTimeline = new Timeline();
53  _icTimeline = new Timeline();
54  _mapTimeline = new Timeline();
55  _tickTimeline = new Timeline();
56  _timerTimeline = new Timeline();
57  _formatPCRegexp = /(.*):[0-9]+:[0-9]+$/;
58  _lastTimestamp = 0;
59  _lastCodeLogEntry;
60  _lastTickLogEntry;
61  _chunkRemainder = '';
62
63  _totalInputBytes = 0;
64  _processedInputChars = 0;
65  _progressCallback;
66
67  MAJOR_VERSION = 7;
68  MINOR_VERSION = 6;
69  constructor() {
70    super();
71    this._chunkConsumer =
72        new AsyncConsumer((chunk) => this._processChunk(chunk));
73    const propertyICParser = [
74      parseInt, parseInt, parseInt, parseInt, parseString, parseString,
75      parseString, parseString, parseString, parseString
76    ];
77    this.setDispatchTable({
78      __proto__: null,
79      'v8-version': {
80        parsers: [
81          parseInt,
82          parseInt,
83        ],
84        processor: this.processV8Version,
85      },
86      'shared-library': {
87        parsers: [parseString, parseInt, parseInt, parseInt],
88        processor: this.processSharedLibrary.bind(this),
89        isAsync: true,
90      },
91      'code-creation': {
92        parsers: [
93          parseString, parseInt, parseInt, parseInt, parseInt, parseString,
94          parseVarArgs
95        ],
96        processor: this.processCodeCreation
97      },
98      'code-deopt': {
99        parsers: [
100          parseInt, parseInt, parseInt, parseInt, parseInt, parseString,
101          parseString, parseString
102        ],
103        processor: this.processCodeDeopt
104      },
105      'code-move':
106          {parsers: [parseInt, parseInt], processor: this.processCodeMove},
107      'code-delete': {parsers: [parseInt], processor: this.processCodeDelete},
108      'code-source-info': {
109        parsers: [
110          parseInt, parseInt, parseInt, parseInt, parseString, parseString,
111          parseString
112        ],
113        processor: this.processCodeSourceInfo
114      },
115      'code-disassemble': {
116        parsers: [
117          parseInt,
118          parseString,
119          parseString,
120        ],
121        processor: this.processCodeDisassemble
122      },
123      'feedback-vector': {
124        parsers: [
125          parseInt, parseString, parseInt, parseInt, parseString, parseString,
126          parseInt, parseInt, parseString
127        ],
128        processor: this.processFeedbackVector
129      },
130      'script-source': {
131        parsers: [parseInt, parseString, parseString],
132        processor: this.processScriptSource
133      },
134      'sfi-move':
135          {parsers: [parseInt, parseInt], processor: this.processFunctionMove},
136      'tick': {
137        parsers:
138            [parseInt, parseInt, parseInt, parseInt, parseInt, parseVarArgs],
139        processor: this.processTick
140      },
141      'active-runtime-timer': undefined,
142      'heap-sample-begin': undefined,
143      'heap-sample-end': undefined,
144      'timer-event-start': {
145        parsers: [parseString, parseInt],
146        processor: this.processTimerEventStart
147      },
148      'timer-event-end': {
149        parsers: [parseString, parseInt],
150        processor: this.processTimerEventEnd
151      },
152      'map-create':
153          {parsers: [parseInt, parseString], processor: this.processMapCreate},
154      'map': {
155        parsers: [
156          parseString, parseInt, parseString, parseString, parseInt, parseInt,
157          parseInt, parseString, parseString
158        ],
159        processor: this.processMap
160      },
161      'map-details': {
162        parsers: [parseInt, parseString, parseString],
163        processor: this.processMapDetails
164      },
165      'LoadGlobalIC': {
166        parsers: propertyICParser,
167        processor: this.processPropertyIC.bind(this, 'LoadGlobalIC')
168      },
169      'StoreGlobalIC': {
170        parsers: propertyICParser,
171        processor: this.processPropertyIC.bind(this, 'StoreGlobalIC')
172      },
173      'LoadIC': {
174        parsers: propertyICParser,
175        processor: this.processPropertyIC.bind(this, 'LoadIC')
176      },
177      'StoreIC': {
178        parsers: propertyICParser,
179        processor: this.processPropertyIC.bind(this, 'StoreIC')
180      },
181      'KeyedLoadIC': {
182        parsers: propertyICParser,
183        processor: this.processPropertyIC.bind(this, 'KeyedLoadIC')
184      },
185      'KeyedStoreIC': {
186        parsers: propertyICParser,
187        processor: this.processPropertyIC.bind(this, 'KeyedStoreIC')
188      },
189      'StoreInArrayLiteralIC': {
190        parsers: propertyICParser,
191        processor: this.processPropertyIC.bind(this, 'StoreInArrayLiteralIC')
192      },
193      'api': {
194        parsers: [parseString, parseVarArgs],
195        processor: this.processApiEvent
196      },
197    });
198    // TODO(cbruni): Choose correct cpp entries provider
199    this._cppEntriesProvider = new RemoteLinuxCppEntriesProvider();
200  }
201
202  printError(str) {
203    console.error(str);
204    throw str
205  }
206
207  processChunk(chunk) {
208    this._chunkConsumer.push(chunk)
209  }
210
211  setProgressCallback(totalSize, callback) {
212    this._totalInputBytes = totalSize;
213    this._progressCallback = callback;
214  }
215
216  async _updateProgress() {
217    if (!this._progressCallback) return;
218    // We use chars and bytes interchangeably for simplicity. This causes us to
219    // slightly underestimate progress.
220    this._progressCallback(
221        this._processedInputChars / this._totalInputBytes,
222        this._processedInputChars);
223  }
224
225  async _processChunk(chunk) {
226    const prevProcessedInputChars = this._processedInputChars;
227    let end = chunk.length;
228    let current = 0;
229    let next = 0;
230    let line;
231    let lineNumber = 1;
232    try {
233      while (current < end) {
234        next = chunk.indexOf('\n', current);
235        if (next === -1) {
236          this._chunkRemainder = chunk.substring(current);
237          break;
238        }
239        line = chunk.substring(current, next);
240        if (this._chunkRemainder) {
241          line = this._chunkRemainder + line;
242          this._chunkRemainder = '';
243        }
244        current = next + 1;
245        lineNumber++;
246        await this.processLogLine(line);
247        this._processedInputChars = prevProcessedInputChars + current;
248      }
249      this._updateProgress();
250    } catch (e) {
251      console.error(
252          `Could not parse log line ${lineNumber}, trying to continue: ${e}`);
253    }
254  }
255
256  async processLogFile(fileName) {
257    this.collectEntries = true;
258    this.lastLogFileName_ = fileName;
259    let i = 1;
260    let line;
261    try {
262      while (line = readline()) {
263        await this.processLogLine(line);
264        i++;
265      }
266    } catch (e) {
267      console.error(
268          `Error occurred during parsing line ${i}` +
269          ', trying to continue: ' + e);
270    }
271    this.finalize();
272  }
273
274  async finalize() {
275    await this._chunkConsumer.consumeAll();
276    if (this._profile.warnings.size > 0) {
277      console.warn('Found profiler warnings:', this._profile.warnings);
278    }
279    // TODO(cbruni): print stats;
280    this._mapTimeline.transitions = new Map();
281    let id = 0;
282    this._mapTimeline.forEach(map => {
283      if (map.isRoot()) id = map.finalizeRootMap(id + 1);
284      if (map.edge && map.edge.name) {
285        const edge = map.edge;
286        const list = this._mapTimeline.transitions.get(edge.name);
287        if (list === undefined) {
288          this._mapTimeline.transitions.set(edge.name, [edge]);
289        } else {
290          list.push(edge);
291        }
292      }
293    });
294  }
295
296  processV8Version(majorVersion, minorVersion) {
297    if ((majorVersion == this.MAJOR_VERSION &&
298         minorVersion <= this.MINOR_VERSION) ||
299        (majorVersion < this.MAJOR_VERSION)) {
300      window.alert(
301          `Unsupported version ${majorVersion}.${minorVersion}. \n` +
302          `Please use the matching tool for given the V8 version.`);
303    }
304  }
305
306  async processSharedLibrary(name, startAddr, endAddr, aslrSlide) {
307    const entry = this._profile.addLibrary(name, startAddr, endAddr);
308    entry.logEntry = new SharedLibLogEntry(entry);
309    // Many events rely on having a script around, creating fake entries for
310    // shared libraries.
311    this._profile.addScriptSource(-1, name, '');
312    await this._cppEntriesProvider.parseVmSymbols(
313        name, startAddr, endAddr, aslrSlide, (fName, fStart, fEnd) => {
314          this._profile.addStaticCode(fName, fStart, fEnd);
315        });
316  }
317
318  processCodeCreation(type, kind, timestamp, start, size, name, maybe_func) {
319    this._lastTimestamp = timestamp;
320    let entry;
321    let stateName = '';
322    if (maybe_func.length) {
323      const funcAddr = parseInt(maybe_func[0]);
324      stateName = maybe_func[1] ?? '';
325      const state = Profile.parseState(maybe_func[1]);
326      entry = this._profile.addFuncCode(
327          type, name, timestamp, start, size, funcAddr, state);
328    } else {
329      entry = this._profile.addCode(type, name, timestamp, start, size);
330    }
331    this._lastCodeLogEntry = new CodeLogEntry(
332        type + stateName, timestamp,
333        Profile.getKindFromState(Profile.parseState(stateName)), kind, entry);
334    this._codeTimeline.push(this._lastCodeLogEntry);
335  }
336
337  processCodeDeopt(
338      timestamp, codeSize, instructionStart, inliningId, scriptOffset,
339      deoptKind, deoptLocation, deoptReason) {
340    this._lastTimestamp = timestamp;
341    const profCodeEntry = this._profile.findEntry(instructionStart);
342    const logEntry = new DeoptLogEntry(
343        deoptKind, timestamp, profCodeEntry, deoptReason, deoptLocation,
344        scriptOffset, instructionStart, codeSize, inliningId);
345    profCodeEntry.logEntry.add(logEntry);
346    this._deoptTimeline.push(logEntry);
347    this.addSourcePosition(profCodeEntry, logEntry);
348    logEntry.functionSourcePosition = logEntry.sourcePosition;
349    // custom parse deopt location
350    if (deoptLocation === '<unknown>') return;
351    // Handle deopt location for inlined code: <location> inlined at <location>
352    const inlinedPos = deoptLocation.indexOf(' inlined at ');
353    if (inlinedPos > 0) {
354      deoptLocation = deoptLocation.substring(0, inlinedPos)
355    }
356    const script = this.getProfileEntryScript(profCodeEntry);
357    if (!script) return;
358    const colSeparator = deoptLocation.lastIndexOf(':');
359    const rowSeparator = deoptLocation.lastIndexOf(':', colSeparator - 1);
360    const line =
361        parseInt(deoptLocation.substring(rowSeparator + 1, colSeparator));
362    const column = parseInt(
363        deoptLocation.substring(colSeparator + 1, deoptLocation.length - 1));
364    logEntry.sourcePosition = script.addSourcePosition(line, column, logEntry);
365  }
366
367  processFeedbackVector(
368      timestamp, fbv_address, fbv_length, instructionStart, optimization_marker,
369      optimization_tier, invocation_count, profiler_ticks, fbv_string) {
370    const profCodeEntry = this._profile.findEntry(instructionStart);
371    if (!profCodeEntry) {
372      console.warn('Didn\'t find code for FBV', {fbv, instructionStart});
373      return;
374    }
375    const fbv = new FeedbackVectorEntry(
376        timestamp, profCodeEntry.logEntry, fbv_address, fbv_length,
377        optimization_marker, optimization_tier, invocation_count,
378        profiler_ticks, fbv_string);
379    profCodeEntry.logEntry.setFeedbackVector(fbv);
380  }
381
382  processScriptSource(scriptId, url, source) {
383    this._profile.addScriptSource(scriptId, url, source);
384  }
385
386  processCodeMove(from, to) {
387    this._profile.moveCode(from, to);
388  }
389
390  processCodeDelete(start) {
391    this._profile.deleteCode(start);
392  }
393
394  processFunctionMove(from, to) {
395    this._profile.moveFunc(from, to);
396  }
397
398  processTick(
399      pc, time_ns, is_external_callback, tos_or_external_callback, vmState,
400      stack) {
401    if (is_external_callback) {
402      // Don't use PC when in external callback code, as it can point
403      // inside callback's code, and we will erroneously report
404      // that a callback calls itself. Instead we use tos_or_external_callback,
405      // as simply resetting PC will produce unaccounted ticks.
406      pc = tos_or_external_callback;
407      tos_or_external_callback = 0;
408    } else if (tos_or_external_callback) {
409      // Find out, if top of stack was pointing inside a JS function
410      // meaning that we have encountered a frameless invocation.
411      const funcEntry = this._profile.findEntry(tos_or_external_callback);
412      if (!funcEntry?.isJSFunction?.()) {
413        tos_or_external_callback = 0;
414      }
415    }
416    const entryStack = this._profile.recordTick(
417        time_ns, vmState,
418        this.processStack(pc, tos_or_external_callback, stack));
419    const newEntry = new TickLogEntry(time_ns, vmState, entryStack);
420    this._tickTimeline.push(newEntry);
421    if (this._lastTickLogEntry !== undefined) {
422      this._lastTickLogEntry.end(time_ns);
423    }
424    this._lastTickLogEntry = newEntry;
425  }
426
427  processCodeSourceInfo(
428      start, scriptId, startPos, endPos, sourcePositions, inliningPositions,
429      inlinedFunctions) {
430    this._profile.addSourcePositions(
431        start, scriptId, startPos, endPos, sourcePositions, inliningPositions,
432        inlinedFunctions);
433    if (this._lastCodeLogEntry === undefined) return;
434    let profileEntry = this._profile.findEntry(start);
435    if (profileEntry !== this._lastCodeLogEntry._entry) return;
436    this.addSourcePosition(profileEntry, this._lastCodeLogEntry);
437    this._lastCodeLogEntry = undefined;
438  }
439
440  addSourcePosition(profileEntry, logEntry) {
441    let script = this.getProfileEntryScript(profileEntry);
442    const parts = profileEntry.getRawName().split(':');
443    if (parts.length < 3) return;
444    const line = parseInt(parts[parts.length - 2]);
445    const column = parseInt(parts[parts.length - 1]);
446    logEntry.sourcePosition = script.addSourcePosition(line, column, logEntry);
447  }
448
449  processCodeDisassemble(start, kind, disassemble) {
450    this._profile.addDisassemble(start, kind, disassemble);
451  }
452
453  processPropertyIC(
454      type, pc, time, line, column, old_state, new_state, mapId, key, modifier,
455      slow_reason) {
456    this._lastTimestamp = time;
457    const codeEntry = this._profile.findEntry(pc);
458    const fnName = this.formatProfileEntry(codeEntry);
459    const script = this.getProfileEntryScript(codeEntry);
460    const map = this.getOrCreateMapEntry(mapId, time);
461    // TODO: Use SourcePosition here directly
462    let entry = new IcLogEntry(
463        type, fnName, time, line, column, key, old_state, new_state, map,
464        slow_reason, modifier, codeEntry);
465    if (script) {
466      entry.sourcePosition = script.addSourcePosition(line, column, entry);
467    }
468    this._icTimeline.push(entry);
469  }
470
471  formatProfileEntry(profileEntry, line, column) {
472    if (!profileEntry) return '<unknown>';
473    if (profileEntry.type === 'Builtin') return profileEntry.name;
474    const name = profileEntry.func.getName();
475    const array = this._formatPCRegexp.exec(name);
476    const formatted =
477        (array === null) ? name : profileEntry.getState() + array[1];
478    if (line === undefined || column === undefined) return formatted;
479    return `${formatted}:${line}:${column}`;
480  }
481
482  getProfileEntryScript(profileEntry) {
483    if (!profileEntry) return undefined;
484    if (profileEntry.type === 'Builtin') return undefined;
485    const script = profileEntry.source?.script;
486    if (script !== undefined) return script;
487    let fileName;
488    if (profileEntry.type === 'SHARED_LIB') {
489      fileName = profileEntry.name;
490    } else {
491      // Slow path, try to get the script from the url:
492      const fnName = this.formatProfileEntry(profileEntry);
493      let parts = fnName.split(' ');
494      fileName = parts[parts.length - 1];
495    }
496    return this.getScript(fileName);
497  }
498
499  processMap(type, time, from, to, pc, line, column, reason, name) {
500    this._lastTimestamp = time;
501    const time_ = parseInt(time);
502    if (type === 'Deprecate') return this.deprecateMap(type, time_, from);
503    // Skip normalized maps that were cached so we don't introduce multiple
504    // edges with the same source and target map.
505    if (type === 'NormalizeCached') return;
506    const from_ = this.getOrCreateMapEntry(from, time_);
507    const to_ = this.getOrCreateMapEntry(to, time_);
508    if (type === 'Normalize') {
509      // Fix a bug where we log "Normalize" transitions for maps created from
510      // the NormalizedMapCache.
511      if (to_.parent?.id === from || to_.time < from_.time || to_.depth > 0) {
512        console.log(`Skipping transition to cached normalized map`);
513        return;
514      }
515    }
516    if (pc) {
517      const profCodeEntry = this._profile.findEntry(pc);
518      if (profCodeEntry) {
519        to_.entry = profCodeEntry;
520        profCodeEntry.logEntry.add(to_);
521        let script = this.getProfileEntryScript(profCodeEntry);
522        if (script) {
523          to_.sourcePosition = script.addSourcePosition(line, column, to_);
524        }
525      }
526    }
527    let edge = new Edge(type, name, reason, time, from_, to_);
528    if (to_.parent !== undefined && to_.parent === from_) {
529      // Fix bug where we double log transitions.
530      console.warn('Fixing up double transition');
531      to_.edge.updateFrom(edge);
532    } else {
533      edge.finishSetup();
534    }
535  }
536
537  deprecateMap(type, time, id) {
538    this._lastTimestamp = time;
539    this.getOrCreateMapEntry(id, time).deprecate();
540  }
541
542  processMapCreate(time, id) {
543    // map-create events might override existing maps if the addresses get
544    // recycled. Hence we do not check for existing maps.
545    this._lastTimestamp = time;
546    this.createMapEntry(id, time);
547  }
548
549  processMapDetails(time, id, string) {
550    // TODO(cbruni): fix initial map logging.
551    const map = this.getOrCreateMapEntry(id, time);
552    map.description = string;
553  }
554
555  createMapEntry(id, time) {
556    this._lastTimestamp = time;
557    const map = new MapLogEntry(id, time);
558    this._mapTimeline.push(map);
559    return map;
560  }
561
562  getOrCreateMapEntry(id, time) {
563    if (id === '0x000000000000') return undefined;
564    const map = MapLogEntry.get(id, time);
565    if (map !== undefined) return map;
566    console.warn(`No map details provided: id=${id}`);
567    // Manually patch in a map to continue running.
568    return this.createMapEntry(id, time);
569  }
570
571  getScript(url) {
572    const script = this._profile.getScript(url);
573    // TODO create placeholder script for empty urls.
574    if (script === undefined) {
575      console.error(`Could not find script for url: '${url}'`)
576    }
577    return script;
578  }
579
580  processApiEvent(type, varArgs) {
581    // legacy events that are no longer supported
582  }
583
584  processTimerEventStart(type, time) {
585    const entry = new TimerLogEntry(type, time);
586    this._timerTimeline.push(entry);
587  }
588
589  processTimerEventEnd(type, time) {
590    // Timer-events are infrequent, and not deeply nested, doing a linear walk
591    // is usually good enough.
592    for (let i = this._timerTimeline.length - 1; i >= 0; i--) {
593      const timer = this._timerTimeline.at(i);
594      if (timer.type == type && !timer.isInitialized) {
595        timer.end(time);
596        return;
597      }
598    }
599    console.error('Couldn\'t find matching timer event start', {type, time});
600  }
601
602  get icTimeline() {
603    return this._icTimeline;
604  }
605
606  get mapTimeline() {
607    return this._mapTimeline;
608  }
609
610  get deoptTimeline() {
611    return this._deoptTimeline;
612  }
613
614  get codeTimeline() {
615    return this._codeTimeline;
616  }
617
618  get tickTimeline() {
619    return this._tickTimeline;
620  }
621
622  get timerTimeline() {
623    return this._timerTimeline;
624  }
625
626  get scripts() {
627    return this._profile.scripts_.filter(script => script !== undefined);
628  }
629
630  get profile() {
631    return this._profile;
632  }
633}
634