Hang/blank window after reload window with running terminal processes

[egamma]

Testing #127195
On OS X Version 11.4

• open vscode folder
• open a terminal
• in the terminal execute the following script

sh
while true
do
date
sleep 1
done

• execute Reload window

The command hangs, you see a blank window and cannot open the developer tools (sry for the unhelpful screenshot)

Closing the blank window and opening the vscode folder in a new window reconnects to the running process.

Repro behaviour:

• I can reproduce this behaviour about every 2-10 times in the above setup with open vscode folder after waiting a couple of seconds.
• I was not able to reproduce the behaviour when I have a simple test folder containing a couple files open.
• I've failed to reproduce the reload hang when there is no open terminal.
• I've failed to reproduce the reload hang in a remote setup using Remote Containers.

@bpasero any suggestion for how to collect more diagnostic information when in this state?

[bpasero]

code-insiders --verbose --open-devtools

[egamma]

Can be reproduced with no active terminals.

[egamma]

Sample of Main Process.zip
Spindump Main Process.zip
Sample of Renderer.zip
Spindump of Renderer.zip

[bpasero]

My findings:

• this reproduces in stable too and I can reproduce running out of sources
• this is more likely to happen with a large workspace state DB (Erich's is >30 MB) and would explain why no user reported this so far
• this reproduces only on reload but I would think it might reproduce even on normal load as well
• the hang happens because we wait for a IPC message from the preload script to return from the main process [1] and this never returns
• the IPC channel exists on the main side and is implemented in [2] (it is the same channel that the window talks to when loading initially)

[1]

vscode/src/vs/base/parts/sandbox/electron-browser/preload.js

Line 74 in 89731c8

configuration = await ipcRenderer.invoke(windowConfigIpcChannel);

[2]

vscode/src/vs/platform/protocol/electron-main/protocolMainService.ts

Line 157 in 100a707

ipcMain.handle(channel, handler);

[deepak1556]

After looking at the mojom traces, the problem turned out to be quite simple. The message pipe used by ipcRenderer module are bound to the lifetime of a RenderFrame as the corresponding interfaces exposed from the browser process are tied to RenderFrameHost. When a renderer navigates to a new document, during the commit stage of navigation (it is when the client has received response from the server), the render process will reset the browser interface connection https://source.chromium.org/chromium/chromium/src/+/main:content/renderer/render_frame_impl.cc;l=3797-3812 so that old message pipe from previous document is not used to get the interfaces.

In normal cases, this above reset happens before preload script executes so there should be no issues. But in this bug, what happens is that on reload the sqlite connection reestablishment is delaying the navigation lifecycle causing the preload script to run before the navigation has committed. This now becomes a race condition where the ipc.invoke calls are dropped because the message pipe they were bound to was destroyed later by the navigation commit stage.

chrometrace.zip

Attaching chrometrace that will have two RenderFrameImpl::didCommitProvisionalLoad callstacks, the first one is in the renderer with pid 886 which does the initial document load. If you close up around 1540ms, you will see that the electron::mojom::ElectronBrowser::Invoke calls related to our vscode:<uuid> used for config retrieval will be after the commit stage has made a call to blink::mojom::BrowserInterfaceBroker::GetInterface.

The second one is in renderer with pid 912, this is the renderer used after the reload call has been issued (a new render process because we don't use process reuse yet). Again close up around 9242ms, you will see that the above electron ipc call will happen before the render commit stage resets the call to BrowserInterfaceBroker

[deepak1556]

As to why the sqlite connection messes with the navigation cycle even though it is async is yet to be investigated. FWIW we should ensure in Electron that preload script is loaded only after navigation commits so that the interface broker expectation set by chromium is respected.

[bpasero]

@deepak1556 Great findings. Since this seems to be so specific to window reload, should I proceed with pushing a change to not warm up the SQLite connection on reload?

[deepak1556]

Thinking about that, if you can delay the ipc calls in the preload till https://github.com/electron/electron/blob/main/docs/api/web-contents.md#event-did-frame-navigate then it is guaranteed that we are making the calls after the renderer has navigated. The above event is the main process equivalent of navigation commit.

[bpasero]

I am a little bit reluctant pushing a change like that so late in the endgame...

[deepak1556]

Oh yeah for the endgame, sqlite change sounds good.

[bpasero]

@deepak1556 please take a look at b67f4cc. This should cover the reload scenario at least. Arguably I think it could happen as well when changing workspaces on an existing window but since no user complained so far, I suggest we do the real fix in Electron in July if possible.

[bpasero]

I pushed another change to also skip the sqlite init when loading a window that was loaded before, leaving this case to only warm up sqlite on the very first opening of a window.

Deepak to investigate whether a fix in Electron:

• is low hanging
• does not have perf implications

Otherwise I suggest to close for now unless lots of others see this in their Electron use.

[deepak1556]

With Electron 13 update and reverting the above sqlite workarounds, I am no longer able to repro the issue. Preload script is executing only after the IPC broker connection is reset.

@bpasero I will leave this issue open incase you want to revert the sqlite workarounds otherwise feel free to close it. Thanks!

[isidorn]

Ben is on vacation, so moving this out to August so he can decide what to do in debt week. Nothing for endgame.

[bpasero]

I was not able to reproduce either after removing my workaround, thus going with it 👍