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 (f80445acd5a3dadef24aa209168452a3d97cc326, 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 https://github.com/microsoft/vscode/issues/122825#issuecomment-814218149

[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 https://github.com/microsoft/vscode/issues/140697#issuecomment-1017559485 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 https://github.com/microsoft/vscode/issues/122825#issuecomment-814218149 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. https://github.com/microsoft/vscode/blob/98c97abb8a33a34a3b82434c91ef93fe5ac819fc/src/vscode-dts/vscode.d.ts#L1491 , https://github.com/microsoft/vscode/blob/98c97abb8a33a34a3b82434c91ef93fe5ac819fc/src/vscode-dts/vscode.d.ts#L6573 , 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."

[vscodenpa]

This feature request has not yet received the 20 community upvotes it takes to make to our backlog. 10 days to go. To learn more about how we handle feature requests, please see our documentation.

Happy Coding!

[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?