Python Extension API incorrectly triggers 'remove' event #20292

DonJayamanne · 2022-11-30T01:58:32Z

On CI we're using a Python global Python env,
In the middle of the tests, the Python extension API triggers and event indicating the python environment has been deleted
and this then causes a few other issues in Jupyter extension

Note: We do not delete the global python env hence I do not expect to receive such and event.
If we're using the event incorrectly please do let us know.

Here are the interesting logs

Jupyter Logs

2022-11-30T00:05:36.8558283Z verbose 00:05:36.535:  Interpreter removed /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
2022-11-30T00:05:36.8560009Z verbose 00:05:36.535:  Interpreter /opt/hostedtoolcache/Python/3.10.8/x64/bin/python deleted, hence deleting corresponding kernel startUsingPythonInterpreter:'.jvsc74a57bd079f32d02658bf12f8569a265222c57f47d77ad75a8d38a3c9f42a05c99ab6a7e./opt/hostedtoolcache/Python/3.10.8/x64/python./opt/hostedtoolcache/Python/3.10.8/x64/python.-m#ipykernel_launcher
2022-11-30T00:05:36.8562018Z verbose 00:05:36.535:  Local Python connection deleted startUsingPythonInterpreter:'.jvsc74a57bd079f32d02658bf12f8569a265222c57f47d77ad75a8d38a3c9f42a05c99ab6a7e./opt/hostedtoolcache/Python/3.10.8/x64/python./opt/hostedtoolcache/Python/3.10.8/x64/python.-m#ipykernel_launcher: (interpreter id=/opt/hostedtoolcache/Python/3.10.8/x64/bin/python)'
2022-11-30T00:05:36.8568304Z verbose 00:05:36.536:  Updating cache with Local kernels startUsingLocalKernelSpec:'..net-csharp./dotnet./.dotnet#interactive#jupyter#--default-kernel#csharp#{connection_file}#--http-port-range#2048-3000 (interpreter id = undefined)', startUsingLocalKernelSpec:'..net-fsharp./dotnet./.dotnet#interactive#jupyter#--default-kernel#fsharp#{connection_file}#--http-port-range#2048-3000 (interpreter id = undefined)', startUsingLocalKernelSpec:'..net-powershell./dotnet./.dotnet#interactive#jupyter#--default-kernel#powershell#{connection_file}#--http-port-range#2048-3000 (interpreter id = undefined)', startUsingLocalKernelSpec:'.julia-1.5./opt/hostedtoolcache/julia/1.5.2/x64/bin/julia././opt/hostedtoolcache/julia/1.5.2/x64/bin/julia#-i#--color=yes#--project=@.#/home/runner/.julia/packages/ijulia/aqu2h/src/kernel.jl#{connection_file} (interpreter id = undefined)', startUsingLocalKernelSpec:'..venvkernel./home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/python./home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/python.-m#ipykernel_launcher (interpreter id = /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/bin/python)', startUsingLocalKernelSpec:'..venvnokernel./home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/python./home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/python.-m#ipykernel_launcher (interpreter id = /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/bin/python)'

& here are the logs from Python extension at the same time

[INFO 2022-10-30 0:5:35.965]: Found interpreter for >> /opt/hostedtoolcache/Python/3.10.8/x64/python /tmp/vscode_jupyter_exts/ms-python.python-2022.19.13321005/pythonFiles/get_output_via_markers.py /tmp/vscode_jupyter_exts/ms-python.python-2022.19.13321005/pythonFiles/interpreterInfo.py <<: {"versionInfo":[3,10,8,"final",0],"sysPrefix":"/opt/hostedtoolcache/Python/3.10.8/x64/.","sysVersion":"3.10.8 (main, Oct 18 2022, 06:43:21) [GCC 9.4.0]","is64Bit":true}
[DEBUG 2022-10-30 0:5:35.968]: No cached env found for /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
[INFO 2022-10-30 0:5:35.970]: Environments added to cache [{"name":"base","location":"/usr/share/miniconda","kind":"virt-conda","executable":{"filename":"/usr/share/miniconda/bin/python","sysPrefix":"/usr/share/miniconda","ctime":1668862752754,"mtime":1668862752754},"display":"Python 3.9.12 ('base')","version":{"major":3,"minor":9,"micro":12,"release":{"level":"final","serial":0},"sysVersion":"3.9.12 (main, Apr  5 2022, 06:56:58) \n[GCC 7.5.0]"},"arch":3,"distro":{"org":"Anaconda, Inc."},"source":[],"type":"Conda","id":"/usr/share/miniconda/bin/python","detailedDisplayName":"Python 3.9.12 ('base': conda)"},{"name":".venvkernel","location":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel","kind":"virt-venv","executable":{"filename":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/bin/python","sysPrefix":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel","ctime":1669766644084,"mtime":1669766644084},"searchLocation":{"$mid":1,"fsPath":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel","path":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel","scheme":"file"},"display":"Python 3.10.8 ('.venvkernel': venv)","version":{"major":3,"minor":10,"micro":8,"release":{"level":"final","serial":0},"sysVersion":"3.10.8 (main, Oct 18 2022, 06:43:21) [GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":[],"type":"Virtual","id":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/bin/python","detailedDisplayName":"Python 3.10.8 ('.venvkernel': venv)"},{"name":".venvnokernel","location":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel","kind":"virt-venv","executable":{"filename":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/bin/python","sysPrefix":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel","ctime":1669766672094,"mtime":1669766672094},"searchLocation":{"$mid":1,"fsPath":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel","path":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel","scheme":"file"},"display":"Python 3.10.8 ('.venvnokernel': venv)","version":{"major":3,"minor":10,"micro":8,"release":{"level":"final","serial":0},"sysVersion":"3.10.8 (main, Oct 18 2022, 06:43:21) [GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":[],"type":"Virtual","id":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/bin/python","detailedDisplayName":"Python 3.10.8 ('.venvnokernel': venv)"},{"name":".venvnoreg","location":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg","kind":"virt-venv","executable":{"filename":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg/bin/python","sysPrefix":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg","ctime":1669766640228,"mtime":1669766640228},"searchLocation":{"$mid":1,"fsPath":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg","path":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg","scheme":"file"},"display":"Python 3.10.8 ('.venvnoreg': venv)","version":{"major":3,"minor":10,"micro":8,"release":{"level":"final","serial":0},"sysVersion":"3.10.8 (main, Oct 18 2022, 06:43:21) [GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":[],"type":"Virtual","id":"/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg/bin/python","detailedDisplayName":"Python 3.10.8 ('.venvnoreg': venv)"},{"name":"","location":"","kind":"global-other","executable":{"filename":"/bin/python","sysPrefix":"/usr","ctime":1668861006324,"mtime":1586947544000},"display":"Python 3.8.10 64-bit","version":{"major":3,"minor":8,"micro":10,"release":{"level":"final","serial":0},"sysVersion":"3.8.10 (default, Jun 22 2022, 20:18:18) \n[GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":["path env var"],"id":"/bin/python","detailedDisplayName":"Python 3.8.10 64-bit"},{"name":"","location":"","kind":"global-other","executable":{"filename":"/bin/python2","sysPrefix":"/usr","ctime":1668860991299,"mtime":1584102683000},"display":"Python 2.7.18 64-bit","version":{"major":2,"minor":7,"micro":18,"release":{"level":"final","serial":0},"sysVersion":"2.7.18 (default, Jul  1 2022, 12:27:04) \n[GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":["path env var"],"id":"/bin/python2","detailedDisplayName":"Python 2.7.18 64-bit"},{"name":"","location":"","kind":"global-other","executable":{"filename":"/usr/bin/python","sysPrefix":"/usr","ctime":1668861006324,"mtime":1586947544000},"display":"Python 3.8.10 64-bit","version":{"major":3,"minor":8,"micro":10,"release":{"level":"final","serial":0},"sysVersion":"3.8.10 (default, Jun 22 2022, 20:18:18) \n[GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":["path env var"],"id":"/usr/bin/python","detailedDisplayName":"Python 3.8.10 64-bit"},{"name":"","location":"","kind":"global-other","executable":{"filename":"/opt/hostedtoolcache/Python/3.10.8/x64/python","sysPrefix":"/opt/hostedtoolcache/Python/3.10.8/x64/.","ctime":1669766020363,"mtime":1668865149931},"display":"Python 3.10.8 64-bit","version":{"major":3,"minor":10,"micro":8,"release":{"level":"final","serial":0},"sysVersion":"3.10.8 (main, Oct 18 2022, 06:43:21) [GCC 9.4.0]"},"arch":3,"distro":{"org":""},"source":["path env var"],"id":"/opt/hostedtoolcache/Python/3.10.8/x64/python","detailedDisplayName":"Python 3.10.8 64-bit"}]
[INFO 2022-10-30 0:5:35.971]: [
  'Display locator refreshing progress, Class name = f, completed in 0ms, has a falsy return value, , Return Value: undefined'
]
[INFO 2022-10-30 0:5:35.973]: [
  'Hide locator refreshing progress, Class name = f, completed in 0ms, has a falsy return value, , Return Value: undefined'
]
[DEBUG 2022-10-30 0:5:35.975]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="workspace"-Arg-Separator-"autoSelectedWorkspacePythonInterpreter-/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:35.976]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="global"-Arg-Separator-"WORKSPACE_FOLDER_INTERPRETER_PATH_/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:35.976]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="global"-Arg-Separator-"WORKSPACE_FOLDER_INTERPRETER_PATH_/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:35.978]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="global"-Arg-Separator-"WORKSPACE_FOLDER_INTERPRETER_PATH_/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:35.978]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="global"-Arg-Separator-"WORKSPACE_FOLDER_INTERPRETER_PATH_/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:35.996]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="global"-Arg-Separator-"WORKSPACE_FOLDER_INTERPRETER_PATH_/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:35.996]: Cached data exists KeyPrefix=Cache_Method_Output_m.addKeyToStorage-Args="global"-Arg-Separator-"WORKSPACE_FOLDER_INTERPRETER_PATH_/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience"-Arg-Separator-undefined
[DEBUG 2022-10-30 0:5:36.7]: Searching for conda environments using conda
[DEBUG 2022-10-30 0:5:36.7]: Cached data exists KeyPrefix=Cache_Method_Output_y.getEnvList-Args=
[DEBUG 2022-10-30 0:5:36.18]: Looking into conda env for executable: {"prefix":"/usr/share/miniconda","name":"base"}
[DEBUG 2022-10-30 0:5:36.34]: Searching for workspace virtual envs in: /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience
[DEBUG 2022-10-30 0:5:36.35]: Found executable within conda env {"prefix":"/usr/share/miniconda","name":"base"}
[DEBUG 2022-10-30 0:5:36.35]: Found conda executable: /usr/share/miniconda/bin/python
[DEBUG 2022-10-30 0:5:36.59]: Workspace Virtual Environment: [added] /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/bin/python
[DEBUG 2022-10-30 0:5:36.59]: Workspace Virtual Environment: [skipped] /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/bin/python3
[DEBUG 2022-10-30 0:5:36.59]: Workspace Virtual Environment: [skipped] /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvkernel/bin/python3.10
[DEBUG 2022-10-30 0:5:36.59]: No cached env found for /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
[DEBUG 2022-10-30 0:5:36.59]: No cached env found for /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
[DEBUG 2022-10-30 0:5:36.59]: No cached env found for /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
[DEBUG 2022-10-30 0:5:36.59]: No cached env found for /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
[DEBUG 2022-10-30 0:5:36.59]: No cached env found for /opt/hostedtoolcache/Python/3.10.8/x64/bin/python
[INFO 2022-10-30 0:5:36.60]: Found: /bin/python --> /bin/python3.8
[INFO 2022-10-30 0:5:36.60]: Found: /bin/python2 --> /bin/python2.7
[INFO 2022-10-30 0:5:36.61]: Found: /bin/python2.7 --> /bin/python2.7
[INFO 2022-10-30 0:5:36.71]: Found: /bin/python3 --> /bin/python3.8
[DEBUG 2022-10-30 0:5:36.71]: Workspace Virtual Environment: [added] /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/bin/python
[DEBUG 2022-10-30 0:5:36.71]: Workspace Virtual Environment: [skipped] /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/bin/python3
[DEBUG 2022-10-30 0:5:36.71]: Workspace Virtual Environment: [skipped] /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnokernel/bin/python3.10
[INFO 2022-10-30 0:5:36.76]: Found: /bin/python3.8 --> /bin/python3.8

The text was updated successfully, but these errors were encountered:

DonJayamanne · 2022-11-30T02:08:55Z

Job https://github.com/microsoft/vscode-jupyter/actions/runs/3579027060
VS Code logs (with Pythono output) https://github.com/microsoft/vscode-jupyter/suites/9575009837/artifacts/456041143
Jupyter logs can be found here https://github.com/microsoft/vscode-jupyter/actions/runs/3579027060/jobs/6019778068

I'm uploading the two logs here separately

Python Python.log.zip
Jupyter jupyterlogs.txt.zip

DonJayamanne · 2022-12-07T20:52:44Z

Running into this very often,
we get an event for remoted and immediate after an event for added
Sometimes it takes longer to get the added

2022-12-07T20:24:35.0606788Z verbose 20:24:35.059:  Python API env change detected, add => 'C:\HOSTEDTOOLCACHE\WINDOWS\PYTHON\3.9.13\X64\PYTHON.EXE}'
2022-12-07T20:24:35.0618910Z verbose 20:24:35.060:  Python API env change detected, remove => 'C:\HOSTEDTOOLCACHE\WINDOWS\PYTHON\3.9.13\X64\PYTHON.EXE}'

DonJayamanne · 2022-12-21T19:08:24Z

Still running into this on CI

2022-12-21T18:36:48.9794627Z verbose 18:36:48.529:  Python API env change detected, update => '/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience/.venvnoreg/bin/python}'
2022-12-21T18:36:49.0029418Z verbose 18:36:48.534:  Rank Kernels, Class name = KernelRankingHelper, completed in 23ms, has a truthy return value, Arg 1: "Untitled-1.ipynb", Arg 2: "", Arg 3: {"orig_nbformat":4,"language_info":{"name":"python"}}, Arg 4: <Uri:/opt/hostedtoolcache/Python/3.10.9/x64/bin/python>, Arg 5: "", Arg 6: undefined
2022-12-21T18:36:49.0128460Z verbose 18:36:48.567:  Python API env change detected, update => '/bin/python}'
2022-12-21T18:36:49.0238166Z verbose 18:36:48.583:  Python API env change detected, add => '/usr/bin/python}'
2022-12-21T18:36:49.0245214Z verbose 18:36:48.621:  No controller, hence notebook communications cannot be initialized for editor Untitled-1.ipynb
2022-12-21T18:36:49.0507862Z info 18:36:48.631:  getRemoteUri: local
2022-12-21T18:36:49.0519623Z verbose 18:36:48.643:  Python API env change detected, add => '/opt/hostedtoolcache/Python/3.10.9/x64/python}'
2022-12-21T18:36:49.0698444Z verbose 18:36:48.764:  Python API env change detected, update => '/usr/bin/python}'
2022-12-21T18:36:49.0765408Z verbose 18:36:48.888:  Python API env change detected, update => '/opt/hostedtoolcache/Python/3.10.9/x64/python}'
2022-12-21T18:36:49.0842667Z verbose 18:36:48.890:  Python API env change detected, remove => '/opt/hostedtoolcache/Python/3.10.9/x64/bin/python}'
2022-12-21T18:36:49.0941313Z verbose 18:36:48.940:  Refreshed Environments
2022-12-21T18:36:49.1388804Z verbose 18:36:48.940:  Refreshed Environments
2022-12-21T18:36:49.1389826Z info 18:36:48.940:  Fetching TargetController document Untitled-1.ipynb cancelled.
2022-12-21T18:36:49.1443254Z verbose 18:36:48.941:  Compute Preferred Controller, Class name = ControllerPreferredService, completed in 521ms, has a truthy return value, Arg 1: <Uri:Untitled-1.ipynb>, Arg 2: undefined, Arg 3: {"a":true,"b":null}, Return Value: {}
2022-12-21T18:36:49.1988309Z No need to update Interpreter path, as it is /opt/hostedtoolcache/Python/3.10.9/x64/bin/python in workspace
2022-12-21T18:36:49.3727989Z verbose 18:36:49.107:  Python API env change detected, add => '/opt/hostedtoolcache/Python/3.10.9/x64/bin/python}'
2022-12-21T18:36:49.4227431Z No need to update Interpreter path, as it is /opt/hostedtoolcache/Python/3.10.9/x64/bin/python in workspace
2022-12-21T18:36:49.4228954Z verbose 18:36:49.197:  Get Active Interpreter, Class name = InterpreterService (started execution), Arg 1: "Untitled-1.ipynb"
2022-12-21T18:36:49.4238902Z info 18:36:49.198:  Active Environment Path for /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience is {"id":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","path":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python"}
2022-12-21T18:36:49.4248549Z info 18:36:49.205:  Resolved Active Environment for /home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience is {"internal":{"path":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","id":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","executable":{"uri":{"$mid":1,"path":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","scheme":"file"},"bitness":"64-bit","sysPrefix":"/opt/hostedtoolcache/Python/3.10.9/x64"},"version":{"major":3,"minor":10,"micro":9,"release":{"level":"final","serial":0},"sysVersion":"3.10.9 (main, Dec  7 2022, 08:16:13) [GCC 11.3.0]"},"tools":[]},"id":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python"}
2022-12-21T18:36:49.4261623Z info 18:36:49.209:  Active Interpreter in Python API for resource '/home/runner/work/vscode-jupyter/vscode-jupyter/src/test/datascience' is /opt/hostedtoolcache/Python/3.10.9/x64/bin/python, EnvType: Unknown, EnvName: '', Version: 3.10.9 (main, Dec  7 2022, 08:16:13) [GCC 11.3.0]
2022-12-21T18:36:49.4265231Z verbose 18:36:49.209:  Get Active Interpreter, Class name = InterpreterService, completed in 13ms, has a truthy return value, Arg 1: "Untitled-1.ipynb", Return Value: {"id":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","sysPrefix":"/opt/hostedtoolcache/Python/3.10.9/x64","displayPath":{"$mid":1,"path":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","scheme":"file"},"envName":"","uri":{"$mid":1,"fsPath":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","path":"/opt/hostedtoolcache/Python/3.10.9/x64/bin/python","scheme":"file"},"displayName":"","envType":"Unknown","version":{"major":3,"minor":10,"patch":9,"raw":"3.10.9 (main, Dec  7 2022, 08:16:13) [GCC 11.3.0]"}}
2022-12-21T18:36:49.4323059Z verbose 18:36:49.281:  Python API env change detected, remove => '/opt/hostedtoolcache/Python/3.10.9/x64/bin/python}'
2022-12-21T18:36:49.4349365Z verbose 18:36:49.297:  Full interpreter list after refreshing (total 15ms, resolve 2ms, refresh 13ms) is length: 7,

This is most likely the cause of the bug that users are also running into microsoft/vscode-jupyter#11747

@karrtikr do you have an update on this bug, we're running into this issue very often on CI and I believe our users too are running into this issue on the stable release and having issues running code in notebooks.

karrtikr · 2022-12-22T13:07:47Z

I'll try to have a look today. Meanwhile you can work around this issue at Jupyter's end by selectively ignoring remove events if resolveEnvironment API for the event does not return undefined.

karrtikr · 2022-12-22T18:09:19Z

I have created a PR #20424 which should hopefully take care of this, leaving this open so you can verify. Happy holidays!

For #20292 We currently remove environments from cache which aren't part of the latest discovery run. This is not correct as consumers can still select envs not reported by discovery run, which we shouldn't remove.

DonJayamanne · 2022-12-22T19:04:20Z

@karrtikr

Can you ship a insider release now, so this can be tested by Jupyter users as well as SteVen.

Also, whats the possibility of having a recovery release for this, we have a few users running into this.
SteVen is running into this consistently on a daily basis, since cell execution is a core functionality of this extension i fear this would adversely impact Jupyter extension users.

@brettcannon /cc

karrtikr · 2022-12-22T19:13:06Z

Also, whats the possibility of having a recovery release for this, we have a few users running into this.

I'm OOF starting now until 3rd, Brett can help with the timelines. I've mentioned a workaround here in case the timeline doesn't work for you guys: #20292 (comment)

Can you ship a insider release now, so this can be tested by Jupyter users as well as SteVen.

Done, should be out soon.

brettcannon · 2022-12-22T19:32:23Z

Can you ship a insider release now, so this can be tested by Jupyter users as well as SteVen.

Done, should be out soon.

And I also kicked it off, so you're doubly covered. 😉

whats the possibility of having a recovery release for this, we have a few users running into this.

Before the New Year, there's unfortunately no chance as there's no one around to handle any issues that may come up. But we can definitely consider doing a bugfix release the week of Jan 3 if you can confirm that the fix does what you need.

DonJayamanne · 2023-01-23T05:54:43Z

Re-opening this issue as we're still running into this with the latest bits.
here is the job: https://github.com/microsoft/vscode-jupyter/actions/runs/3982254971/jobs/6826558182
Here are the VS Code logs https://github.com/microsoft/vscode-jupyter/suites/10516484742/artifacts/522267049

We've had a few other failures as well, but forgot to report this.

karrtikr · 2023-01-23T16:47:57Z

@DonJayamanne This probably won't make it in the current iteration, as I'm OOF most of the week. Consider using the workaround I suggested above for this release.

DonJayamanne · 2023-01-23T23:06:48Z

@karrtikr that work around also does not work as Python extension is caching the information.
I have to check whether the file exists on disc or not to get things working.
I.e.

assume I delete a python env,
and then refresh the list,
Now we get the remove event
I call resolveEnvironment, and I still get a valid response
That is clearly wrong
The way to get around this is to check if the executable exists on disc or not

Bug: I think there's another bug in the API

karrtikr · 2023-01-24T05:58:31Z

Strange, 'remove' event is only fired after the environment is removed from cache, so 'resolveEnvironment' should ideally be returning 'undefined'.

Maybe there's some other caching that's going on.

DonJayamanne · 2023-02-10T11:28:05Z

@karrtikr just wanted to check if there was any progress on this.
I'm curious what needs-spike means, does that mean this iteration you are only going to investigate this and resolve this the next iteration?

If this isn't resolved for this iteration or cannot be resolved, then we might want to add some work around in the Jupyter extension.
This is because when such events get fired, notebooks break completely (i.e. user could be running some code and then all of a sudden everything could crash just because of this invalid event).

karrtikr · 2023-02-10T12:12:45Z

We've other priority items that are being worked on right now, but we should be able to tackle this in this iteration as well. But given this has a simple workaround, please use that meanwhile.

I'm curious what needs-spike means, does that mean this iteration you are only going to investigate this and resolve this the next iteration?

It just means the next step is to investigate, we can resolve this immediately after in this iteration.

brettcannon · 2023-02-10T18:03:09Z

FYI all of our "needs" labels are scoped to the issue, not to a specific iteration; it just records what is keeping the issue open.

DonJayamanne · 2023-02-10T20:11:14Z

Thanks for the clarification

karrtikr · 2023-03-01T19:06:21Z

I'm not able to reproduce this issue on Jupyter CI, confirmed after removing the workaround which was added. No tests fails, and I checked verbose logging to ensure that no remove events are being fired.

DonJayamanne · 2023-03-01T19:14:20Z

tests fails, and I checked verbose logging to ensure that no remove events are being fired.

please note it was flaky, it wasn’t something that happened 100% of the time
I would suggest running the tests at least 10-20 times

karrtikr · 2023-03-01T19:23:55Z

Okay I'll try it a few more times, I have added additional logging in the Python extension to diagnose in case this happens again.

karrtikr · 2023-03-02T09:33:06Z

Able to repro it finally after running 10 runs concurrently 😄 Reason remove events were being fired was that running those interpreters was failing on CI due to timeout error (probably because of CPU load). So increased timeout from 15s to 30s on CI which seemed to have solved the problem.

The cause of this issue was different than what was originally reported in the issue.

DonJayamanne added the feature-request Request for new features or functionality label Nov 30, 2022

github-actions bot added the triage-needed Needs assignment to the proper sub-team label Nov 30, 2022

DonJayamanne changed the title ~~Python Extension API incorrectly triggers 'remote'~~ Python Extension API incorrectly triggers 'remove' event Nov 30, 2022

DonJayamanne added bug Issue identified by VS Code Team member as probable bug and removed feature-request Request for new features or functionality labels Nov 30, 2022

DonJayamanne assigned karrtikr Nov 30, 2022

DonJayamanne mentioned this issue Dec 1, 2022

Controller gets disposed incorrectly (due to incorrect notification of removal of python env) microsoft/vscode-jupyter#12250

Closed

karrtikr mentioned this issue Dec 22, 2022

Do not remove envs which are provided by the consumer #20424

Merged

karrtikr added this to the January 2023 milestone Dec 22, 2022

karrtikr closed this as completed in #20424 Dec 22, 2022

DonJayamanne mentioned this issue Dec 22, 2022

Remove work around added for Python API issue microsoft/vscode-jupyter#12435

Merged

github-actions bot locked as resolved and limited conversation to collaborators Jan 22, 2023

DonJayamanne reopened this Jan 23, 2023

karthiknadig modified the milestones: January 2023, February 2023 Jan 24, 2023

karthiknadig modified the milestones: February 2023, March 2023 Feb 21, 2023

DonJayamanne closed this as completed in microsoft/vscode-jupyter#12962 Mar 3, 2023

karrtikr added the verified Verification succeeded label Mar 20, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Python Extension API incorrectly triggers 'remove' event #20292

Python Extension API incorrectly triggers 'remove' event #20292

DonJayamanne commented Nov 30, 2022 •

edited

Loading

DonJayamanne commented Nov 30, 2022 •

edited

Loading

DonJayamanne commented Dec 7, 2022

DonJayamanne commented Dec 21, 2022 •

edited

Loading

karrtikr commented Dec 22, 2022

karrtikr commented Dec 22, 2022

DonJayamanne commented Dec 22, 2022 •

edited

Loading

karrtikr commented Dec 22, 2022

brettcannon commented Dec 22, 2022

DonJayamanne commented Jan 23, 2023

karrtikr commented Jan 23, 2023 •

edited

Loading

DonJayamanne commented Jan 23, 2023

karrtikr commented Jan 24, 2023

DonJayamanne commented Feb 10, 2023 •

edited

Loading

karrtikr commented Feb 10, 2023

brettcannon commented Feb 10, 2023

DonJayamanne commented Feb 10, 2023

karrtikr commented Mar 1, 2023

DonJayamanne commented Mar 1, 2023

karrtikr commented Mar 1, 2023

karrtikr commented Mar 2, 2023 •

edited

Loading

Python Extension API incorrectly triggers 'remove' event #20292

Python Extension API incorrectly triggers 'remove' event #20292

Comments

DonJayamanne commented Nov 30, 2022 • edited Loading

DonJayamanne commented Nov 30, 2022 • edited Loading

DonJayamanne commented Dec 7, 2022

DonJayamanne commented Dec 21, 2022 • edited Loading

karrtikr commented Dec 22, 2022

karrtikr commented Dec 22, 2022

DonJayamanne commented Dec 22, 2022 • edited Loading

karrtikr commented Dec 22, 2022

brettcannon commented Dec 22, 2022

DonJayamanne commented Jan 23, 2023

karrtikr commented Jan 23, 2023 • edited Loading

DonJayamanne commented Jan 23, 2023

karrtikr commented Jan 24, 2023

DonJayamanne commented Feb 10, 2023 • edited Loading

karrtikr commented Feb 10, 2023

brettcannon commented Feb 10, 2023

DonJayamanne commented Feb 10, 2023

karrtikr commented Mar 1, 2023

DonJayamanne commented Mar 1, 2023

karrtikr commented Mar 1, 2023

karrtikr commented Mar 2, 2023 • edited Loading

DonJayamanne commented Nov 30, 2022 •

edited

Loading

DonJayamanne commented Nov 30, 2022 •

edited

Loading

DonJayamanne commented Dec 21, 2022 •

edited

Loading

DonJayamanne commented Dec 22, 2022 •

edited

Loading

karrtikr commented Jan 23, 2023 •

edited

Loading

DonJayamanne commented Feb 10, 2023 •

edited

Loading

karrtikr commented Mar 2, 2023 •

edited

Loading