posit-dev / positron

Positron, a next-generation data science IDE
Other
2.51k stars 78 forks source link

"R 4.4.1 failed to start up (exit code 0)" #3788

Closed BorgeJorge closed 3 weeks ago

BorgeJorge commented 3 months ago

Positron Version:

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 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.14393

Steps to reproduce the issue:

  1. Booted up Positron

What did you expect to happen?

I expected R to start up

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

The console window displayed:

R 4.4.1 starting.
R 4.4.1 failed to start up (exit code 0)

The following were the contents of appdata/roaming/positron/Console R 4.4.1.log:

2024-07-01 18:04:34.616 [info] [Positron] Connecting to R 4.4.1 kernel (pid 9076)
2024-07-01 18:04:34.616 [info] [Positron] Streaming log file: C:\Users\MIJANT~1\AppData\Local\Temp\2\kernel-eKespL\kernel.log
2024-07-01 18:04:34.616 [info] [Positron] Connecting to kernel sockets defined in C:\Users\MIJANT~1\AppData\Local\Temp\2\kernel-eKespL\connection.json...
2024-07-01 18:04:34.616 [info] [Positron] Control socket created (count = 1)
2024-07-01 18:04:34.617 [info] [Positron] Shell socket created (count = 2)
2024-07-01 18:04:34.617 [info] [Positron] Stdin socket created (count = 3)
2024-07-01 18:04:34.635 [info] [Positron] I/O socket created (count = 4)
2024-07-01 18:04:34.635 [info] [Positron] Heartbeat socket created (count = 5)
2024-07-01 18:04:34.635 [info] [Positron] Control socket connecting to tcp://127.0.0.1:60301...
2024-07-01 18:04:34.635 [info] [Positron] Shell socket connecting to tcp://127.0.0.1:53658...
2024-07-01 18:04:34.636 [info] [Positron] Stdin socket connecting to tcp://127.0.0.1:57166...
2024-07-01 18:04:34.636 [info] [Positron] I/O socket connecting to tcp://127.0.0.1:52356...
2024-07-01 18:04:34.636 [info] [Positron] Heartbeat socket connecting to tcp://127.0.0.1:50039...
2024-07-01 18:04:34.636 [info] [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined)
2024-07-01 18:04:34.636 [info] [Positron] R 4.4.1 failed to start; exit code: 1
2024-07-01 18:04:34.636 [info] [Positron] R kernel status changed: starting => exited
jennybc commented 3 months ago

Can you look in the Positron R Extension output channel?

Screenshot 2024-07-01 at 4 37 49 PM
BorgeJorge commented 3 months ago

Thanks, here's what's in that output channel:

2024-07-01 19:45:09.679 [info] Log level: Debug
2024-07-01 19:45:09.679 [info] Refreshing testthat status
2024-07-01 19:45:09.679 [info] Not working in an R package
2024-07-01 19:45:09.679 [info] Context key 'testthatIsConfigured' is 'false'
2024-07-01 19:45:09.679 [info] Context key 'testthatHasTests' is 'false'
2024-07-01 19:45:09.679 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-01 19:45:09.744 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-01 19:45:09.758 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-01 19:45:09.836 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-01 19:45:09.843 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-01 19:45:09.917 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-01 19:45:09.920 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-01 19:45:09.920 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.1",
    "major": 4,
    "minor": 4,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.4.1"
  },
  "version": "4.4.1",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-01 19:45:09.920 [info] Candidate R binary at C:\Program Files\R\R-4.2.3\bin\x64\R.exe
2024-07-01 19:45:09.920 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.2.3\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.2.3",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.3",
    "major": 4,
    "minor": 2,
    "patch": 3,
    "prerelease": [],
    "build": [],
    "version": "4.2.3"
  },
  "version": "4.2.3",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
2024-07-01 19:45:09.920 [info] Candidate R binary at C:\Program Files\R\R-4.3.0\bin\x64\R.exe
2024-07-01 19:45:09.920 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.3.0\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.3.0",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.3.0",
    "major": 4,
    "minor": 3,
    "patch": 0,
    "prerelease": [],
    "build": [],
    "version": "4.3.0"
  },
  "version": "4.3.0",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
2024-07-01 19:45:09.920 [info] Candidate R binary at C:\Program Files\R\R-4.3.1\bin\x64\R.exe
2024-07-01 19:45:09.920 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.3.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.3.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.3.1",
    "major": 4,
    "minor": 3,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.3.1"
  },
  "version": "4.3.1",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
2024-07-01 19:45:09.920 [info] Candidate R binary at C:\Program Files\R\R-4.3.3\bin\x64\R.exe
2024-07-01 19:45:09.920 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.3.3\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.3.3",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.3.3",
    "major": 4,
    "minor": 3,
    "patch": 3,
    "prerelease": [],
    "build": [],
    "version": "4.3.3"
  },
  "version": "4.3.3",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
2024-07-01 19:45:09.921 [info] Candidate R binary at C:\Program Files\R\R-4.4.0\bin\x64\R.exe
2024-07-01 19:45:09.921 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.0\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.0",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.0",
    "major": 4,
    "minor": 4,
    "patch": 0,
    "prerelease": [],
    "build": [],
    "version": "4.4.0"
  },
  "version": "4.4.0",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
BorgeJorge commented 3 months ago

Sorry, didn't mean to close this.

jennybc commented 3 months ago

So the last bit of the equivalent log looks like this for me:

2024-07-01 12:53:34.898 [info] Candidate R binary at C:\Program Files\R\R-4.3.3\bin\x64\R.exe
2024-07-01 12:53:34.898 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.3.3\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.3.3",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.3.3",
    "major": 4,
    "minor": 3,
    "patch": 3,
    "prerelease": [],
    "build": [],
    "version": "4.3.3"
  },
  "version": "4.3.3",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-01 12:53:38.412 [info] Creating Positron R 4.3.3 language client (port 45400)
2024-07-01 12:53:38.412 [info] ARK (R 4.3.3) language client state changed uninitialized => starting
2024-07-01 12:53:38.478 [info] ARK (R 4.3.3) language client init successful
2024-07-01 12:53:38.478 [info] ARK (R 4.3.3) language client state changed starting => running

Just to confirm, your log just ... ends after the metadata for the last R installation discovered? There is no logging around, e.g., "Creating Positron R 4.4.1 language client"?

BorgeJorge commented 3 months ago

That's correct. There's absolutely nothing beneath that final json metadata about the R-4.4.0 installation. No "Creating Positron," no nuthin.

DavisVaughan commented 3 months ago

Can you please copy and paste in the entire Console: R 4.4.1 output channel log? The output channel log likely has more information than just that appdata/roaming/positron/Console R 4.4.1.log file. I think that only contains the positron side of the logs, and is missing the ark side of the logs where the failure actually occurred.

BorgeJorge commented 3 months ago

Okay, here you go:

2024-07-02 10:49:30.918 [info] [Positron] Connecting to R 4.4.1 kernel (pid 9360)
2024-07-02 10:49:30.918 [info] [Positron] Streaming log file: C:\Users\MIJANT~1\AppData\Local\Temp\2\kernel-1oToUA\kernel.log
2024-07-02 10:49:30.918 [info] [Positron] Connecting to kernel sockets defined in C:\Users\MIJANT~1\AppData\Local\Temp\2\kernel-1oToUA\connection.json...
2024-07-02 10:49:30.918 [info] [Positron] Control socket created (count = 1)
2024-07-02 10:49:30.918 [info] [Positron] Shell socket created (count = 2)
2024-07-02 10:49:30.918 [info] [Positron] Stdin socket created (count = 3)
2024-07-02 10:49:30.927 [info] [Positron] I/O socket created (count = 4)
2024-07-02 10:49:30.927 [info] [Positron] Heartbeat socket created (count = 5)
2024-07-02 10:49:30.927 [info] [Positron] Control socket connecting to tcp://127.0.0.1:59201...
2024-07-02 10:49:30.927 [info] [Positron] Shell socket connecting to tcp://127.0.0.1:53180...
2024-07-02 10:49:30.927 [info] [Positron] Stdin socket connecting to tcp://127.0.0.1:55335...
2024-07-02 10:49:30.927 [info] [Positron] I/O socket connecting to tcp://127.0.0.1:60447...
2024-07-02 10:49:30.927 [info] [Positron] Heartbeat socket connecting to tcp://127.0.0.1:63028...
[Positron] R 4.4.1 failed to start; exit code: 1
[Positron] R kernel status changed: starting => exited
zajichek commented 3 months ago

I have something similar happening here as well, though it is exit code 134. Not sure if this is related to current issue or completely different. I'm also working on an older Mac, not sure if that affects the install.

image

Here's some relevant output:

Console image

Popups image image

Output -> Console: R 4.2.2

2024-07-02 13:08:34.460 [info] [Positron] Connecting to R 4.2.2 kernel (pid 23480)
2024-07-02 13:08:34.460 [info] [Positron] Streaming log file: /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-ZGjq8R/kernel.log
2024-07-02 13:08:34.460 [info] [Positron] Connecting to kernel sockets defined in /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-ZGjq8R/connection.json...
2024-07-02 13:08:34.460 [info] [Positron] Control socket created (count = 1)
2024-07-02 13:08:34.460 [info] [Positron] Shell socket created (count = 2)
2024-07-02 13:08:34.460 [info] [Positron] Stdin socket created (count = 3)
2024-07-02 13:08:34.460 [info] [Positron] I/O socket created (count = 4)
2024-07-02 13:08:34.460 [info] [Positron] Heartbeat socket created (count = 5)
2024-07-02 13:08:34.460 [info] [Positron] Control socket connecting to tcp://127.0.0.1:53155...
2024-07-02 13:08:34.460 [info] [Positron] Shell socket connecting to tcp://127.0.0.1:52511...
2024-07-02 13:08:34.460 [info] [Positron] Stdin socket connecting to tcp://127.0.0.1:54650...
2024-07-02 13:08:34.460 [info] [Positron] I/O socket connecting to tcp://127.0.0.1:53654...
2024-07-02 13:08:34.460 [info] [Positron] Heartbeat socket connecting to tcp://127.0.0.1:49175...
2024-07-02 13:08:34.460 [info] [Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined)
2024-07-02 13:08:34.460 [info] [Positron] R 4.2.2 failed to start; exit code: 134
2024-07-02 13:08:34.460 [info] [Positron] R kernel status changed: starting => exited
2024-07-02 13:08:34.460 [info] [R] *** Log started at Tue Jul  2 13:08:31 CDT 2024
2024-07-02 13:08:34.460 [info] [R] *** Command line:
2024-07-02 13:08:34.460 [info] [R] /Applications/Positron.app/Contents/Resources/app/extensions/positron-r/resources/ark/ark --connection_file /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-ZGjq8R/connection.json --log /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-ZGjq8R/kernel.log --startup-file /Applications/Positron.app/Contents/Resources/app/extensions/positron-r/resources/scripts/startup.R --session-mode console -- --interactive --no-restore-data
2024-07-02 13:08:34.460 [info] [R] dyld: Symbol not found: __ZNKSt3__115basic_stringbufIcNS_11char_traitsIcEENS_9allocatorIcEEE3strEv
2024-07-02 13:08:34.460 [info] [R]   Referenced from: /Applications/Positron.app/Contents/Resources/app/extensions/positron-r/resources/ark/ark (which was built for Mac OS X 14.0)
2024-07-02 13:08:34.460 [info] [R]   Expected in: /usr/lib/libc++.1.dylib
2024-07-02 13:08:34.460 [info] [R] 
2024-07-02 13:08:34.460 [info] [R] *** Log ended at Tue Jul  2 13:08:31 CDT 2024
2024-07-02 13:08:34.460 [info] [R] Process exit code 134
[Positron] Connecting to R 4.2.2 kernel (pid 23540)
[Positron] Streaming log file: /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-tDIb2d/kernel.log
[Positron] Connecting to kernel sockets defined in /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-tDIb2d/connection.json...
[Positron] Control socket created (count = 6)
[Positron] Shell socket created (count = 7)
[Positron] Stdin socket created (count = 8)
[Positron] I/O socket created (count = 9)
[Positron] Heartbeat socket created (count = 10)
[Positron] Control socket connecting to tcp://127.0.0.1:63446...
[Positron] Shell socket connecting to tcp://127.0.0.1:56368...
[Positron] Stdin socket connecting to tcp://127.0.0.1:54458...
[Positron] I/O socket connecting to tcp://127.0.0.1:60159...
[Positron] Heartbeat socket connecting to tcp://127.0.0.1:65359...
[Positron] R 4.2.2 failed to start; exit code: 134
[R] /Applications/Positron.app/Contents/Resources/app/extensions/positron-r/resources/ark/ark --connection_file /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-tDIb2d/connection.json --log /var/folders/q8/1pkzzk4n1jj1zcy_57k660100000gn/T/kernel-tDIb2d/kernel.log --startup-file /Applications/Positron.app/Contents/Resources/app/extensions/positron-r/resources/scripts/startup.R --session-mode console -- --interactive --no-restore-data
[R] dyld: Symbol not found: __ZNKSt3__115basic_stringbufIcNS_11char_traitsIcEENS_9allocatorIcEEE3strEv
[R]   Referenced from: /Applications/Positron.app/Contents/Resources/app/extensions/positron-r/resources/ark/ark (which was built for Mac OS X 14.0)
[R]   Expected in: /usr/lib/libc++.1.dylib
[R] 
[R] *** Log ended at Tue Jul  2 13:12:46 CDT 2024
[R] Process exit code 134
[R] 
[Positron] R kernel status changed: starting => exited

Output -> Positron R Extension

2024-07-02 13:08:29.650 [info] Log level: Debug
2024-07-02 13:08:29.650 [info] Refreshing testthat status
2024-07-02 13:08:29.650 [info] Not working in an R package
2024-07-02 13:08:29.650 [info] Context key 'testthatIsConfigured' is 'false'
2024-07-02 13:08:29.650 [info] Context key 'testthatHasTests' is 'false'
2024-07-02 13:08:29.838 [info] Resolved R binary at /Library/Frameworks/R.framework/Versions/4.2/Resources/bin/R
2024-07-02 13:08:30.084 [info] Candidate R binary at /Library/Frameworks/R.framework/Versions/4.2/Resources/bin/R
2024-07-02 13:08:30.084 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "/Library/Frameworks/R.framework/Versions/4.2/Resources/bin/R",
  "homepath": "/Library/Frameworks/R.framework/Resources",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.2",
    "major": 4,
    "minor": 2,
    "patch": 2,
    "prerelease": [],
    "build": [],
    "version": "4.2.2"
  },
  "version": "4.2.2",
  "arch": "x86_64",
  "current": true,
  "orthogonal": false
}
2024-07-02 13:08:30.085 [info] Resolved R binary at /Library/Frameworks/R.framework/Versions/4.2/Resources/bin/R
2024-07-02 13:08:30.449 [info] Candidate R binary at /Library/Frameworks/R.framework/Versions/4.2/Resources/bin/R
2024-07-02 13:08:30.449 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "/Library/Frameworks/R.framework/Versions/4.2/Resources/bin/R",
  "homepath": "/Library/Frameworks/R.framework/Resources",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.2",
    "major": 4,
    "minor": 2,
    "patch": 2,
    "prerelease": [],
    "build": [],
    "version": "4.2.2"
  },
  "version": "4.2.2",
  "arch": "x86_64",
  "current": true,
  "orthogonal": false
}
2024-07-02 13:08:30.449 [info] Candidate R binary at /Library/Frameworks/R.framework/Versions/3.0/Resources/bin/R
2024-07-02 13:08:30.449 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "/Library/Frameworks/R.framework/Versions/3.0/Resources/bin/R",
  "homepath": "/Library/Frameworks/R.framework/Resources",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.2",
    "major": 4,
    "minor": 2,
    "patch": 2,
    "prerelease": [],
    "build": [],
    "version": "4.2.2"
  },
  "version": "4.2.2",
  "arch": "x86_64",
  "current": false,
  "orthogonal": false
}
2024-07-02 13:08:30.449 [info] Candidate R binary at /Library/Frameworks/R.framework/Versions/3.3/Resources/bin/R
2024-07-02 13:08:30.449 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "/Library/Frameworks/R.framework/Versions/3.3/Resources/bin/R",
  "homepath": "/Library/Frameworks/R.framework/Resources",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.2",
    "major": 4,
    "minor": 2,
    "patch": 2,
    "prerelease": [],
    "build": [],
    "version": "4.2.2"
  },
  "version": "4.2.2",
  "arch": "x86_64",
  "current": false,
  "orthogonal": false
}
2024-07-02 13:08:30.449 [info] Candidate R binary at /Library/Frameworks/R.framework/Versions/3.6/Resources/bin/R
2024-07-02 13:08:30.449 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "/Library/Frameworks/R.framework/Versions/3.6/Resources/bin/R",
  "homepath": "/Library/Frameworks/R.framework/Resources",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.2",
    "major": 4,
    "minor": 2,
    "patch": 2,
    "prerelease": [],
    "build": [],
    "version": "4.2.2"
  },
  "version": "4.2.2",
  "arch": "x86_64",
  "current": false,
  "orthogonal": false
}
2024-07-02 13:08:30.449 [info] Filtering out /Library/Frameworks/R.framework/Versions/3.0/Resources/bin/R: not current and also not orthogonal.
2024-07-02 13:08:30.449 [info] Filtering out /Library/Frameworks/R.framework/Versions/3.3/Resources/bin/R: not current and also not orthogonal.
2024-07-02 13:08:30.449 [info] Filtering out /Library/Frameworks/R.framework/Versions/3.6/Resources/bin/R: not current and also not orthogonal.
DavisVaughan commented 3 months ago

@zajichek that looks different but the Console log there is great, thanks, I've extracted into https://github.com/posit-dev/positron/issues/3812

BorgeJorge commented 3 months ago

FWIW, I just reopened Positron and noticed that this time there was one additional line in the Console: R 4.4.1 output channel log, the third line from the bottom, containing setConsoleWidth:

2024-07-03 01:01:20.631 [info] [Positron] Connecting to R 4.4.1 kernel (pid 10068)
2024-07-03 01:01:20.631 [info] [Positron] Streaming log file: C:\Users\MIJANT~1\AppData\Local\Temp\kernel-xgk3kg\kernel.log
2024-07-03 01:01:20.631 [info] [Positron] Connecting to kernel sockets defined in C:\Users\MIJANT~1\AppData\Local\Temp\kernel-xgk3kg\connection.json...
2024-07-03 01:01:20.631 [info] [Positron] Control socket created (count = 1)
2024-07-03 01:01:20.631 [info] [Positron] Shell socket created (count = 2)
2024-07-03 01:01:20.631 [info] [Positron] Stdin socket created (count = 3)
2024-07-03 01:01:20.631 [info] [Positron] I/O socket created (count = 4)
2024-07-03 01:01:20.633 [info] [Positron] Heartbeat socket created (count = 5)
2024-07-03 01:01:20.633 [info] [Positron] Control socket connecting to tcp://127.0.0.1:62865...
2024-07-03 01:01:20.633 [info] [Positron] Shell socket connecting to tcp://127.0.0.1:56999...
2024-07-03 01:01:20.633 [info] [Positron] Stdin socket connecting to tcp://127.0.0.1:50390...
2024-07-03 01:01:20.633 [info] [Positron] I/O socket connecting to tcp://127.0.0.1:43363...
2024-07-03 01:01:20.633 [info] [Positron] Heartbeat socket connecting to tcp://127.0.0.1:62889...
[Positron] Error setting console width: Cannot invoke 'setConsoleWidth'; no UI comm is open. (undefined)
[Positron] R 4.4.1 failed to start; exit code: 1
[Positron] R kernel status changed: starting => exited

Not big news since I saw this before in the physical log file, but it's curious that it decides to show up here now. The Positron R Extension output channel log remains the same.

EKtheSage commented 2 months ago

Hello,

I think I have similar issue but my exit code is 5. I tried using different versions of R (4.4.0, 4.3.1 but saw the same error starting R.

R 4.4.0 starting.
Error: Socket connect timed out after 20 seconds
"c:\Program Files\Positron\resources\app\extensions\positron-r\resources\ark\ark.exe" --connection_file 
C:\Users\ETHANK~1\AppData\Local\Temp\kernel-njumcq\connection.json --log 
C:\Users\ETHANK~1\AppData\Local\Temp\kernel-njumcq\kernel.log --startup-file 
"c:\Program Files\Positron\resources\app\extensions\positron-r\resources\scripts\startup.R" --session-mode console -- --interactive --no-restore-data 
Process exit code 5 

Output of Positron R Extension:

2024-07-12 00:02:48.618 [info] Log level: Debug
2024-07-12 00:02:48.618 [info] Refreshing testthat status
2024-07-12 00:02:48.643 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-12 00:02:48.648 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-12 00:02:48.649 [info] Not working in an R package
2024-07-12 00:02:48.649 [info] Context key 'testthatIsConfigured' is 'false'
2024-07-12 00:02:48.649 [info] Context key 'testthatHasTests' is 'false'
2024-07-12 00:02:48.675 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 00:02:48.698 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-12 00:02:49.285 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 00:02:49.307 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-12 00:02:49.307 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 00:02:49.311 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-12 00:02:53.356 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 00:02:53.360 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-12 00:02:53.360 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.0\bin\x64\R.exe
2024-07-12 00:02:53.373 [info] Candidate R binary at C:\Program Files\R\R-4.4.0\bin\x64\R.exe
2024-07-12 00:02:53.373 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.0\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.0",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.0",
    "major": 4,
    "minor": 4,
    "patch": 0,
    "prerelease": [],
    "build": [],
    "version": "4.4.0"
  },
  "version": "4.4.0",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-12 00:02:53.428 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.0\bin\x64\R.exe
2024-07-12 00:02:53.455 [info] Candidate R binary at C:\Program Files\R\R-4.4.0\bin\x64\R.exe
2024-07-12 00:02:53.455 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.0\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.0",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.0",
    "major": 4,
    "minor": 4,
    "patch": 0,
    "prerelease": [],
    "build": [],
    "version": "4.4.0"
  },
  "version": "4.4.0",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-12 00:02:53.455 [info] Candidate R binary at C:\Program Files\R\R-4.2.2\bin\x64\R.exe
2024-07-12 00:02:53.455 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.2.2\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.2.2",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.2.2",
    "major": 4,
    "minor": 2,
    "patch": 2,
    "prerelease": [],
    "build": [],
    "version": "4.2.2"
  },
  "version": "4.2.2",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
2024-07-12 00:02:53.455 [info] Candidate R binary at C:\Program Files\R\R-4.3.1\bin\x64\R.exe
2024-07-12 00:02:53.455 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.3.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.3.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.3.1",
    "major": 4,
    "minor": 3,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.3.1"
  },
  "version": "4.3.1",
  "arch": "x86_64",
  "current": false,
  "orthogonal": true
}
EKtheSage commented 2 months ago

The issue happened in the latest Posit version 2024.07.0-41, switching to version 2024.06.1-54 works. Below is the output of Positron R Extension using version 2024.06.1-54

2024-07-12 14:16:37.941 [info] Log level: Debug
2024-07-12 14:16:37.941 [info] Refreshing testthat status
2024-07-12 14:16:37.941 [info] Not working in an R package
2024-07-12 14:16:37.941 [info] Context key 'testthatIsConfigured' is 'false'
2024-07-12 14:16:37.941 [info] Context key 'testthatHasTests' is 'false'
2024-07-12 14:16:37.972 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-12 14:16:37.982 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-12 14:16:38.019 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:16:38.033 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-12 14:16:38.034 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:16:38.042 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-12 14:16:38.071 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:16:38.098 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-12 14:16:38.107 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:16:38.111 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-12 14:16:38.217 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:16:38.217 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:16:38.218 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.1",
    "major": 4,
    "minor": 4,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.4.1"
  },
  "version": "4.4.1",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-12 14:16:38.218 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:16:38.218 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:16:38.218 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.1",
    "major": 4,
    "minor": 4,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.4.1"
  },
  "version": "4.4.1",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-12 14:16:47.934 [info] Creating Positron R 4.4.1 language client (port 60118)
2024-07-12 14:16:47.934 [info] ARK (R 4.4.1) language client state changed uninitialized => starting
2024-07-12 14:16:47.990 [info] ARK (R 4.4.1) language client init successful
2024-07-12 14:16:47.990 [info] ARK (R 4.4.1) language client state changed starting => running
2024-07-12 14:19:07.707 [info] Log level: Debug
2024-07-12 14:19:07.707 [info] Refreshing testthat status
2024-07-12 14:19:07.714 [info] Not working in an R package
2024-07-12 14:19:07.714 [info] Context key 'testthatIsConfigured' is 'false'
2024-07-12 14:19:07.714 [info] Context key 'testthatHasTests' is 'false'
2024-07-12 14:19:08.951 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-12 14:19:08.965 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-07-12 14:19:09.017 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:19:09.030 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-12 14:19:09.030 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:19:09.036 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU
2024-07-12 14:19:09.092 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:19:09.106 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-12 14:19:09.107 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
2024-07-12 14:19:09.113 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM
2024-07-12 14:19:09.158 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:19:09.160 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:19:09.160 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.1",
    "major": 4,
    "minor": 4,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.4.1"
  },
  "version": "4.4.1",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-12 14:19:09.161 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:19:09.161 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe
2024-07-12 14:19:09.161 [info] R installation discovered: {
  "valid": true,
  "supported": true,
  "binpath": "C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe",
  "homepath": "C:\\Program Files\\R\\R-4.4.1",
  "semVersion": {
    "options": {},
    "loose": false,
    "includePrerelease": false,
    "raw": "4.4.1",
    "major": 4,
    "minor": 4,
    "patch": 1,
    "prerelease": [],
    "build": [],
    "version": "4.4.1"
  },
  "version": "4.4.1",
  "arch": "x86_64",
  "current": true,
  "orthogonal": true
}
2024-07-12 14:19:10.935 [info] Creating Positron R 4.4.1 language client (port 59746)
2024-07-12 14:19:10.935 [info] ARK (R 4.4.1) language client state changed uninitialized => starting
2024-07-12 14:19:10.988 [info] ARK (R 4.4.1) language client init successful
2024-07-12 14:19:10.988 [info] ARK (R 4.4.1) language client state changed starting => running
2024-07-12 14:20:19.049 [info] ARK (R 4.4.1) language client state changed running => stopped
2024-07-12 14:20:22.478 [info] Creating Positron R 4.4.1 language client (port 55287)
2024-07-12 14:20:22.478 [info] ARK (R 4.4.1) language client state changed stopped => starting
2024-07-12 14:20:22.851 [info] ARK (R 4.4.1) language client init successful
2024-07-12 14:20:22.851 [info] ARK (R 4.4.1) language client state changed starting => running
2024-07-12 14:48:16.250 [warning] ARK (R 4.4.1) language client error occurred (port 55287). 'Error' with message: read ECONNRESET. This is error number undefined.
2024-07-12 14:48:16.250 [warning] ARK (R 4.4.1) language client error occurred (port 55287). 'Error' with message: read ECONNRESET. This is error number undefined.
2024-07-12 14:48:16.250 [info] ARK (R 4.4.1) language client state changed running => stopped
2024-07-12 14:48:16.279 [warning] ARK (R 4.4.1) language client error occurred (port 55287). 'Error' with message: Cannot call write after a stream was destroyed. This is error number 1.
2024-07-12 14:48:23.252 [info] Creating Positron R 4.4.1 language client (port 55722)
2024-07-12 14:48:23.252 [info] ARK (R 4.4.1) language client state changed uninitialized => starting
2024-07-12 14:48:24.160 [info] ARK (R 4.4.1) language client init successful
2024-07-12 14:48:24.160 [info] ARK (R 4.4.1) language client state changed starting => running
IsoRatio commented 2 months ago

Any new updates? I had the same issue with latest 2024.07.0-67. Positron R Extension output below:

2024-07-18 10:37:54.681 [info] Log level: Debug 2024-07-18 10:37:54.681 [info] Refreshing testthat status 2024-07-18 10:37:54.681 [info] Not working in an R package 2024-07-18 10:37:54.681 [info] Context key 'testthatIsConfigured' is 'false' 2024-07-18 10:37:54.681 [info] Context key 'testthatHasTests' is 'false' 2024-07-18 10:37:54.732 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU 2024-07-18 10:37:54.736 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU 2024-07-18 10:37:54.785 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value. 2024-07-18 10:37:54.797 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU 2024-07-18 10:37:54.803 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value. 2024-07-18 10:37:54.807 [info] Checking for 'InstallPath' in registry key \Software\WOW6432Node\R-Core\R64 for hive HKCU 2024-07-18 10:37:54.852 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value. 2024-07-18 10:37:54.864 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM 2024-07-18 10:37:54.885 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value. 2024-07-18 10:37:54.889 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKLM 2024-07-18 10:37:55.064 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe 2024-07-18 10:37:55.065 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe 2024-07-18 10:37:55.065 [info] R installation discovered: { "valid": true, "supported": true, "binpath": "C:\Program Files\R\R-4.4.1\bin\x64\R.exe", "homepath": "C:\Program Files\R\R-4.4.1", "semVersion": { "options": {}, "loose": false, "includePrerelease": false, "raw": "4.4.1", "major": 4, "minor": 4, "patch": 1, "prerelease": [], "build": [], "version": "4.4.1" }, "version": "4.4.1", "arch": "x86_64", "current": true, "orthogonal": true } 2024-07-18 10:37:55.065 [info] Candidate R binary at C:\Program Files\R\R-4.3.0\bin\x64\R.exe 2024-07-18 10:37:55.065 [info] R installation discovered: { "valid": true, "supported": true, "binpath": "C:\Program Files\R\R-4.3.0\bin\x64\R.exe", "homepath": "C:\Program Files\R\R-4.3.0", "semVersion": { "options": {}, "loose": false, "includePrerelease": false, "raw": "4.3.0", "major": 4, "minor": 3, "patch": 0, "prerelease": [], "build": [], "version": "4.3.0" }, "version": "4.3.0", "arch": "x86_64", "current": false, "orthogonal": true } 2024-07-18 10:37:55.066 [info] Identified the current version of R from the registry: C:\Program Files\R\R-4.4.1\bin\x64\R.exe 2024-07-18 10:37:55.067 [info] Candidate R binary at C:\Program Files\R\R-4.4.1\bin\x64\R.exe 2024-07-18 10:37:55.067 [info] R installation discovered: { "valid": true, "supported": true, "binpath": "C:\Program Files\R\R-4.4.1\bin\x64\R.exe", "homepath": "C:\Program Files\R\R-4.4.1", "semVersion": { "options": {}, "loose": false, "includePrerelease": false, "raw": "4.4.1", "major": 4, "minor": 4, "patch": 1, "prerelease": [], "build": [], "version": "4.4.1" }, "version": "4.4.1", "arch": "x86_64", "current": true, "orthogonal": true }

jmcphers commented 2 months ago

Thanks all for these reports! Unfortunately we haven't been able to reproduce this internally. Some more diagnostics that would be helpful:

In the Console: R X.Y.Z output channel, you'll see a line like this one:

[Positron] Streaming log file: C:\Users\MIJANT~1\AppData\Local\Temp\kernel-xgk3kg\kernel.log

Can you send the contents of that file, if it isn't empty?

There's also an output channel called Jupyter Adapter. What do you see in there, if anything?

Is there any antivirus/malware software on your machine? If so, can you check its logs for references to kernel-wrapper or ark.exe?

BorgeJorge commented 2 months ago

Unfortunately my kernel.log is empty. The Jupyter Adapter output channel contains the following:

Jupyter Adapter extension activated
Created session r-efab108c:  for kernel {"extensionId":{"value":"vscode.positron-r","_lower":"vscode.positron-r"},"runtimeId":"912077798d99e95f382c96e6337fbb96","runtimeName":"R 4.4.1","runtimeShortName":"4.4.1","runtimePath":"C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe","runtimeVersion":"0.0.2","runtimeSource":"System","languageId":"r","languageName":"R","languageVersion":"4.4.1","base64EncodedIconSvg":"PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4NCjxzdmcgaWQ9IkxheWVyXzEiIGRhdGEtbmFtZT0iTGF5ZXIgMSIgeG1sbnM9Imh0dHA6Ly93d3cudzMub3JnLzIwMDAvc3ZnIiB4bWxuczp4bGluaz0iaHR0cDovL3d3dy53My5vcmcvMTk5OS94bGluayIgdmlld0JveD0iMCAwIDEwMCAxMDAiPg0KICA8ZGVmcz4NCiAgICA8bGluZWFyR3JhZGllbnQgaWQ9ImxpbmVhci1ncmFkaWVudCIgeDE9Ii00OC45MyIgeTE9IjE1MC44OCIgeDI9Ii00OC44IiB5Mj0iMTUwLjc0IiBncmFkaWVudFRyYW5zZm9ybT0idHJhbnNsYXRlKDM1Mjg1LjUxIDcyODc3LjQ5KSBzY2FsZSg3MjEuMDkgLTQ4Mi45NCkiIGdyYWRpZW50VW5pdHM9InVzZXJTcGFjZU9uVXNlIj4NCiAgICAgIDxzdG9wIG9mZnNldD0iMCIgc3RvcC1jb2xvcj0iI2NjY2VkMCIvPg0KICAgICAgPHN0b3Agb2Zmc2V0PSIxIiBzdG9wLWNvbG9yPSIjODU4NDhjIi8+DQogICAgPC9saW5lYXJHcmFkaWVudD4NCiAgICA8bGluZWFyR3JhZGllbnQgaWQ9ImxpbmVhci1ncmFkaWVudC0yIiB4MT0iLTQ5LjUzIiB5MT0iMTUxLjE3IiB4Mj0iLTQ5LjM5IiB5Mj0iMTUxLjAzIiBncmFkaWVudFRyYW5zZm9ybT0idHJhbnNsYXRlKDE5NzUxIDYxNDI4LjY3KSBzY2FsZSgzOTggLTQwNi4xMikiIGdyYWRpZW50VW5pdHM9InVzZXJTcGFjZU9uVXNlIj4NCiAgICAgIDxzdG9wIG9mZnNldD0iMCIgc3RvcC1jb2xvcj0iIzMzNmRiNiIvPg0KICAgICAgPHN0b3Agb2Zmc2V0PSIxIiBzdG9wLWNvbG9yPSIjMWM1ZWFhIi8+DQogICAgPC9saW5lYXJHcmFkaWVudD4NCiAgPC9kZWZzPg0KICA8cGF0aCBkPSJtNTAsNzcuOTVDMjIuODQsNzcuOTUuODEsNjMuMjEuODEsNDUuMDFTMjIuODQsMTIuMDcsNTAsMTIuMDdzNDkuMTksMTQuNzUsNDkuMTksMzIuOTQtMjIuMDIsMzIuOTQtNDkuMTksMzIuOTRabTcuNTMtNTNjLTIwLjY1LDAtMzcuMzksMTAuMDgtMzcuMzksMjIuNTJzMTYuNzQsMjIuNTIsMzcuMzksMjIuNTIsMzUuODgtNi44OSwzNS44OC0yMi41Mi0xNS4yNC0yMi41Mi0zNS44OC0yMi41MloiIHN0eWxlPSJmaWxsOiB1cmwoI2xpbmVhci1ncmFkaWVudCk7IGZpbGwtcnVsZTogZXZlbm9kZDsiLz4NCiAgPHBhdGggZD0ibTc1LjcyLDYzLjA5czIuOTguOSw0LjcxLDEuNzdjLjYuMywxLjY0LjkxLDIuMzksMS43MS43My43OCwxLjA5LDEuNTcsMS4wOSwxLjU3bDExLjczLDE5Ljc4aC0xOC45NnMtOC44Ny0xNi42NC04Ljg3LTE2LjY0YzAsMC0xLjgyLTMuMTItMi45My00LjAyLS45My0uNzUtMS4zMy0xLjAyLTIuMjUtMS4wMmgtNC41MXYyMS42OXMtMTYuNzgsMC0xNi43OCwwdi01NS40aDMzLjdzMTUuMzUuMjgsMTUuMzUsMTQuODgtMTQuNjcsMTUuNjktMTQuNjcsMTUuNjlabS03LjMtMTguNTVoLTEwLjE2czAsOS40MSwwLDkuNDFoMTAuMTZzNC43MS0uMDIsNC43MS00LjgtNC43MS00LjYyLTQuNzEtNC42MloiIHN0eWxlPSJmaWxsOiB1cmwoI2xpbmVhci1ncmFkaWVudC0yKTsgZmlsbC1ydWxlOiBldmVub2RkOyIvPg0KPC9zdmc+","sessionLocation":"workspace","startupBehavior":"immediate","extraRuntimeData":{"homepath":"C:\\Program Files\\R\\R-4.4.1","binpath":"C:\\Program Files\\R\\R-4.4.1\\bin\\x64\\R.exe","current":false}}
R kernel status changed: uninitialized => initializing
R kernel status changed: initializing => starting
Starting R 4.4.1 kernel: c:\Program Files\Positron\resources\app\extensions\positron-r\resources\ark\ark.exe --connection_file C:\Users\MIJANT~1\AppData\Local\Temp\2\kernel-iWk9kH\connection.json --log C:\Users\MIJANT~1\AppData\Local\Temp\2\kernel-iWk9kH\kernel.log --startup-file c:\Program Files\Positron\resources\app\extensions\positron-r\resources\scripts\startup.R --session-mode console -- --interactive --no-restore-data...
Environment: {"RUST_BACKTRACE":"1","RUST_LOG":"warn,ark=warn","R_HOME":"C:\\Program Files\\R\\R-4.4.1","RSTUDIO_PANDOC":"c:\\Program Files\\Positron\\bin\\pandoc"}

My "machine" is actually a CyberArk virtual machine that I access remotely, and which has centrally managed antivirus software. I'll try to get the admin person to check the log for those references.

Thanks!

juliasilge commented 2 months ago

Seems like a similar problem here: https://forum.posit.co/t/in-positron-how-can-i-get-the-r-terminal-to-work/189806

juliasilge commented 2 months ago

There are some interesting logs posted here now from the above ⤴️ person: https://forum.posit.co/t/in-positron-how-can-i-get-the-r-terminal-to-work/189806/3?u=julia

In the Positron R Extension output:

2024-08-06 15:51:33.330 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-08-06 15:51:33.569 [info] Checking for 'InstallPath' in registry key \Software\R-Core\R64 for hive HKCU
2024-08-06 15:51:37.677 [info] Unable to get value of 'InstallPath': QUERY command exited with code 1:

ERROR: The system was unable to find the specified registry key or value.
jennybc commented 2 months ago

In general, we expect to see a lot of ☝️ . We check lots of registry keys, most of which won't be defined. And the above is just the error that the registry-checking npm module throws when you look for a key that's not there.

jennybc commented 2 months ago

So I this is normal in a Windows log from the R discovery phase and doesn't explain why a discovered R would not start up.

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.

Image

Image

What do you see there? 👀

BorgeJorge commented 1 month ago

Thanks Julia. I followed your steps, and I also selected the terminal window so that it displays on bootup. Now when I boot up, for a split second I see what you see on the right (that is, I see two possible terminals listed, one for powershell and one for R 4.4.1). But an error window immediately pops up, obscuring my view of the terminal list:

image

When I close that small error window the terminal list has disappeared. And when I reopen the terminal list by clicking on the plus sign, I see:

image

Let me know if I can try anything else.

Thanks, Tod

juliasilge commented 1 month ago

Thank you for trying this out @BorgeJorge! With this setting still on "true", can you go to "Output" and choose "Terminal":

Screenshot 2024-08-22 at 11 34 39 AM

I'd like to see if we can get that log file to see if there are any clues. I think the easiest steps are:

terminal.log

BorgeJorge commented 1 month ago

Here you go!

terminal.log

jennybc commented 1 month ago

@BorgeJorge have you ever customized anything around the default settings for integrated terminals? I'm talking about "terminal.integrated.defaultProfile.windows" in your user settings.

BorgeJorge commented 1 month ago

I assume you mean File -> Preferences -> Settings -> User -> Features -> Terminal -> Integrated Default Profile: Windows? I have not, and it shows as null:

image

BorgeJorge commented 1 month ago

This is probably irrelevant but I'll mention it. I've noticed that since I installed Positron, I can no longer open R scripts or Quarto documents in RStudio by double clicking the file in Windows Explorer. This is true even though I've associated those file extensions with RStudio, and even when I explicitly select Open With -> RStudio from my right-click mouse menu. But of course this could be a spurious correlation.

jennybc commented 1 month ago

I have an experiment for you.

Would you (temporarily) set your integrated terminal to Command Prompt? That presumably is already the default and I see you are accepting the default. But your log file makes it seem like maybe the Jupyter adapter wrapper script is being executed by PowerShell nonetheless (???). It's worth a try! If this actually changes your experience, I would then change something on our end, i.e. this is just gathering more data for us. Definitely make this change, quit all instances of Positron, relaunch and see what happens.

To ensure that an integrated terminal in Positron defaults to cmd.exe (instead of PowerShell), follow these steps:

  1. Open Command Palette:

    • Press Ctrl+Shift+P on Windows.
  2. Select Default Profile:

    • Type Terminal: Select Default Profile and press Enter.
  3. Choose Command Prompt:

    • Ensure that Command Prompt (cmd.exe) is selected instead of PowerShell.

Alternatively, you can directly modify your settings.json file to set cmd.exe as the default shell:

Open Settings (JSON):

Press Ctrl+Shift+P and type Preferences: Open Settings (JSON). Add or Modify the Terminal Shell Setting:

{
    "terminal.integrated.defaultProfile.windows": "Command Prompt",
    "terminal.integrated.profiles.windows": {
        "Command Prompt": {
            "path": "C:\\Windows\\System32\\cmd.exe"
        }
    }
}
BorgeJorge commented 1 month ago

Thanks Jennifer. I reset the default terminal to the standard command prompt, and indeed I'm now seeing a more normal (non-Powershell) prompt in the terminal window, but R still fails to start up.

Happy to try other stuff, just let me know.

jennybc commented 1 month ago

Can you capture another terminal log, under these conditions, like the one above?

I'm referring to this: https://github.com/posit-dev/positron/issues/3788#issuecomment-2305419047

jennybc commented 1 month ago

From the log you already sent, I've homed in on this (I cleaned this up a bit):

'c:\Program' is not recognized as an internal or external command, operable program or batch file.

In my functioning Windows setup, the kernel wrapper launch looks like so:

Command line: c:\Program Files\Positron\resources\app\extensions\jupyter-adapter\resources\kernel-wrapper.bat 'D:\Users\jenny\AppData\Local\Temp\1\kernel-6OrCj4\kernel.log' 'c:\Program Files\Positron\resources\app\extensions\positron-r\resources\ark\ark.exe' '--connection_file' 'D:\Users\jenny\AppData\Local\Temp\1\kernel-6OrCj4\connection.json' '--log' 'D:\Users\jenny\AppData\Local\Temp\1\kernel-6OrCj4\kernel.log' '--startup-file' 'c:\Program Files\Positron\resources\app\extensions\positron-r\resources\scripts\startup.R' '--session-mode' 'console' '--' '--interactive' '--no-restore-data'

So I think this is what's failing, presumably due to the space in "Program Files".

From this document about troubleshooting problems with VS Code integrated terminals:

https://code.visualstudio.com/docs/supporting/troubleshoot-terminal-launch#_additional-troubleshooting-steps

If you're on Windows 10 1809 (build 17763) or below, the issue is related to the legacy "winpty" backend. Upgrading to Windows 1903 (build 18362) moves you onto the new "conpty" backend that is built by Microsoft and could fix your problem.

I asked Co-Pilot to elaborate on the sorts of problems one can see with the old winpty backed and it says:

In the provided code snippet from JupyterKernel.ts, you are creating a new terminal using the VS Code terminal API. The behavior of this terminal can be affected by the backend being used:

  • If you are on Windows 10 1809 or below:

    • The terminal will use the "winpty" backend.
    • You might encounter issues with paths containing spaces or special characters. Quoting paths and arguments correctly is crucial to avoid these issues.
  • If you are on Windows 10 1903 or above:

    • The terminal will use the "conpty" backend.
    • This backend handles paths with spaces and quoting more gracefully.You are less likely to encounter issues related to terminal behavior.

From @BorgeJorge very first post, I see Windows_NT x64 10.0.14393 which Co-Pilot describes like so:

The version "Windows_NT x64 10.0.14393" corresponds to Windows 10, specifically the Anniversary Update (version 1607). This version was released in August 2016.

So I am beginning to think this really old version of Windows could be the problem. We can perhaps still take more care with quoting (I have some ideas), but I think the root cause might be the Windows version.

BorgeJorge commented 1 month ago

Great detective work, Jenny! I am indeed on a very old version of Windows Server 2016:

image

Unfortunately I'm probably wedded to this Windows version, since I work on a CyberArk virtual machine in an educational environment. But I really appreciate now knowing what's going on.

Thank you!

jennybc commented 1 month ago

I'm going to create a draft solution and somehow get a release build for you to try @BorgeJorge. Probably not today, but soon.

jennybc commented 1 month ago

I still plan to make (what I hope is) a simple change that would help here and should be neutral-to-positive overall.

But when discussing this issue in a meeting today, I was reminded that Posit has some general policies on support that are relevant. Basically, once an OS is past its end-of-life (not counting extensions that require paid plans from the vendor), we generally don't support it.

The general policy: https://posit.co/about/platform-support/

The Windows version we're talking about here (Windows Server 2016) reached its end-of-life (for mainstream support) in 2022:

https://learn.microsoft.com/en-us/lifecycle/products/windows-server-2016

BorgeJorge commented 1 month ago

Thanks for letting me know Jenny, that certainly makes sense. And I really appreciate all the effort you put in to identify the problem. Apologies for my OS being stuck in the prior decade!

jennybc commented 3 weeks ago

I'm closing this as #wontfix. In the PR linked above, I tried a simple fix (quoting the path to the wrapper script that launches Jupyter kernels), but this appears to break things in modern Windows. I have no idea if this would help on these very old Windows machines, but it really doesn't matter.

We've clearly established that Windows 10 1809 (build 17763) or below is incompatible with current VS Code terminals, which is critical for Positron. The affected Windows versions are past their end-of-life.