search

atlas-engineer / nyxt

Nyxt - the hacker's browser.
https://nyxt-browser.com/
9.9k stars 412 forks source link

Startup failure on Guix when connecting via ssh #391

Closed khinsen closed 4 years ago

khinsen commented 5 years ago

Typing "next -v" into a shell window produces the following error message:

$ next -v
Arguments parsed: (VERBOSE T) and NIL
 <INFO> [12:56:45] next base.lisp (start) - NEXT:+VERSION+: "1.3.2"
 <INFO> [12:56:45] next base.lisp (load-lisp-file form-fun-4) -
  Loading configuration from /home/hinsen/.config/next/init.lisp...
 <INFO> [12:56:46] next remote.lisp (initialize-instance :after remote-interface) -
  D-Bus addresses: (#<Unix socket address: "NIL">)
Unhandled SIMPLE-ERROR in thread #<SB-THREAD:THREAD "Anonymous thread" RUNNING
                                    {10058B2EE3}>:
  No server addresses left to try to open.

Backtrace for: #<SB-THREAD:THREAD "Anonymous thread" RUNNING {10058B2EE3}>
0: (SB-DEBUG::DEBUGGER-DISABLED-HOOK #<SIMPLE-ERROR "No server addresses left to try to open." {10058BB613}> #<unused argument> :QUIT T)
1: (SB-DEBUG::RUN-HOOK *INVOKE-DEBUGGER-HOOK* #<SIMPLE-ERROR "No server addresses left to try to open." {10058BB613}>)
2: (INVOKE-DEBUGGER #<SIMPLE-ERROR "No server addresses left to try to open." {10058BB613}>)
3: (ERROR "No server addresses left to try to open.")
4: ((LAMBDA NIL :IN DBUS/PROTOCOLS:OPEN-CONNECTION))
5: (DBUS/CONVENIENCE::CALL-WITH-OPEN-BUS #<CLOSURE (LAMBDA (NEXT::BUS) :IN INITIALIZE-INSTANCE) {10058B8EFB}> #<event base, 0 FDs monitored, using: #<epoll(4) multiplexer> {10058A7523}> (#<DBUS/TRANSPORT-UNIX:UNIX-SERVER-ADDRESS {10058B8DB3}>))
6: ((LAMBDA NIL :IN INITIALIZE-INSTANCE))
7: ((LAMBDA NIL :IN BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS))
8: ((FLET SB-UNIX::BODY :IN SB-THREAD::NEW-LISP-THREAD-TRAMPOLINE))
9: ((FLET "WITHOUT-INTERRUPTS-BODY-4" :IN SB-THREAD::NEW-LISP-THREAD-TRAMPOLINE))
10: ((FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::NEW-LISP-THREAD-TRAMPOLINE))
11: ((FLET "WITHOUT-INTERRUPTS-BODY-1" :IN SB-THREAD::CALL-WITH-MUTEX))
12: (SB-THREAD::CALL-WITH-MUTEX #<CLOSURE (FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::NEW-LISP-THREAD-TRAMPOLINE) {7FC48737ED8B}> #<SB-THREAD:MUTEX "thread result lock" owner: #<SB-THREAD:THREAD "Anonymous thread" RUNNING {10058B2EE3}>> NIL T NIL)
13: (SB-THREAD::NEW-LISP-THREAD-TRAMPOLINE #<SB-THREAD:THREAD "Anonymous thread" RUNNING {10058B2EE3}> NIL #<CLOSURE (LAMBDA NIL :IN BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS) {10058B2E8B}> NIL)
14: ("foreign function: call_into_lisp")
15: ("foreign function: new_thread_trampoline")

unhandled condition in --disable-debugger mode, quitting

D-bus is running:

$ pgrep -lf dbus

276 dbus-daemon
350 dbus-daemon
363 dbus-daemon
917 dbus-daemon
932 dbus-daemon
942 dbus-daemon

Information

  guix dd2a832
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: dd2a83270bccb539439b2fc831d0db04e5276f11

None. I ssh into a headless virtual machine running Guix System.

1.3.2

Guix

jmercouris commented 5 years ago

Hi, thank you very much for your report! It seems that Next (the Common Lisp part) is unable to connect to D-Bus. Do you have a Common Lisp environment set-up would you be willing to run some test commands in a CL Repl?

Ambrevar commented 5 years ago

But is D-Bus running for your user? Can you report the output of

ps -U $USER | grep dbus

?

Master contains some fixes that could help auto-start dbus when needed. For Guix I thought this was fixed in 1.3.2.

khinsen commented 5 years ago

@Ambrevar Yes, D-Bus is running for my user:

$ ps -U $USER | grep dbus
  521 tty8     00:00:00 dbus-daemon
  533 tty8     00:00:00 dbus-daemon
  615 ?        00:00:00 dbus-daemon

@jmercouris No Lisp environment, sorry. I haven't used Common Lisp for a decade or so.

One more observation: If I start up my virtual machine with a display, I can run Next there. It's only when connecting via ssh that I get an error message. My X11 over ssh setup is working correctly, I use it all the time to run Emacs.

Ambrevar commented 5 years ago

Can you report the content of

~/.local/share/next/next-gtk-webkit.log

?

khinsen commented 5 years ago

@Ambrevar Sure, see below. But judging from the time stamps, it was created the one time I started Next successfully on the VM's display. I see no entries corresponding to my failed attempts to start Next via ssh.

** Message: 14:18:03.900: Starting platform port
** Message: 14:18:04.014: Method name: window_active
** Message: 14:18:04.014: Method parameter(s): <no active window>
** Message: 14:18:04.031: Method name: window_active
** Message: 14:18:04.031: Method parameter(s): <no active window>
** Message: 14:18:04.036: Method name: window_make
** Message: 14:18:04.036: Method parameter(s): 1
** Message: 14:18:04.237: Method result(s): window id 1
** Message: 14:18:04.347: Method name: buffer_make
** Message: 14:18:04.347: Method parameter(s): buffer ID 1, options {'cookies-path': '/home/hinsen/.local/share/next/cookies.txt'}
** Message: 14:18:04.409: Method result(s): buffer id 1
** Message: 14:18:04.520: Method name: window_active
** Message: 14:18:04.520: Method parameter(s): 1
** Message: 14:18:04.596: Method name: window_active
** Message: 14:18:04.596: Method parameter(s): 1
** Message: 14:18:04.645: Method name: minibuffer_evaluate_javascript
** Message: 14:18:04.645: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:04.645: Method result(s): callback id 0
** Message: 14:18:04.741: Method name: minibuffer_evaluate_javascript
** Message: 14:18:04.741: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:04.741: Method result(s): callback id 1
** Message: 14:18:04.775: Method name: window_set_minibuffer_height
** Message: 14:18:04.775: Method parameter(s): window id 1, minibuffer height 25
** Message: 14:18:04.775: Method result(s): minibuffer preferred height 0
** Message: 14:18:04.797: Method name: window_active
** Message: 14:18:04.797: Method parameter(s): 1
** Message: 14:18:04.807: Method name: window_active
** Message: 14:18:04.807: Method parameter(s): 1
** Message: 14:18:04.816: Method name: minibuffer_evaluate_javascript
** Message: 14:18:04.816: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:04.816: Method result(s): callback id 2
** Message: 14:18:04.830: Method name: minibuffer_evaluate_javascript
** Message: 14:18:04.830: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:04.830: Method result(s): callback id 3
** Message: 14:18:04.851: Method name: window_set_minibuffer_height
** Message: 14:18:04.851: Method parameter(s): window id 1, minibuffer height 25
** Message: 14:18:04.851: Method result(s): minibuffer preferred height 0
** Message: 14:18:04.876: Method name: buffer_evaluate_javascript
** Message: 14:18:04.876: Method parameter(s): buffer id 1, javascript (...)
** Message: 14:18:04.876: Method result(s): callback id 0
** Message: 14:18:04.893: Method name: window_active
** Message: 14:18:04.893: Method parameter(s): 1
** Message: 14:18:04.900: Method name: window_set_active_buffer
** Message: 14:18:04.900: Method parameter(s): window id 1, buffer id 1
** Message: 14:18:04.900: Window 1 switches from buffer (null) to 1 with URI (null)
** Message: 14:18:04.917: Method name: window_active
** Message: 14:18:04.917: Method parameter(s): 1
** Message: 14:18:04.933: Method name: buffer_evaluate_javascript
** Message: 14:18:04.933: Method parameter(s): buffer id 1, javascript (...)
** Message: 14:18:04.933: Method result(s): callback id 1
** Message: 14:18:04.942: Method name: window_set_active_buffer
** Message: 14:18:04.942: Method parameter(s): window id 1, buffer id 1
** Message: 14:18:04.942: Window 1 switches from buffer 1 to 1 with URI (null)
** Message: 14:18:04.964: Method name: window_active
** Message: 14:18:04.964: Method parameter(s): 1
** Message: 14:18:04.972: Method name: buffer_evaluate_javascript
** Message: 14:18:04.972: Method parameter(s): buffer id 1, javascript (...)
** Message: 14:18:04.972: Method result(s): callback id 2
** Message: 14:18:05.153: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 0)
** Message: 14:18:05.169: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 1)
** Message: 14:18:05.171: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 2)
** Message: 14:18:05.173: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 3)
failed to create drawable
** Message: 14:18:05.904: RPC message: buffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 0)
** Message: 14:18:06.007: RPC message: buffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 1)
** Message: 14:18:06.009: RPC message: buffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 2)
** Message: 14:18:06.022: Method name: window_set_title
** Message: 14:18:06.022: Method parameter(s): 1, Next - *Help*
** Message: 14:18:06.056: Method name: window_set_title
** Message: 14:18:06.056: Method parameter(s): 1, Next - *Help*
** Message: 14:18:08.201: RPC message: buffer_uri_at_point ('https://github.com/atlas-engineer/next',)
** Message: 14:18:08.207: Method name: window_active
** Message: 14:18:08.207: Method parameter(s): 1
** Message: 14:18:08.224: Method name: window_active
** Message: 14:18:08.224: Method parameter(s): 1
** Message: 14:18:08.237: Method name: minibuffer_evaluate_javascript
** Message: 14:18:08.237: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:08.239: Method result(s): callback id 4
** Message: 14:18:08.241: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 4)
** Message: 14:18:08.251: Method name: minibuffer_evaluate_javascript
** Message: 14:18:08.251: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:08.251: Method result(s): callback id 5
** Message: 14:18:08.252: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 5)
** Message: 14:18:08.265: Method name: window_set_minibuffer_height
** Message: 14:18:08.265: Method parameter(s): window id 1, minibuffer height 25
** Message: 14:18:08.265: Method result(s): minibuffer preferred height 0
** Message: 14:18:08.554: RPC message: buffer_uri_at_point ('',)
** Message: 14:18:08.581: Method name: window_active
** Message: 14:18:08.581: Method parameter(s): 1
** Message: 14:18:08.592: Method name: buffer_evaluate_javascript
** Message: 14:18:08.592: Method parameter(s): buffer id 1, javascript (...)
** Message: 14:18:08.592: Method result(s): callback id 3
** Message: 14:18:08.595: RPC message: buffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 3)
** Message: 14:18:08.602: Method name: window_active
** Message: 14:18:08.602: Method parameter(s): 1
** Message: 14:18:08.618: Method name: buffer_evaluate_javascript
** Message: 14:18:08.618: Method parameter(s): buffer id 1, javascript (...)
** Message: 14:18:08.618: Method result(s): callback id 4
** Message: 14:18:08.620: RPC message: buffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 4)
** Message: 14:18:08.632: Method name: window_active
** Message: 14:18:08.632: Method parameter(s): 1
** Message: 14:18:08.641: Method name: window_active
** Message: 14:18:08.641: Method parameter(s): 1
** Message: 14:18:08.661: Method name: minibuffer_evaluate_javascript
** Message: 14:18:08.661: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:08.661: Method result(s): callback id 6
** Message: 14:18:08.664: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 6)
** Message: 14:18:08.684: Method name: minibuffer_evaluate_javascript
** Message: 14:18:08.684: Method parameter(s): window id 1, javascript (...)
** Message: 14:18:08.684: Method result(s): callback id 7
** Message: 14:18:08.686: RPC message: minibuffer_javascript_call_back (buffer id, javascript, callback id) = (1, ..., 7)
** Message: 14:18:08.703: Method name: window_set_minibuffer_height
** Message: 14:18:08.703: Method parameter(s): window id 1, minibuffer height 25
** Message: 14:18:08.703: Method result(s): minibuffer preferred height 0
** Message: 14:18:13.209: RPC message: window_will_close ('1',)
Ambrevar commented 5 years ago

How do you start Next? Also do you have anything in your ~/.config/next/init.lisp?

It looks like it does not find the "next-gtk-webkit" executable. You might be doing something wrong with how you start it over SSH.

khinsen commented 5 years ago

@Ambrevar I don't have any init.lisp for now. I start Next by typing "next" after connecting via ssh. I compared my environment variables after ssh login with those I get in an XFCE session on the same machine: they are the same.

khinsen commented 5 years ago

I just had a flash of enlightenment: the XFCE session! My D-Bus daemon is started from that session. I don't know much about D-Bus, but that sounds like a potential problem.

So I logged out of my XFCE session, killed the D-Bus daemon (which was still running for whatever reason), and ran dbus-launch next from my ssh connection. It works!

Next, headless mode: dbus-launch next works fine as well, even though there is no XFCE session and even though I didn't kill the D-Bus daemon that who-knows-what has started.

In other words, I have a workaround but I have no idea why it works. But it's definitely related to D-Bus.

jmercouris commented 5 years ago

Very very fascinating. Thank you for sharing, I have no idea why that works either...

Ambrevar commented 5 years ago

Can you provide detailed information of your setup?

My suspicion is that when you run Next over SSH is sees the D-Bus address from the environment variable that's not available on the Guix system, so it cannot start.

khinsen commented 5 years ago

@Ambrevar My host system is macOS, which has no D-Bus at all, so there's no risk of any relevant environment variable getting copied over to the host.

In the guest system (Guix), the desktop environment is XFCE. It is not installed in the user profile, but started via GDM at system startup. dbus is not in the user profile, but it's part of the system profile (/run/current-system/profile) and therefore on the user's PATH.

Headless mode is a feature of VirtualBox. I spin up my VM using the command-line tool:

VBoxManage startvm "Guix" --type headless

This is supposed to behave like a real PC with no display nor keyboard connected.

I connect from macOS to Guix using ssh -p 2222 -Y localhost, with VirtualBox ensuring a port redirection to port 22 of the guest system. Then I just type next (or dbus-launch next).

env | grep DBUS_SESSION has no output under macOS (no surprise), nor when I run it via SSH on the guest system. When I spin up the guest with a display and use a terminal from the desktop, I get

DBUS_SESSION_BUS_ADDRESS=unix:abstract=/tmp/dbus-M6pcCDyYZS,guid=95c3cf2bc74cd443e4a4626e5d8cdab1

To me this looks as if my SSH session has no D-Bus session of its own, but Next picks up the D-Bus session from the XFCE desktop in some way and therefore doesn't start a D-Bus session itself. Caveat: I know nearly nothing about D-Bus.

Ambrevar commented 5 years ago

What if you don't spin up the VM in headless mode?

env | grep DBUS_SESSION has no output under macOS (no surprise), nor when I run it via SSH on the guest system. When I spin up the guest with a display and use a terminal from the desktop, I get

DBUS_SESSION_BUS_ADDRESS=unix:abstract=/tmp/dbus-M6pcCDyYZS,guid=95c3cf2bc74cd443e4a4626e5d8cdab1

Correct me if I'm wrong: when you start the VM in headless mode, the VM can not start GDM since there is no "head". Thus you don't have any dbus running, which is to be expected, right?

So what if you run

export $(dbus-launch) && next

in your headless SSH session?

khinsen commented 5 years ago

@Ambrevar Your hypotheses are all correct. And export $(dbus-launch) && next works fine (just like the simple dbus-launch next. It's when I run with the display that I cannot start next in an ssh session. It looks like Next picks up the dbus session started by XFCE.

Ambrevar commented 5 years ago

This is correct, Next needs a running D-Bus session. I had implemented a fallback but apparently it does not work for some people. Since I don't have the system to reproduce the issue, it's hard to guess why. The logs show

D-Bus addresses: (#<Unix socket address: "NIL">)

Which means that the fallback did not work for some reason, without report more error.

Donaim commented 4 years ago

I had the same issue on current master with ubuntu 18.04 Running next with dbus-launch ./next helped

Ambrevar commented 4 years ago

This issue might be gone altogether with the recent architectural changes on master (Next now has only 1 process instead of 2.)

khinsen commented 4 years ago

I'll check next time I get a working Next in Guix. With yesterday's pull, next fails to build ("Unhandled UIOP/LISP-BUILD:COMPILE-FILE-ERROR", then "COMPILE-FILE-ERROR while compiling #<CL-SOURCE-FILE "next" "source" "search-buffer">", but I don't see what exactly went wrong in compiling that file). There doesn't seem to be any working build of next on ci.guix.gnu.org either at the moment.

Then I tried running from source, using the supplied guix.scm. That fails when compiling source/interprocess-communication-gtk, but this time with a clearer error message:

     Symbol "WEBKIT-NAVIGATION-POLICY-DECISION-GET-NAVIGATION-ACTION" not found in the CL-WEBKIT2 package.
;
;       Line: 241, Column: 93, File-Position: 10276
Ambrevar commented 4 years ago

I've got one from Guix 170c6b03444b1bb059728efc85e14edd3688dfdb. You must have been unlucky, try again :)

Anyways, the Guix package is 1.5.0, which does not contain the latest architectural changes. Those will come once 2.0 is released.

In the meantime, you can use the Guix recipe in build-scripts/guix.scm to build master.

khinsen commented 4 years ago

That works! And as far as I can tell from a first few tests, the initial problem indeed went away. To be confirmed when I have Next back in service - my init.lisp crashes, so I'll have to do some debugging.

Ambrevar commented 4 years ago

Indeed, the init.lisp syntax is no longer compatible with the coming 2.0. We will update the documentation.

Hint for now (this will change before 2.0):

Ambrevar commented 4 years ago

Check out the changelog, I'm regularly updating it to highlight the user-facing breaking changes. I might have missed a few things though, feel free to ping me.