Socket connect time out when starting Python interpreter

MrMho commented 3 months ago

Versions

Positron Version: 2024.06.1 (system setup) build 2024.06.1-27 Code - OSS Version: 1.90.0 Commit: a893e5b282612ccb2200102957ac38d3c14e5196 Date: 2024-06-26T01:33:58.809Z (5 days ago) Electron: 29.4.0 Chromium: 122.0.6261.156 Node.js: 20.9.0 V8: 12.2.281.27-electron.0 OS: Windows_NT x64 10.0.19045

Python 3.11.1

Steps to reproduce the issue:

Open a Jupyter Notebook
Wait for Positron attempting to connect to the Python interpreter (see "Console" pane)

What did you expect to happen?

Be able to use Python in the console and in the Jupyter Notebook. However, both are not responding when you try to run code.

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

Error: Socket connect timed out after 20 seconds
C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe "c:\Program Files\Positron\resources\app\extensions\positron-python\python_files\positron\positron_language_server.py" -f C:\Users\ [UserName]\AppData\Local\Temp\kernel-emflIe\connection.json --logfile C:\Users\[UserName]AppData\Local\Temp\kernel-emflIe\kernel.log --loglevel error --session-mode console 
Process exit code 1

seeM commented 3 months ago

This appears to be the same issue as https://github.com/posit-dev/positron/discussions/3717, also on Windows.

The kernel is taking longer than expected to connect to the frontend. Either nothing is going wrong and it really is just taking long, in which case we should bump the timeout. Or something unexpected is happening.

Could you please share the full output logs? You can open them using Ctrl+Shift+p and running the "Interpreter: Show interpreter output" command. You can include them as a gist or directly here wrapped in a <details></details> tag so that it's easier to read.

As a very rough test, what happens if you run just C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe in the terminal? Does it open the ordinary REPL? How long does it take? Similarly for this (replacing [UserName] as needed):

C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe "c:\Program Files\Positron\resources\app\extensions\positron-python\python_files\positron\positron_language_server.py" -f C:\Users\ [UserName]\AppData\Local\Temp\kernel-emflIe\connection.json --logfile C:\Users\[UserName]AppData\Local\Temp\kernel-emflIe\kernel.log --loglevel error --session-mode console

MrMho commented 3 months ago

Full interpreter output

``` [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined) [Positron] Connecting to Python 3.11.1 (Global) kernel (pid 9824) [Positron] Streaming log file: C:\Users\[UserName]\AppData\Local\Temp\kernel-21DQ7r\kernel.log [Positron] Connecting to kernel sockets defined in C:\Users\[UserName]\AppData\Local\Temp\kernel-21DQ7r\connection.json... [Positron] Control socket created (count = 16) [Positron] Shell socket created (count = 17) [Positron] Stdin socket created (count = 18) [Positron] I/O socket created (count = 19) [Positron] Heartbeat socket created (count = 20) [Positron] Control socket connecting to tcp://127.0.0.1:47344... [Positron] Shell socket connecting to tcp://127.0.0.1:49939... [Positron] Stdin socket connecting to tcp://127.0.0.1:58659... [Positron] I/O socket connecting to tcp://127.0.0.1:55626... [Positron] Heartbeat socket connecting to tcp://127.0.0.1:52822... [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined) [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined) [Positron] Control socket still connecting (2s) [Positron] Shell socket still connecting (2s) [Positron] Stdin socket still connecting (2s) [Positron] I/O socket still connecting (2s) [Positron] Heartbeat socket still connecting (2s) [Positron] Control socket still connecting (4s) [Positron] Shell socket still connecting (4s) [Positron] Stdin socket still connecting (4s) [Positron] I/O socket still connecting (4s) [Positron] Heartbeat socket still connecting (4s) [Python] *** Log started at 02.07.2024 13:42:47,34 [Python] *** Command line: [Python] C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe "c:\Program Files\Positron\resources\app\extensions\positron-python\python_files\positron\positron_language_server.py" -f C:\Users\ [UserName]\AppData\Local\Temp\kernel-21DQ7r\connection.json --logfile C:\Users\[UserName]\AppData\Local\Temp\kernel-21DQ7r\kernel.log --loglevel error --session-mode console [Positron] Control socket still connecting (6s) [Positron] Shell socket still connecting (6s) [Positron] Stdin socket still connecting (6s) [Positron] I/O socket still connecting (6s) [Positron] Heartbeat socket still connecting (6s) [Positron] Control socket still connecting (8s) [Positron] Shell socket still connecting (8s) [Positron] Stdin socket still connecting (8s) [Positron] I/O socket still connecting (8s) [Positron] Heartbeat socket still connecting (8s) [Positron] Python 3.11.1 (Global) failed to start; exit code: 0 [Python] *** Log ended at 02.07.2024 13:42:53,91 [Python] Process exit code 1 [Positron] Control socket still connecting (10s) [Positron] Shell socket still connecting (10s) [Positron] Stdin socket still connecting (10s) [Positron] I/O socket still connecting (10s) [Positron] Heartbeat socket still connecting (10s) [Positron] Control socket still connecting (12s) [Positron] Shell socket still connecting (12s) [Positron] Stdin socket still connecting (12s) [Positron] I/O socket still connecting (12s) [Positron] Heartbeat socket still connecting (12s) [Positron] Control socket still connecting (14s) [Positron] Shell socket still connecting (14s) [Positron] Stdin socket still connecting (14s) [Positron] I/O socket still connecting (14s) [Positron] Heartbeat socket still connecting (14s) [Positron] Control socket still connecting (16s) [Positron] Shell socket still connecting (16s) [Positron] Stdin socket still connecting (16s) [Positron] I/O socket still connecting (16s) [Positron] Heartbeat socket still connecting (16s) [Positron] Control socket still connecting (18s) [Positron] Shell socket still connecting (18s) [Positron] Stdin socket still connecting (18s) [Positron] I/O socket still connecting (18s) [Positron] Heartbeat socket still connecting (18s) [Positron] Control socket connect timed out after 20 seconds [Positron] Shell socket connect timed out after 20 seconds [Positron] Stdin socket connect timed out after 20 seconds [Positron] I/O socket connect timed out after 20 seconds [Positron] Heartbeat socket connect timed out after 20 seconds ```

2.

Running C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe in the terminal works fine and only takes about one second. It opens up a functioning REPL.

Running this

C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe "c:\Program Files\Positron\resources\app\extensions\positron-python\python_files\positron\positron_language_server.py" -f C:\Users\ [UserName]\AppData\Local\Temp\kernel-emflIe\connection.json --logfile C:\Users\[UserName]AppData\Local\Temp\kernel-emflIe\kernel.log --loglevel error --session-mode console

gives me the following output

NOTE: When using the `ipython kernel` entry point, Ctrl-C will not work.

To exit, you will have to explicitly quit this process, by either sending
"quit" from a client, or using Ctrl-\ in UNIX-like environments.

To read more about this, see https://github.com/ipython/ipython/issues/2049

To connect another client to this kernel, use:
    --existing C:\Users\[UserName]\AppData\Local\Temp\kernel-emflIe\connection.json

Full interpreter output

``` [Positron] Control socket still connecting (2s) [Positron] Shell socket still connecting (2s) [Positron] Stdin socket still connecting (2s) [Positron] I/O socket still connecting (2s) [Positron] Heartbeat socket still connecting (2s) [Positron] Control socket still connecting (4s) [Positron] Shell socket still connecting (4s) [Positron] Stdin socket still connecting (4s) [Positron] I/O socket still connecting (4s) [Positron] Heartbeat socket still connecting (4s) [Positron] Control socket still connecting (6s) [Positron] Shell socket still connecting (6s) [Positron] Stdin socket still connecting (6s) [Positron] I/O socket still connecting (6s) [Positron] Heartbeat socket still connecting (6s) [Positron] Control socket still connecting (8s) [Positron] Shell socket still connecting (8s) [Positron] Stdin socket still connecting (8s) [Positron] I/O socket still connecting (8s) [Positron] Heartbeat socket still connecting (8s) [Positron] Control socket still connecting (10s) [Positron] Shell socket still connecting (10s) [Positron] Stdin socket still connecting (10s) [Positron] I/O socket still connecting (10s) [Positron] Heartbeat socket still connecting (10s) [Positron] Control socket still connecting (12s) [Positron] Shell socket still connecting (12s) [Positron] Stdin socket still connecting (12s) [Positron] I/O socket still connecting (12s) [Positron] Heartbeat socket still connecting (12s) [Positron] Control socket still connecting (14s) [Positron] Shell socket still connecting (14s) [Positron] Stdin socket still connecting (14s) [Positron] I/O socket still connecting (14s) [Positron] Heartbeat socket still connecting (14s) [Positron] Control socket still connecting (16s) [Positron] Shell socket still connecting (16s) [Positron] Stdin socket still connecting (16s) [Positron] I/O socket still connecting (16s) [Positron] Heartbeat socket still connecting (16s) [Positron] Control socket still connecting (18s) [Positron] Shell socket still connecting (18s) [Positron] Stdin socket still connecting (18s) [Positron] I/O socket still connecting (18s) [Positron] Heartbeat socket still connecting (18s) [Positron] Control socket connect timed out after 20 seconds [Positron] Shell socket connect timed out after 20 seconds [Positron] Stdin socket connect timed out after 20 seconds [Positron] I/O socket connect timed out after 20 seconds [Positron] Heartbeat socket connect timed out after 20 seconds [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined) [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined) ```

seeM commented 3 months ago

Thank you very much for the details.

It looks like the kernel process is crashing (with exit code 1). I'm not sure why it's crashing when Positron starts it but not in the terminal.

Positron runs it via a "kernel wrapper" script, maybe that's causing an issue. Could you please try running that in a terminal as well, and sharing the output or any errors from the terminal? It should be the same as before, but with the kernel-wrapper file prepended:

"C:\Program Files\Positron\resources\app\extensions\jupyter-adapter/resources/kernel-wrapper.bat"  C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe C:\Users\[UserName]AppData\Local\Temp\kernel-emflIe\kernel.log "c:\Program Files\Positron\resources\app\extensions\positron-python\python_files\positron\positron_language_server.py" -f C:\Users\ [UserName]\AppData\Local\Temp\kernel-emflIe\connection.json --logfile C:\Users\[UserName]AppData\Local\Temp\kernel-emflIe\kernel.log --loglevel error --session-mode console

MrMho commented 3 months ago

~~Sorry. Running your command in the terminal gives me an unexpected token in column 100 error (starting here~~C:\Users\Public\AppData\Local\Programs\Python\Python311\p...). ~~Are you sure it is correct? Or maybe I am missing something here.~~

MrMho commented 3 months ago

Ok, nevermind. The above error was caused by some powershell quirk, I guess.

I was now able to run the command.

Gives me the following output

Copyright (C) 2023 Posit Software, PBC. All rights reserved.
This script is used to run a program and capture its output to a file. It is
used to capture the output of the kernel process so that it can be displayed
in the UI in the case of a startup failure; it may also be used in the future
to perform Positron-specific kernel startup routines, such as setting up

The process cannot access the file because it is being used by another process.
The process cannot access the file because it is being used by another process.
The process cannot access the file because it is being used by another process.

I have no idea what other process that could be. I have nothing running in the background, as far as I know.

The interpreter output repeats the usual [Positron] SEND heartbeat with timeout of 30 seconds.

seeM commented 3 months ago

I see.

Could you please also share your CPU specs?
This might be silly, but does rebooting your computer help?

MrMho commented 3 months ago

Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz 3.40 GHz
I already tried that, didn't help unfortunately.

seeM commented 3 months ago

Sorry, this is quite a tricky one to debug remotely 😅 I have another idea to narrow down the issue.

Could you please try running the command below directly in a terminal and share the output here? I think the error message is being lost in the other approaches we've tried.

C:\Users\Public\AppData\Local\Programs\Python\Python311\python.exe "c:\Program Files\Positron\resources\app\extensions\positron-python\python_files\positron\positron_language_server.py" --loglevel debug

If it errors, hopefully the message will give us a clue for where to look next.

If it works, though, it should print out something like this:

``` 0.00s - 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. [PositronIPKernelApp] Using existing profile dir: '/Users/seem/.ipython/profile_default' [PositronIPKernelApp] Searching path ['/Users/seem/.ipython/profile_default', '/Users/seem/.pyenv/versions/3.11.9/etc/ipython', '/usr/local/etc/ipython', '/etc/ipython'] for config files [PositronIPKernelApp] Attempting to load config file: ipython_config.py [PositronIPKernelApp] Looking for ipython_config in /etc/ipython [PositronIPKernelApp] Looking for ipython_config in /usr/local/etc/ipython [PositronIPKernelApp] Looking for ipython_config in /Users/seem/.pyenv/versions/3.11.9/etc/ipython [PositronIPKernelApp] Looking for ipython_config in /Users/seem/.ipython/profile_default [PositronIPKernelApp] Loaded config file: /Users/seem/.ipython/profile_default/ipython_config.py [PositronIPKernelApp] Attempting to load config file: ipython_kernel_config.py [PositronIPKernelApp] Looking for ipython_kernel_config in /etc/ipython [PositronIPKernelApp] Looking for ipython_kernel_config in /usr/local/etc/ipython [PositronIPKernelApp] Looking for ipython_kernel_config in /Users/seem/.pyenv/versions/3.11.9/etc/ipython [PositronIPKernelApp] Looking for ipython_kernel_config in /Users/seem/.ipython/profile_default [PositronIPKernelApp] Connection file not found: kernel-73768.json [PositronIPKernelApp] Starting the kernel at pid: 73768 [PositronIPKernelApp] shell ROUTER Channel on port: 52493 [PositronIPKernelApp] stdin ROUTER Channel on port: 52494 [PositronIPKernelApp] control ROUTER Channel on port: 52495 [asyncio] Using selector: KqueueSelector [PositronIPKernelApp] iopub PUB Channel on port: 52497 [asyncio] Using selector: KqueueSelector [PositronIPKernelApp] Heartbeat REP Channel on port: 52499 [PositronIPKernelApp] Writing connection file: /Users/seem/Library/Jupyter/runtime/kernel-73768.json [PositronIPKernelApp] To connect another client to this kernel, use: [PositronIPKernelApp] --existing kernel-73768.json NOTE: When using the `ipython kernel` entry point, Ctrl-C will not work. To exit, you will have to explicitly quit this process, by either sending "quit" from a client, or using Ctrl-\ in UNIX-like environments. To read more about this, see https://github.com/ipython/ipython/issues/2049 To connect another client to this kernel, use: --existing kernel-73768.json [PositronIPKernelApp] Seeing logger to stderr, rerouting to raw filedescriptor. [PositronIPKernelApp] Loading IPython extensions... [PositronIPKernelApp] Loading IPython extension: storemagic [PositronIPKernelApp] Running startup files from /Users/seem/.ipython/profile_default/startup... [PositronIPKernelApp] Running file in user namespace: /Users/seem/.ipython/profile_default/startup/startup.py [matplotlib] matplotlib data path: /Users/seem/.pyenv/versions/3.11.9/lib/python3.11/site-packages/matplotlib/mpl-data [matplotlib] CONFIGDIR=/Users/seem/.matplotlib [matplotlib] interactive is False [matplotlib] platform is darwin [matplotlib] CACHEDIR=/Users/seem/.matplotlib [matplotlib.font_manager] Using fontManager instance from /Users/seem/.matplotlib/fontlist-v330.json [positron_ipykernel.pydoc] Pydoc server ready at: http://localhost:52510/ [__main__] Process ID 73768 ```

Then, could you please also try to connect an ordinary Jupyter console to your running kernel with:

jupyter console --existing kernel-73768.json

I got the --existing kernel-73768.json part from the output of the kernel script – you will need to replace that accordingly. You may need to pip install jupyter-console for that.

Does that perhaps cause the kernel process to crash with any useful error message?

MrMho commented 2 months ago

Ok, both commands work without any problems: I can start the kernel, connect to it and I get a responsive Jupyter console.

I did some more testing and noticed that sometimes Positron can launch and connect to the kernel just fine. Then, after a system reboot I get the socket connect timeout that I described in the first post. Sometimes I can fix this by restarting the kernel via Positron's GUI (interpreter list in the top-right corner).

To summarize, the error only appears occasionally and is not reliably reproducible for me. To be honest, I am quiet puzzled and have no idea why that is. Sorry, this is probably not very helpful for you guys.

seeM commented 2 months ago

Ah, it's annoying that the kernel works when started in the terminal but silently errors in Positron! Does it work every time in the terminal or is that unreliable too?

The best next step I can think of is to try to improve our logging for the kernel wrapper script on Windows so that we can see what's going wrong in the Positron context.

MrMho commented 2 months ago

Ah, it's annoying that the kernel works when started in the terminal but silently errors in Positron! Does it work every time in the terminal or is that unreliable too?

I have tried it several times with different terminal applications (cmd, powershell, bash) and the kernel works everytime when started from the terminal.

In Positron, it works in about 50% of the cases. My current work-around is to manually restart the interpreter via Positron's GUI, which works well most of the times.

dmonder commented 2 months ago

For what it's worth, I am getting this same error in the same way (it fails when I start it up but if I manually start it everything works). ?I also tried the commands requested above and received the same responses.

I am using the following setup:

Positron Version: 2024.07.0 (system setup) build 2024.07.0-52 Code - OSS Version: 1.90.0 Commit: eee2ff0fdcb422608b5181338e6204cdb5e311cd Date: 2024-07-16T03:21:53.561Z Electron: 29.4.0 Chromium: 122.0.6261.156 Node.js: 20.9.0 V8: 12.2.281.27-electron.0 OS: Windows_NT x64 10.0.22000

seeM commented 2 months ago

The best next step I can think of is to try to improve our logging for the kernel wrapper script on Windows so that we can see what's going wrong in the Positron context.

Adding some more detail for whomever works on this:

We run our kernels indirectly via a "kernel wrapper" script. Here's why, as commented in the script:

This script is used to run a program and capture its output to a file. It is used to capture the output of the kernel process so that it can be displayed in the UI in the case of a startup failure; it may also be used in the future to perform Positron-specific kernel startup routines, such as setting up environment variables.

We have two versions of this script:

UNIX kernel-wrapper.sh: https://github.com/posit-dev/positron/blob/main/extensions/jupyter-adapter/resources/kernel-wrapper.sh
Windows kernel-wrapper.bat: https://github.com/posit-dev/positron/blob/main/extensions/jupyter-adapter/resources/kernel-wrapper.bat

As noted in the Windows version, we don't currently capture stdout or stderr for Windows:

Unlike kernel-wrapper.sh, we do not redirect stdout and stderr to the output file, since this would lock the file and prevent the kernel itself from being able to open the file and log to it, since on Windows only 1 process is allowed to hold write access to a file at any time (https://stackoverflow.com/questions/9337415/how-do-you-have-shared-log-files-under-windows). We generally care about capturing stdout and stderr in the case of startup failure, in which case we might get useful failure information from there, but history has shown us that Windows is not great about emitting problems to the tty, so it probably isn't that useful to try and capture it. https://github.com/posit-dev/positron/issues/1540

One possible approach to capture stdout and stderr on Windows is pipe them to separate files, and update the log streamer (src) to read from multiple files. It may still encounter some Windows file locking issue anyway, though.

I recommend reading through the discussion in #1540 as well.

ntluong95 commented 2 months ago

Also, I just want to add 1 point is that if the python interpreter fails to start, then the buttons 'Restart console" or "Shutdown console" are also malfunction, which means if you click on this, nothing happen. If I want to restart the interpreter, either close Positron and open again. Recently, I found that I can do by Ctrl + Shift + P -> Python: Select interpreter. This way is much more reliable, but it will create another python console with the same name of the old one. See this picture:

juliasilge commented 1 month ago

Thanks to all for your patience on this! 🙌 We have another possibility for diagnosing the problem, if you are willing to give it a try.

Please download and install the latest release
Go into the settings, find positron.jupyterAdapter.showTerminal, and opt in (set it to true):

Complete close Positron and reopen it
Go to the terminals; you will see an additional one for R and/or Python. Mine look like this for both R and Python (totally blank), because my interpreters can start fine and all the output is going where it is intended:

What do you see there? 👀

MrMho commented 1 month ago

This is what my Python terminal shows:

C:\Users\[UserName]>REM ---------------------------------------------------------------------------------------------

C:\Users\[UserName]>REM Copyright (C) 2023 Posit Software, PBC. All rights reserved.

C:\Users\[UserName]>REM ---------------------------------------------------------------------------------------------

C:\Users\[UserName]>REM This script is used to run a program and capture its output to a file. It is

C:\Users\[UserName]>REM used to capture the output of the kernel process so that it can be displayed

C:\Users\[UserName]>REM in the UI in the case of a startup failure; it may also be used in the future

C:\Users\ [UserName]>REM to perform Positron-specific kernel startup routines, such as setting up

C:\Users\[UserName]>REM environment variables.
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.
NOTE: When using the `ipython kernel` entry point, Ctrl-C will not work.   

To exit, you will have to explicitly quit this process, by either sending  
"quit" from a client, or using Ctrl-\ in UNIX-like environments.

To read more about this, see https://github.com/ipython/ipython/issues/2049

To connect another client to this kernel, use:
    --existing C:\Users\[UserName]\AppData\Local\Temp\kernel-8a33mo\connection.json

posit-dev / positron