Extension: During deactivate, globalState.update promises are immediately canceled

[bmcbarron]

Issue Type: Bug

Minimal repro here, which consists of the default yo code-created extension with the changes summarized below:

let globalState: vscode.Memento;

export function activate(context: vscode.ExtensionContext) {
  // ...
  globalState = context.globalState;
  console.log(`Pre-existing keys: [${globalState.keys().join(', ')}]`);
  globalState.update('test', 'repro');
}

export async function deactivate() {
  try {
    await globalState.update('test', undefined);
    console.log('globalState.update succeeded');
  } catch (err) {
    console.log(`globalState.update failed with ${err}`);
  }
}

Repro Steps

1. Debug an extension (or install and run natively).
2. Activate extension (in this case with Ctrl-Shift-P "Hello World")
3. Close VS Code
4. In extension deactive, delete a key from context.globalState, and return the resulting promise.

Expected: As long as the promise finishes within 5 seconds, the operation will complete.

Actual: The promise is canceled. In the repro shown here, the message globalState.update failed with Canceled: Canceled is emitted. The next time the extension is run, the extension prints Pre-existing keys: [test], verifying that the key was not removed.

VS Code version: Code 1.64.2 (f80445a, 2022-02-09T22:02:28.252Z)
OS version: Windows_NT x64 10.0.19044
Restricted Mode: No

System Info

Item	Value
CPUs	Intel(R) Core(TM) i7-8700K CPU @ 3.70GHz (12 x 3696)
GPU Status	2d_canvas: enabled gpu_compositing: enabled multiple_raster_threads: enabled_on oop_rasterization: enabled opengl: enabled_on rasterization: enabled skia_renderer: enabled_on video_decode: enabled vulkan: disabled_off webgl: enabled webgl2: enabled
Load (avg)	undefined
Memory (System)	15.94GB (2.63GB free)
Process Argv	--crash-reporter-id 1871b94c-c67d-43d1-b37d-bdf3332353ad
Screen Reader	no
VM	0%

Extensions (35)

Extension	Author (truncated)	Version
tsl-problem-matcher	amo	0.5.0
chronicler	arc	0.1.16
doxdocgen	csc	1.4.0
mustache	daw	1.1.1
vscode-eslint	dba	2.2.2
xml	Dot	2.5.1
vscode-npm-script	eg2	0.3.24
prettier-vscode	esb	9.3.0
godot-javascript-debug	gee	0.1.5
godot-tools	gee	1.1.3
better-cpp-syntax	jef	1.15.13
volar	joh	0.32.0
hjson	lak	0.3.2
template-string-converter	meg	0.6.0
python	ms-	2022.0.1814523869
vscode-pylance	ms-	2022.2.4
jupyter-renderers	ms-	1.0.6
remote-containers	ms-	0.217.4
remote-ssh	ms-	0.74.0
remote-ssh-edit	ms-	0.74.0
remote-wsl	ms-	0.64.2
vscode-remote-extensionpack	ms-	0.21.0
cmake-tools	ms-	1.9.2
cpptools	ms-	1.8.4
cpptools-extension-pack	ms-	1.1.0
live-server	ms-	0.2.12
powershell	ms-	2021.12.0
vscode-gn	npc	1.1.0
vscode-versionlens	pfl	1.0.9
svg-preview	Sim	2.8.3
shader	sle	1.1.5
es6-string-html	Tob	2.12.0
cmake	twx	0.0.17
sort-lines	Tyr	1.9.1
wallaby-vscode	Wal	1.0.327

(2 theme extensions excluded)

A/B Experiments

vsliv368:30146709
vsreu685:30147344
python383cf:30185419
vspor879:30202332
vspor708:30202333
vspor363:30204092
pythonvspyl392:30443607
pythontb:30283811
pythonptprofiler:30281270
vshan820:30294714
vstes263:30335439
vscorecescf:30442554
pythondataviewer:30285071
vscod805cf:30301675
pythonvspyt200:30340761
binariesv615:30325510
bridge0708:30335490
bridge0723:30353136
vsaa593:30376534
vsc1dst:30438360
pythonvs932:30410667
wslgetstarted:30433507
vsclayoutctrt:30437039
vsrem710cf:30416617
vscop841cf:30438916
dsvsc008:30440022
pythonvsnew555:30442236
vsbas813:30436447
vscscmwlcmt:30438805
vscgsvidc:30438801
helix:30440343
vsnot107:30443614

[gjsjohnmurray]

Documentation at https://code.visualstudio.com/api/references/activation-events#Start-up may be relevant:

Extension must return a Promise from deactivate() if the cleanup process is asynchronous. An extension may return undefined from deactivate() if the cleanup runs synchronously.

[bmcbarron]

Thanks, @gjsjohnmurray , for the documentation link. However, I don't believe that is the issue here. The deactivate function in the OP repro returns a Promise by virtual of being an async function. (FWIW, I also saw this behavior when returning an explicit Promise, prior to converting this to async. They are equivalent.)

[gjsjohnmurray]

Maybe some clues in #122825 (comment)

[bmcbarron]

Yep, that does look relevant. It would be unfortunate if the entire vscode API was non-functional during deactivate. In particular, updates to persistent state seem particularly apropos for the "cleanup phase."

Maybe there are two action items here:

1. Document (at least in a broad sense) that some APIs are unavailable during deactivate. Even nicer would be to change the description of the Canceled error to offer more clarity than just "Canceled".
2. Decide which (if any) of the APIs should work, and verify/fix their current state.

As a workaround, folks can avoid using globalState, and instead store the same json in a file at globalStorageUri. I haven't checked to see if the vscode.fs.* apis work during deactivate, or if raw node APIs would need to be used, instead.

Related but probably a separate thread from all of this: I first started to implement cleanup tasks by returning Disposables from activate. Although dispose() is called at the same time as deactivate, Promises returned by dispose are not executed. That may be by design, but it is a little inconsistent. The dispose idiom also feels cleaner than passing state to deactivate via globals.

I could help contribute some of these changes, although I could use some high level pointers on what and where.

[gjsjohnmurray]

Related but probably a separate thread from all of this: I first started to implement cleanup tasks by returning Disposables from activate. Although dispose() is called at the same time as deactivate, Promises returned by dispose are not executed. That may be by design, but it is a little inconsistent. The dispose idiom also feels cleaner than passing state to deactivate via globals.

See #140697 (comment) and following.

[bpasero]

@alexdima should it be possible to run long running operations in the deactivate method that potentially needs to travel to the renderer process and then maybe also main process (that is the case for storage)?

[alexdima]

@bpasero We currently don't keep the renderer process running longer to wait for the extension host to shut down. The comment at #122825 (comment) is still accurate. We can, however, decide to revisit this past decision. But this would change how reloading works, how opening a folder works, etc. If we decide to keep the renderer up and running to service API calls, this might result in constant 5-6s delays to all these operations.

I agree that Canceled is a too generic error to get when using the vscode API in the deactivate() method. The error comes from a very low level layer, which implements the rpc protocol and a Canceled error is one of the only types of errors that we have standardized in our code-base. Throwing a different error is a straight-forward change, but it might result in a lot of unintended side-effects, like error telemetry, or it might spam the logs. @jrieken What do you think? Would it be feasible to logically "invalidate" the vscode API during deactivate() and have a more case-by-case approach with good errors when the extension host goes down, or should we just bite the bullet and change the low level error to "Shutting down" or something like that?

Regarding dispose() not being awaited, this came up before, so we have documented this in most places where the extension can pass in a dispose() method. e.g.

vscode/src/vscode-dts/vscode.d.ts

Line 1491 in 98c97ab

* dispose-functions aren't awaited.

,

vscode/src/vscode-dts/vscode.d.ts

Line 6573 in 98c97ab

* *Note* that asynchronous dispose-functions aren't awaited.

, but maybe we missed some spots?

[jrieken]

@jrieken What do you think? Would it be feasible to logically "invalidate" the vscode API during deactivate() and have a more case-by-case approach with good errors when the extension host goes down, or should we just bite the bullet and change the low level error to "Shutting down" or something like that?

I think invalidating the API and special errors in selected places makes sense to me. Failing to update/persist state during shutdown is an evergreen and a better error would certain improve things.

[bmcbarron]

Invalidation/special errors sounds great! Let me know if you're interested in help here.

@alexdima I'm embarrassed that I missed the existing documentation about the non-async behavior of dispose(). Ironically, the two places I did look are the two locations that don't mention it:

• The class comment for Disposable.
• The method comment for dispose().

If you're inclined, I think dispose() is a reasonable place to have a comment, especially since it returns any even though all return values are ignored. In hindsight, making this a void method would have eliminated this class of issue, but that ship has obviously sailed.

Separately: I wouldn't ask for a revisit on delaying the renderer shutdown. I love the responsiveness there. What I should have asked in my earlier post is: Is the storage API's implementation inherently dependent on the renderer process, or is it just that the extension driving the API is hosted in that process? If it's the latter, what about these ideas:

1. Allow the extension to spawn a process that can (at least temporarily) survive renderer shutdown and still have access to some of the relevant non-renderer APIs.
2. Forward relevant API requests queued in deactivate() to the main process, even if the renderer won't stick around for the response. Yes, that means an extension would have to deal with the data being written or not written, but that's always true for crashes. In the typical case of a well-ordered shutdown, I could still get my final writes done. Such APIs could fail in the renderer with something like "Command issued, but response not awaited."

[gjsjohnmurray]

@andreamah this issue may be relevant to #128138 which you commented on and reopened today. I couldn't add this comment there because when reopening it you forgot to unlock it.

[andreamah]

@andreamah this issue may be relevant to #128138 which you commented on and reopened today. I couldn't add this comment there because when reopening it you forgot to unlock it.

oh, nice catch! thanks for letting me know!

[boltex]

@alexdima @jrieken During deactivate, vscode.workspace.fs.writeFile gives me a 'canceled' exception and refuses to write to file. Is it normal that the vscode API is not available during 'deactivate' even if I return a promise that waits for my file-write operation to resolve?

[alexdima]

Yes, all vscode async API should be avoided during deactivate. Most async API is serviced by the renderer process, which might have already disappeared. For critical things, like making storing critical data, we suggest a pattern of auto-saving after a delay, and doing OS resource cleanup during deactivate (killing spawned processes, shutting down spawned VMs, etc.).

[vscodenpa]

The described behavior is how it is expected to work. If you disagree, please explain what is expected and what is not in more detail. See also our issue reporting guidelines.

Happy Coding!

[boltex]

@alexdima Thank you very much. Although I humbly suggest that this critical information be added to the official documentation about an extension disactivate function.

(Because a vast majority of cleanup tasks intended by extension developers might be async procedures!)

[alexdima]

@boltex Would you please create a PR against https://github.com/microsoft/vscode-docs which backs our website?