dmypy process remains running

[bersbersbers]

I have observed several times that some python.exe process has been left running after I closed VS Code, the command line of which hinted at dmypy still running.

At least once, I have also observed that replacing the current .venv hung until I manually killed these dmypy process(es). (I did notice that VS Code tried to temporarily change the interpreter when deleting the .venv first failed, but it did not continue until I killed the process.)

VS Code 1.85.0, extension version v2023.6.0, mypy 1.7.1 in a .venv, Python 3.12.1

I will add more details to this issue it happens again.

[karthiknadig]

Do let us know if you can find some repro steps.

[bersbersbers]

I can repro it now. Basically:

• Open Task Manager
• Close all python.exe processes
• Open VS Code with a .py file in a workspace with some 10,000 lines of Python code
• Watch for the dmypy python.exe process in Task Manager. As soon as you see one, close VS Code.
• You may see as many as four processes like this - 2 shims and two real ones:
  
• The top one will continue allocating memory (up to 500 MB in my case) at full (single-thread) CPU load, then stop, but remain.
• The bottom two will eventually close (within a couple of seconds)
• Final state:
  

So I think the problem is that dmypy does not receive, or ignores, the shutdown signal while it is starting up. When I wait for the process to reach 500 MB of RAM before closing VS Code, everything is closed fine. Switching .venvs also shuts down dmypy successfully.

Debugging tips, such as how to redirect the output of the closing VS Code windows, would be appreciated ;)

[karthiknadig]

@bersbersbers you can use debugpy (Python debugger) with the attach to process configuration to attach to the process running the lsp_server.py. You can open the bundled\tool\lsp_server.py in VS Code and set breakpoint in these two handlers:

vscode-mypy/bundled/tool/lsp_server.py

Lines 442 to 461 in ee85553

	@LSP_SERVER.feature(lsp.EXIT)
	def on_exit(_params: Optional[Any] = None) -> None:
	"""Handle clean up on exit."""
	for settings in WORKSPACE_SETTINGS.values():
	if get_mypy_info(settings).is_daemon:
	try:
	_run_dmypy_command([], copy.deepcopy(settings), "kill")
	except Exception:
	pass
	@LSP_SERVER.feature(lsp.SHUTDOWN)
	def on_shutdown(_params: Optional[Any] = None) -> None:
	"""Handle clean up on shutdown."""
	for settings in WORKSPACE_SETTINGS.values():
	if get_mypy_info(settings).is_daemon:
	try:
	_run_dmypy_command([], copy.deepcopy(settings), "stop")
	except Exception:
	pass

Closing VS Code, Re-load Window, or Close Workspace, etc will trigger exit and shutdown messages. If you do setting changes we manually trigger a server restart where we sent shutdown, exit, then start a new instance. All of these have to come to the above two handlers.

[bersbersbers]

Understood, thanks!

It's the first time I am using the Python debugger to attach to something, and am not able to attach the debugger to the process. (I am trying to attach from one VS Code window, with C:\Temp open, to attach to a mypy process started in a second VS Code windows having C:\Code\Project open.)

The debugger log file shows somethings like this:

403 Client --> Adapter:
{
    "command": "attach",
    "arguments": {
        "name": "Python Debugger: Attach using Process Id",
        "type": "debugpy",
        "request": "attach",
        "processId": "35984",
        "logToFile": true,
        "justMyCode": false,
        "__configurationTarget": 6,
        "clientOS": "windows",
        "debugOptions": [
            "RedirectOutput",
            "FixFilePathCase",
            "ShowReturnValue"
        ],
        "host": "localhost",
        "showReturnValue": true,
        "workspaceFolder": "c:\\Temp",
        "pathMappings": [
            {
                "localRoot": "c:\\Temp",
                "remoteRoot": "c:\\Temp"
            }
        ],
        "__sessionId": "6dd56adb-a7cf-4cdb-a1c4-b9761ab2f84a"
    },
    "type": "request",
    "seq": 2
}
420 Client <-- Adapter:
{
    "seq": 4,
    "type": "event",
    "event": "debugpyWaitingForServer",
    "body": {
        "host": "127.0.0.1",
        "port": 62724
    }
}
15426 Client <-- Adapter:
{
    "seq": 5,
    "type": "response",
    "request_seq": 2,
    "success": false,
    "command": "attach",
    "message": "Timed out waiting for debug server to connect."
}

Debug console says

Attaching to PID: 28656 (elapsed: 1.00s).
Attaching to PID: 28656 (elapsed: 2.00s).
Attaching to PID: 28656 (elapsed: 3.00s).
Attaching to PID: 28656 (elapsed: 4.00s).
Attaching to PID: 28656 (elapsed: 5.01s).
Attaching to PID: 28656 (elapsed: 6.01s).
Attaching to PID: 28656 (elapsed: 7.01s).
Attaching to PID: 28656 (elapsed: 8.01s).
Attaching to PID: 28656 (elapsed: 9.01s).
Attaching to PID: 28656 (elapsed: 10.01s).
--- Starting attach to pid: 28656 ---
0.01s - Debugger warning: It seems that frozen modules are being used, which may
0.00s - make the debugger miss breakpoints. Please pass -Xfrozen_modules=off
0.00s - to python to disable frozen modules.
0.00s - Note: Debugging will proceed. Set PYDEVD_DISABLE_FILE_VALIDATION=1 to disable this validation.
--- Connecting to 64 bits target (current process is: 64) ---

--- Injecting attach dll: attach_amd64.dll into pid: 28656 ---
Running executable to inject dll.
OpenProcess with pid: 28656
VirtualAllocEx in pid: 28656
WriteProcessMemory in pid: 28656
loadLibraryAddress: 28656
Waiting for LoadLibraryA to complete.
Ok, finished dll injection.

--- Injecting run code dll: run_code_on_dllmain_amd64.dll into pid: 28656 ---
Running executable to inject dll.
OpenProcess with pid: 28656
VirtualAllocEx in pid: 28656
WriteProcessMemory in pid: 28656
loadLibraryAddress: 28656
Waiting for LoadLibraryA to complete.
Ok, finished dll injection.
Attaching to PID: 28656 (elapsed: 11.01s).
Attaching to PID: 28656 (elapsed: 12.01s).
Attaching to PID: 28656 (elapsed: 13.01s).
Attaching to PID: 28656 (elapsed: 14.01s).
Attaching to PID: 28656 (elapsed: 15.01s).

I tried the Python and the Python Debugger, and also attaching to different targets.

I also tried mypy from environment (1.7.1) as well as bundled (1.6.1).

Anyway, what I did see now is the following in the Mypy type checker output when switching between .venvs:

2023-12-15 10:00:19.936 [info] [Trace - 10:00:19 AM] Received notification 'window/logMessage'.
2023-12-15 10:00:19.936 [info] CWD Server: c:\Code\project
2023-12-15 10:00:38.880 [info] Server: Stop requested
2023-12-15 10:00:38.880 [info] [Trace - 10:00:38 AM] Sending request 'shutdown - (1)'.
2023-12-15 10:00:40.889 [info] [Error - 10:00:40 AM] Stopping server timed out
2023-12-15 10:00:40.890 [error] Server: Stop failed: Error: Stopping the server timed out
2023-12-15 10:00:40.904 [info] Server run command: c:\Code\project\.venv311\Scripts\python.exe c:\Users\bers\.vscode\extensions\ms-python.mypy-type-checker-2023.6.0\bundled\tool\lsp_server.py
2023-12-15 10:00:40.905 [info] Server: Start requested.
2023-12-15 10:00:42.451 [info] CWD Server: c:\Code\project

After waiting for a while and switching back, it is more successful:

2023-12-15 10:04:50.610 [info] Server: Stop requested
2023-12-15 10:04:50.610 [info] [Trace - 10:04:50 AM] Sending request 'shutdown - (1)'.
2023-12-15 10:04:50.636 [info] [Trace - 10:04:50 AM] Received notification 'window/logMessage'.
2023-12-15 10:04:50.636 [info] c:\Code\project\.venv311\Scripts\python.exe -m mypy.dmypy --status-file C:\Users\bers\AppData\Local\Temp\.vscode.dmypy_status\status-068f2deb-956a-4134-ae30-541e781b1b1a.json stop
2023-12-15 10:04:50.638 [info] [Trace - 10:04:50 AM] Received notification 'window/logMessage'.
2023-12-15 10:04:50.638 [info] CWD Server: c:\Code\project
2023-12-15 10:04:51.104 [info] [Trace - 10:04:51 AM] Received notification 'window/logMessage'.
2023-12-15 10:04:51.104 [info] 
Daemon stopped


2023-12-15 10:04:51.105 [info] [Trace - 10:04:51 AM] Received response 'shutdown - (1)' in 499ms.
2023-12-15 10:04:51.105 [info] [Trace - 10:04:51 AM] Sending notification 'exit'.

The good think is that this way, I can quickly reproduce the issue without having to restart VS Code. And it is still true that I see this issue when switching venvs while mypy is allocating memory, which suggests to me it is busy with other things and may not be responding to the shutdown message in time. If I can increase the 2s timeout somehow (to, say, 60s), I think that would make shutdown work.

I also tried print debugging. When shutdown is successful, I can print everything I want to the output window using log_to_output. When shutdown is not successful, I do not even get this output:

def on_shutdown(_params: Optional[Any] = None) -> None:
    """Handle clean up on shutdown."""
    log_to_output("on_shutdown")
    ...

[bersbersbers]

Final bit for today: I can reproduce the problem even without a large code base, just by having a very simple Python file in C:\Temp and opening that, and then switching between two venvs quickly (with any import strategy, if that matters).

[shaperilio]

I just quit VSCode and four dmypy processes were running. Two died after several seconds but two remain.

I had only one workspace open and one process is using system python while the other one is using the one from my virtual environment, and I have the options set to use my environment's mypy.

[Kein]

Oh, looks like I've posted dupe:
#291

Very annoying issue nonetheless.

[karthiknadig]

Disable daemon mode. This happens because the daemon itself sometimes does not handle stop command correctly.

[Kein]

Sure, but I found better solution for now

[Kein]

@karthiknadig For the record -- disabling daemon mode does not help, same issue

[karthiknadig]

Can you provide the process paths and cli for the strangling mypy processes?