I'm trying to install the Open Source Rstudio Server on a Redhat 8 Linux system. I've used
rstudio-server-rhel-2023.12.1-402-x86_64.rpm downloaded from Posit. The Linux system has full workstation capabilities and I can run Firefox on it with no problems. In addition, I've configured the Linux system's firewall to allow connections on port 8787.
Using Firefox on this system, Rstudio server works fine. It authenticates using our Active Directory system as expected and I can successfully run R code.
However, when I try to use Rstudio server from a Windows laptop using either Edge or Chrome, I can login successfully, but then after a short delay, I get this error display:
i.e. "R is taking longer to start than usual".
I've used 'strace' to monitor system calls on the rserver process and there is a difference between a successful connection and an unsuccessful one: there is no attempt to access my home directory in the unsuccessful connection, nor is a subprocess started to run rsession.
I've enabled 'debug' logging using logging.conf and apparently the Rstudio server is not initiating RPC calls when the connection attempt fails, although I don't understand the log messages. For a successful connection, these are the log messages around the time of the successful connection and initiation of the session: (cookies were erased)
2024-03-15T19:54:42.053105Z [rserver] DEBUG PAM login start - running: /usr/lib/rstudio-server/bin/rserver-pam rbruccoler rstudio 1
2024-03-15T19:54:43.650404Z [rserver] DEBUG PAM login result: for username: rbruccoler returns: authenticated
2024-03-15T19:54:43.651708Z [rserver] DEBUG User db query start: rbruccoler
2024-03-15T19:54:43.653819Z [rserver] DEBUG Found user in db: rbruccoler
2024-03-15T19:54:43.654959Z [rserver] DEBUG Begin update last signIn time
2024-03-15T19:54:43.656133Z [rserver] DEBUG End update last signIn time
2024-03-15T19:54:43.671991Z [rserver] DEBUG Adding session cookie: rbruccoler|XXXXX for user: rbruccoler
2024-03-15T19:54:43.673499Z [rserver] DEBUG Sign in for user: rbruccoler redirecting to: /
2024-03-15T19:54:46.568087Z [rserver] DEBUG - Start server proxy request POST /rpc/client_init (rbruccoler:40) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:54:46.577652Z [rserver] DEBUG Launching session for user: rbruccoler id:
2024-03-15T19:54:46.580202Z [rserver] DEBUG Launching RStudio session for: rbruccoler id:
2024-03-15T19:54:46.582421Z [rserver] DEBUG Launched session process for user: rbruccoler: /usr/lib/rstudio-server/bin/rsession pid: 2235153
2024-03-15T19:54:46.874268Z [rserver] ERROR system error 13 (Permission denied) [host: localhost:8787, uri: /rpc/client_init, path: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d, user-id: 1985484955, request-uri: /rpc/client_init]; OCCURRED AT void rstudio::core::http::LocalStreamAsyncClient::handleConnect(const rstudio_boost::system::error_code&) src/cpp/server/session/ServerSessionProxy.cpp:124; LOGGED FROM: void rstudio::server::session_proxy::{anonymous}::logIfNotConnectionTerminated(const rstudio::core::Error&, const rstudio::core::http::Request&) src/cpp/server/session/ServerSessionProxy.cpp:513
2024-03-15T19:54:46.881437Z [rserver] DEBUG -- rpc error: other error for: /rpc/client_init (rbruccoler:40) in 0.313s error: system error 13 (Permission denied)
2024-03-15T19:54:47.894709Z [rserver] DEBUG - Start server proxy request POST /rpc/client_init (rbruccoler:41) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:54:49.298615Z [rserver] DEBUG -- sent server proxy response for: /rpc/client_init (rbruccoler:41) in 1.404s id:: 200 93258b
2024-03-15T19:54:49.321757Z [rserver] DEBUG - Start server proxy request GET /mathjax/MathJax.js?config=TeX-MML-AM_CHTML (rbruccoler:42) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:54:49.329785Z [rserver] DEBUG - Start server proxy request POST /rpc/set_user_state (rbruccoler:43) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:24.393585Z [rserver] DEBUG -- sent server proxy response for: /mathjax/MathJax.js?config=TeX-MML-AM_CHTML (rbruccoler:42) in 35.72s id:: 304 0b
2024-03-15T19:55:24.493259Z [rserver] DEBUG Refreshing auth: replacing old cookie: rbruccoler|XXXXXX
2024-03-15T19:55:24.498374Z [rserver] DEBUG Adding session cookie: rbruccoler|XXXXXX for user: rbruccoler
2024-03-15T19:55:24.511165Z [rserver] DEBUG - Start server proxy request GET /mathjax/config/TeX-MML-AM_CHTML.js?V=2.7.6 (rbruccoler:44) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:24.762744Z [rserver] DEBUG -- sent server proxy response for: /rpc/set_user_state (rbruccoler:43) in 35.433s id:: 200 48b
2024-03-15T19:55:24.814083Z [rserver] DEBUG - Start server proxy request POST /rpc/set_user_prefs (rbruccoler:45) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.142358Z [rserver] DEBUG -- sent server proxy response for: /mathjax/config/TeX-MML-AM_CHTML.js?V=2.7.6 (rbruccoler:44) in 0.650s id:: 304 0b
2024-03-15T19:55:25.277909Z [rserver] DEBUG -- sent server proxy response for: /rpc/set_user_prefs (rbruccoler:45) in 0.464s id:: 200 48b
2024-03-15T19:55:25.355594Z [rserver] DEBUG - Start server proxy request GET /mathjax/jax/output/HTML-CSS/config.js?V=2.7.6 (rbruccoler:46) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.357886Z [rserver] DEBUG - Start server proxy request GET /theme/default/textmate.rstheme?dark=0&refresh=1 (rbruccoler:47) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.358954Z [rserver] DEBUG - Start server proxy request POST /rpc/get_rversion_info (rbruccoler:48) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.523025Z [rserver] DEBUG - Start server proxy request POST /rpc/get_rversion_info (rbruccoler:49) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.525830Z [rserver] DEBUG - Start server proxy request POST /rpc/get_rversion_info (rbruccoler:50) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.739752Z [rserver] DEBUG - Start server proxy request POST /rpc/discover_package_dependencies (rbruccoler:51) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:25.957504Z [rserver] DEBUG -- sent server proxy response for: /mathjax/jax/output/HTML-CSS/config.js?V=2.7.6 (rbruccoler:46) in 0.616s id:: 304 0b
2024-03-15T19:55:25.965957Z [rserver] DEBUG - Start server proxy request POST /rpc/discover_package_dependencies (rbruccoler:52) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:26.769344Z [rserver] DEBUG -- sent server proxy response for: /theme/default/textmate.rstheme?dark=0&refresh=1 (rbruccoler:47) in 1.412s id:: 304 0b
2024-03-15T19:55:26.771452Z [rserver] DEBUG - Start server proxy request POST /rpc/check_for_external_edit (rbruccoler:53) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:27.372032Z [rserver] DEBUG -- sent server proxy response for: /rpc/get_rversion_info (rbruccoler:48) in 2.13s id:: 200 121b
2024-03-15T19:55:27.374481Z [rserver] DEBUG - Start server proxy request POST /rpc/get_project_template_registry (rbruccoler:54) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:27.431441Z [rserver] DEBUG -- sent server proxy response for: /rpc/get_rversion_info (rbruccoler:49) in 1.908s id:: 200 121b
2024-03-15T19:55:27.437722Z [rserver] DEBUG - Start server proxy request POST /rpc/get_environment_state (rbruccoler:56) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:27.660339Z [rserver] DEBUG -- sent server proxy response for: /rpc/get_rversion_info (rbruccoler:50) in 2.134s id:: 200 121b
2024-03-15T19:55:27.666898Z [rserver] DEBUG - Start server proxy request POST /rpc/process_notify_visible (rbruccoler:57) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:28.017801Z [rserver] DEBUG -- sent server proxy response for: /rpc/discover_package_dependencies (rbruccoler:51) in 2.457s id:: 200 68b
2024-03-15T19:55:28.107601Z [rserver] DEBUG - Start server proxy request POST /rpc/read_config_json (rbruccoler:58) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:28.174449Z [rserver] DEBUG -- sent server proxy response for: /rpc/discover_package_dependencies (rbruccoler:52) in 2.208s id:: 200 68b
2024-03-15T19:55:28.186176Z [rserver] DEBUG - Start server proxy request POST /rpc/read_config_json (rbruccoler:59) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:28.618494Z [rserver] DEBUG -- sent server proxy response for: /rpc/check_for_external_edit (rbruccoler:53) in 1.847s id:: 200 67b
2024-03-15T19:55:28.624497Z [rserver] DEBUG - Start server proxy request POST /rpc/read_config_json (rbruccoler:60) for local stream: /var/run/rstudio-server/rstudio-rsession/rbruccoler-d
2024-03-15T19:55:28.924780Z [rserver] DEBUG -- sent server proxy response for: /rpc/get_project_template_registry (rbruccoler:54) in 1.550s id:: 200 86b
For a failed connection, here's the log (cookies were erased):
2024-03-15T19:51:04.021658Z [rserver] DEBUG PAM login start - running: /usr/lib/rstudio-server/bin/rserver-pam rbruccoler rstudio 1
2024-03-15T19:51:04.603476Z [rserver] DEBUG PAM login result: for username: rbruccoler returns: authenticated
2024-03-15T19:51:04.604265Z [rserver] DEBUG User db query start: rbruccoler
2024-03-15T19:51:04.605228Z [rserver] DEBUG Found user in db: rbruccoler
2024-03-15T19:51:04.605825Z [rserver] DEBUG Begin update last signIn time
2024-03-15T19:51:04.606420Z [rserver] DEBUG End update last signIn time
2024-03-15T19:51:04.610967Z [rserver] DEBUG Created new UserSession for: rbruccoler (total: 1)
2024-03-15T19:51:04.611661Z [rserver] DEBUG User db query start: rbruccoler
2024-03-15T19:51:04.612390Z [rserver] DEBUG Found user in db: rbruccoler
2024-03-15T19:51:04.612957Z [rserver] DEBUG Adding session cookie: rbruccoler|XXXXXX for user: rbruccoler
2024-03-15T19:51:04.613594Z [rserver] DEBUG Sign in for user: rbruccoler redirecting to: /
I can successfully use Rstudio server from another Linux desktop system, and the Chromium browser running locally also works.
It appears that the difference starts when the server redirects to "/". For the laptop, nothing happens, but on the Linux desktop, the /rpc/client_init path works.
Any suggestions on what to try next would be greatly appreciated. Thank you. --Bob