Restarting conda Python 3.11 kernel with data frame loaded consistently takes > 30 seconds

[wesm]

Positron Version:

main as of 5/31

Steps to reproduce the issue:

1. Load a pandas data frame in a fresh interpreter, such as

import numpy as np
import pandas as pd

df = pd.DataFrame(
    {"a": [1, 2, 3, np.NaN, 5],
     "b": ["    foo", "  bar", "baz", "qux", "potato"],
     "c": [True, False, True, False, True],
     "d": [True, None, None, False, True],
     'e': pd.date_range('2000-01-01', periods=5),
     'f': ['foo', True, None, False, True]
    }
)

2. restart the interpreter

Here's an example timeline

2024-05-31 14:27:12.004 [info] Python (3.11.8) language client state changed running => stopped
2024-05-31 14:27:46.106 [info] Creating Positron Python 3.11.8 language client (port 50077)
2024-05-31 14:27:46.107 [info] Python (3.11.8) language client state changed stopped => starting
2024-05-31 14:27:46.159 [info] Python (3.11.8) language client init successful
2024-05-31 14:27:46.159 [info] Python (3.11.8) language client state changed starting => running

What did you expect to happen?

For the interpreter to restart within 5 seconds

Were there any error messages in the output or Developer Tools console?

some, but unsure if related

[jthomasmock]

I see similar times (~ 20s) in .venv for Python 3.10.6 and 3.12. I manage Python versions with pyenv and have about 17 total interpreters, if I recall correctly.

Positron Version: 2024.05.0 (Universal) build 1307
Code - OSS Version: 1.89.0
Commit: a32eab6
Date: 2024-05-27T03:48:23.965Z (4 days ago)
Electron: 28.2.8
Chromium: 120.0.6099.291
Node.js: 18.18.2
V8: 12.0.267.19-electron.0
OS: Darwin arm64 23.4.0

[seeM]

I'm unfortunately unable to repro this. Could you please set the Python kernel log level (python.languageServerLogLevel) to debug and share the full kernel log file i.e. the "Console: Python x.y.z" output channel?

[wesm]

Here's a log with debug languageServerLogLevel:

https://gist.github.com/wesm/cb1eff8bcefbae32a5a309019bcb693d

[wesm]

Looks like the kernel is not responding to the shutdown signals properly

[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='sleeping', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.01 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='running', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.03 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.1 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.3 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 1 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 3 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGTERM: 15> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 10 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.01 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.03 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.1 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 0.3 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 1 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 3 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Python] [PositronIPKernelApp] Sending <Signals.SIGKILL: 9> to subprocess psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')
[Python] [PositronIPKernelApp] Will sleep 10 sec before checking for children and retrying. [psutil.Process(pid=485401, name='python', status='zombie', started='10:37:13')]
[Positron] SEND heartbeat with timeout of 30 seconds

[seeM]

Those logs are the main ipykernel process trying to shutdown its subprocesses here:

https://github.com/ipython/ipykernel/blob/a7d66ae2197e0d7471ba160542cf5ff7713084b5/ipykernel/kernelbase.py#L1245

Any idea which child process it's referring to? Does anything surface if you search for the PID in those same logs?

[seeM]

Oops, just realized that you posted the full logs! There's no other reference to the child PID.

It looks like it still fails to terminate the subprocess after the longest timeout (10 seconds) then just proceeds with the shutdown sequence.

[wesm]

After the first sigterm, the process status goes from "running" to "zombie" (dead but still in the process table), which in theory should not hold up the kernel restart, so that seems like a smoking gun

[wesm]

I looked at ps -aux during this 30 second period and the dead process shows up as

wesm      485577  0.0  0.0      0     0 pts/8    Z+   10:37   0:09 [python] <defunct>