-
Notifications
You must be signed in to change notification settings - Fork 36.8k
chore: log js stacks from unresponsive window #241390
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
68c69af
d92b9ed
677b5ee
f63146b
be988c7
bd46144
3753076
ff1bc9b
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -4,7 +4,7 @@ | |
| *--------------------------------------------------------------------------------------------*/ | ||
|
|
||
| import electron, { BrowserWindowConstructorOptions } from 'electron'; | ||
| import { DeferredPromise, RunOnceScheduler, timeout } from '../../../base/common/async.js'; | ||
| import { DeferredPromise, RunOnceScheduler, timeout, Delayer } from '../../../base/common/async.js'; | ||
| import { CancellationToken } from '../../../base/common/cancellation.js'; | ||
| import { toErrorMessage } from '../../../base/common/errorMessage.js'; | ||
| import { Emitter, Event } from '../../../base/common/event.js'; | ||
|
|
@@ -44,6 +44,7 @@ import { IUserDataProfilesMainService } from '../../userDataProfile/electron-mai | |
| import { ILoggerMainService } from '../../log/electron-main/loggerService.js'; | ||
| import { IInstantiationService } from '../../instantiation/common/instantiation.js'; | ||
| import { VSBuffer } from '../../../base/common/buffer.js'; | ||
| import { errorHandler } from '../../../base/common/errors.js'; | ||
|
|
||
| export interface IWindowCreationOptions { | ||
| readonly state: IWindowState; | ||
|
|
@@ -540,6 +541,11 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| private pendingLoadConfig: INativeWindowConfiguration | undefined; | ||
| private wasLoaded = false; | ||
|
|
||
| private readonly jsCallStackMap: Map<string, number>; | ||
| private readonly jsCallStackEffectiveSampleCount: number; | ||
| private readonly jsCallStackCollector: Delayer<void>; | ||
| private readonly jsCallStackCollectorStopScheduler: RunOnceScheduler; | ||
|
|
||
| constructor( | ||
| config: IWindowCreationOptions, | ||
| @ILogService logService: ILogService, | ||
|
|
@@ -595,6 +601,25 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| } | ||
| //#endregion | ||
|
|
||
| //#region JS Callstack Collector | ||
|
|
||
| let sampleInterval = parseInt(this.environmentMainService.args['unresponsive-sample-interval'] || '1000'); | ||
| let samplePeriod = parseInt(this.environmentMainService.args['unresponsive-sample-period'] || '15000'); | ||
| if (sampleInterval <= 0 || samplePeriod <= 0 || sampleInterval > samplePeriod) { | ||
| this.logService.warn(`Invalid unresponsive sample interval (${sampleInterval}ms) or period (${samplePeriod}ms), using defaults.`); | ||
| sampleInterval = 1000; | ||
| samplePeriod = 15000; | ||
| } | ||
|
|
||
| this.jsCallStackMap = new Map<string, number>(); | ||
| this.jsCallStackEffectiveSampleCount = Math.round(sampleInterval / samplePeriod); | ||
| this.jsCallStackCollector = this._register(new Delayer<void>(sampleInterval)); | ||
| this.jsCallStackCollectorStopScheduler = this._register(new RunOnceScheduler(() => { | ||
| this.stopCollectingJScallStacks(); // Stop collecting after 15s max | ||
| }, samplePeriod)); | ||
|
|
||
| //#endregion | ||
|
|
||
| // respect configured menu bar visibility | ||
| this.onConfigurationUpdated(); | ||
|
|
||
|
|
@@ -655,6 +680,7 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
|
|
||
| // Window error conditions to handle | ||
| this._register(Event.fromNodeEventEmitter(this._win, 'unresponsive')(() => this.onWindowError(WindowError.UNRESPONSIVE))); | ||
| this._register(Event.fromNodeEventEmitter(this._win, 'responsive')(() => this.onWindowError(WindowError.RESPONSIVE))); | ||
| this._register(Event.fromNodeEventEmitter(this._win.webContents, 'render-process-gone', (event, details) => details)(details => this.onWindowError(WindowError.PROCESS_GONE, { ...details }))); | ||
| this._register(Event.fromNodeEventEmitter(this._win.webContents, 'did-fail-load', (event, exitCode, reason) => ({ exitCode, reason }))(({ exitCode, reason }) => this.onWindowError(WindowError.LOAD, { reason, exitCode }))); | ||
|
|
||
|
|
@@ -730,6 +756,7 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| } | ||
|
|
||
| private async onWindowError(error: WindowError.UNRESPONSIVE): Promise<void>; | ||
| private async onWindowError(error: WindowError.RESPONSIVE): Promise<void>; | ||
| private async onWindowError(error: WindowError.PROCESS_GONE, details: { reason: string; exitCode: number }): Promise<void>; | ||
| private async onWindowError(error: WindowError.LOAD, details: { reason: string; exitCode: number }): Promise<void>; | ||
| private async onWindowError(type: WindowError, details?: { reason?: string; exitCode?: number }): Promise<void> { | ||
|
|
@@ -741,6 +768,9 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| case WindowError.UNRESPONSIVE: | ||
| this.logService.error('CodeWindow: detected unresponsive'); | ||
| break; | ||
| case WindowError.RESPONSIVE: | ||
| this.logService.error('CodeWindow: recovered from unresponsive'); | ||
| break; | ||
| case WindowError.LOAD: | ||
| this.logService.error(`CodeWindow: failed to load (reason: ${details?.reason || '<unknown>'}, code: ${details?.exitCode || '<unknown>'})`); | ||
| break; | ||
|
|
@@ -799,6 +829,14 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| return; | ||
| } | ||
|
|
||
| // Interrupt V8 and collect JavaScript stack | ||
| this.jsCallStackCollector.trigger(() => this.startCollectingJScallStacks()); | ||
| // Stack collection will stop under any of the following conditions: | ||
| // - The window becomes responsive again | ||
| // - The window is destroyed i-e reopen or closed | ||
| // - sampling period is complete, default is 15s | ||
| this.jsCallStackCollectorStopScheduler.schedule(); | ||
|
|
||
| // Show Dialog | ||
| const { response, checkboxChecked } = await this.dialogMainService.showMessageBox({ | ||
| type: 'warning', | ||
|
|
@@ -815,6 +853,7 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| // Handle choice | ||
| if (response !== 2 /* keep waiting */) { | ||
| const reopen = response === 0; | ||
| this.stopCollectingJScallStacks(); | ||
| await this.destroyWindow(reopen, checkboxChecked); | ||
| } | ||
| } | ||
|
|
@@ -847,6 +886,9 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| await this.destroyWindow(reopen, checkboxChecked); | ||
| } | ||
| break; | ||
| case WindowError.RESPONSIVE: | ||
| this.stopCollectingJScallStacks(); | ||
| break; | ||
| } | ||
| } | ||
|
|
||
|
|
@@ -1449,6 +1491,50 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| return segments; | ||
| } | ||
|
|
||
| private async startCollectingJScallStacks(): Promise<void> { | ||
| if (!this.jsCallStackCollector.isTriggered()) { | ||
| const stack = await this._win.webContents.mainFrame.collectJavaScriptCallStack(); | ||
|
|
||
| // Increment the count for this stack trace | ||
| if (stack) { | ||
| const count = this.jsCallStackMap.get(stack) || 0; | ||
| this.jsCallStackMap.set(stack, count + 1); | ||
| } | ||
|
|
||
| this.jsCallStackCollector.trigger(() => this.startCollectingJScallStacks()); | ||
| } | ||
| } | ||
|
|
||
| private stopCollectingJScallStacks(): void { | ||
| this.jsCallStackCollectorStopScheduler.cancel(); | ||
| this.jsCallStackCollector.cancel(); | ||
|
|
||
| if (this.jsCallStackMap.size) { | ||
| let logMessage = `CodeWindow unresponsive samples:\n`; | ||
| let samples = 0; | ||
|
|
||
| const sortedEntries = Array.from(this.jsCallStackMap.entries()) | ||
| .sort((a, b) => b[1] - a[1]); | ||
|
|
||
| for (const [stack, count] of sortedEntries) { | ||
| samples += count; | ||
| // If the stack appears more than 20 percent of the time, log it | ||
| // to the error telemetry as UnresponsiveSampleError. | ||
| if (Math.round((count * 100) / this.jsCallStackEffectiveSampleCount) > 20) { | ||
|
Collaborator
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Taken inspiration from renderer auto profiler but unlike the auto profiler we don't have individual frame timings, given the samples are sorted by their effective appearance over the sample period, I feel this should cover the interesting bits to error telemetry as Adding the window id and process id to the error message so that we can aggregate them. Let me know if there are better markers to add. |
||
| const fakeError = new UnresponsiveError(stack, this.id, this.win?.webContents.getOSProcessId()); | ||
| errorHandler.onUnexpectedError(fakeError); | ||
| } | ||
| logMessage += `<${count}> ${stack}\n`; | ||
| } | ||
|
|
||
| logMessage += `Total Samples: ${samples}\n`; | ||
| logMessage += 'For full overview of the unresponsive period, capture cpu profile via https://aka.ms/vscode-tracing-cpu-profile'; | ||
| this.logService.error(logMessage); | ||
| } | ||
|
|
||
| this.jsCallStackMap.clear(); | ||
| } | ||
|
|
||
| matches(webContents: electron.WebContents): boolean { | ||
| return this._win?.webContents.id === webContents.id; | ||
| } | ||
|
|
@@ -1460,3 +1546,12 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |
| this.loggerMainService.deregisterLoggers(this.id); | ||
| } | ||
| } | ||
|
|
||
| class UnresponsiveError extends Error { | ||
|
|
||
| constructor(sample: string, windowId: number, pid: number = 0) { | ||
| super(`UnresponsiveSampleError: by ${windowId} from ${pid}`); | ||
| this.name = 'UnresponsiveSampleError'; | ||
| this.stack = sample; | ||
| } | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Won't this be zero, and then cause div-by-zero below?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@deepak1556 can you check?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oops, good catch. It should have been the other way.