chore: log js stacks from unresponsive window #241390
Conversation
| // Document-policy header is needed for collecting | ||
| // JavaScript callstacks via https://www.electronjs.org/docs/latest/api/web-frame-main#framecollectjavascriptcallstack-experimental | ||
| // until https://github.com/electron/electron/issues/45356 is resolved. | ||
| if (extname(path).toLowerCase() === '.html') { |
There was a problem hiding this comment.
Should this be using the same code as above for COI.CoopAndCope?
| @@ -540,6 +540,8 @@ export class CodeWindow extends BaseWindow implements ICodeWindow { | |||
| private pendingLoadConfig: INativeWindowConfiguration | undefined; | |||
| private wasLoaded = false; | |||
|
|
|||
| private JScallStackCollector: NodeJS.Timeout | undefined; | |||
There was a problem hiding this comment.
💄 : Class members first letter are lowercase unless maybe its a static constant.
| if (this.JScallStackCollector) { | ||
| return; | ||
| } | ||
| this.JScallStackCollector = setInterval(async () => { |
There was a problem hiding this comment.
We have a RunOnceScheduler utility for this that is a bit easier to work with.
| this.JScallStackCollector = setInterval(async () => { | ||
| const stack = await this._win.webContents.mainFrame.collectJavaScriptCallStack(); | ||
| this.logService.error('CodeWindow unresponsive : ', stack); | ||
| }, 1000); |
There was a problem hiding this comment.
Should this stop at one point printing? What if the user leaves this running? Maybe the interval is also quite short and do we know that the stack would be any different after collecting it once?
There was a problem hiding this comment.
So we stop printing in 2 cases currently,
- Once the user has responded to the dialog with close or reopen
- If window becomes responsive again, that is signaled by the
responsiveevent from the runtime.
I am thinking of the following scenarios of unresponsive windows,
- A long running JS task that will eventually recover, the unresponsive event can happen in this case if the main thread is blocked for more than the period that the main process thinks is ideal to respond to user inputs.
- An infinite loop that will never recover, it could be async stack that re-enters from a different stack.
The call stack api basically interrupts V8 at a point in time and collects the current executing stack, since it is a single sample it would be hard to reason either of those cases. Hence I am thinking of collecting samples at an interval till the stop printing cases kick in. The interval I chose was just the defaults for most sampling profilers. But what I don't is aggregate the stacks so it would indeed make the console noisy.
Should we remember the last printed stack and simply ignore it when it always repeats?
Instead of ignoring, what if we aggregate a count for each repetitive stacks and only display the result at the end of the stack collection period. Something like
[main 2025-02-20T20:07:19.499Z] CodeWindow: detected unresponsive
[main 2025-02-20T20:07:20.366Z] CodeWindow unresponsive sample <N> times:
<M> at NativeAuxiliaryWindowService.createContainer (vscode-file://vscode-app/Users/demohan/github/vscode/out/vs/workbench/services/auxiliaryWindow/electron-sandbox/auxiliaryWindowService.js:118:9)
<M> at NativeAuxiliaryWindowService.open (vscode-file://vscode-app/Users/demohan/github/vscode/out/vs/workbench/services/auxiliaryWindow/browser/auxiliaryWindowService.js:181:50)
where N = Unresponsive time end - Unresponsive time start / Sample interval
where M = Number of times the stack appeared in the N period
There was a problem hiding this comment.
I would just stop after 10 iterations or so, reducing the risk of filling the log forever.
There was a problem hiding this comment.
Can you clarify the situation where the unresponsive interval will never end ? My understanding is that we always prompt a dialog and user has to choose an action to close or reopen at some point. Also my new suggestion is to print the log only once at the end of the unresponsive session.
There was a problem hiding this comment.
Instead of ignoring, what if we aggregate a count for each repetitive stacks and only display the result at the end of the stack collection period.
+1 on that. I would not print as you capture but aggregate (by count and maybe timestamp) so that you can print a summary. Either when responsive again, confirmed, or after a long'ish freeze time (in case never recovers). With that don't flood the log and have trace-like information
| } | ||
| this.JScallStackCollector = setInterval(async () => { | ||
| const stack = await this._win.webContents.mainFrame.collectJavaScriptCallStack(); | ||
| this.logService.error('CodeWindow unresponsive : ', stack); |
There was a problem hiding this comment.
Should we remember the last printed stack and simply ignore it when it always repeats?
|
also let's remove |
First pass for #240178
Logs look as follows in a simulated unresponsiveness,