Next hangs after a while (Guix build)

[Ambrevar]

It seems that Next hangs after a while.

It happened to me after many hours, and it seems when I tried to open a URL externally.
(Could be a red herring.)

Possible causes:

• Unhandled exception at the FFI / javascript level. If so, it should be easy to fix.
• Corruption at the FFI library level (like the C-v issue). If so, we need to fix the libraries or find a way to not trigger the issue.

@jellelicht If you have a recipe please share :)

[Ambrevar]

@jellelicht reported the following strace:

...
clone(child_stack=0x7f81f766bfb0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[15133], tls=0x7f81f766c700, child_tidptr=0x7f81f766c9d0) = 15133
sched_getaffinity(15133, 32, [0, 1, 2, 3, 4, 5, 6, 7]) = 32
futex(0x7f824c2578d8, FUTEX_WAKE_PRIVATE, 1) = 1
recvmsg(4, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(4, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 3, 35648) = 1 ([{fd=5, revents=POLLIN}])
read(5, "\5\0\0\0\0\0\0\0", 16)         = 8
recvmsg(4, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(4, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 3, 35648) = 1 ([{fd=5, revents=POLLIN}])
read(5, "\1\0\0\0\0\0\0\0", 16)         = 8
recvmsg(4, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(4, {msg_namelen=0}, 0)          = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 3, 35648) = 1 ([{fd=5, revents=POLLIN}])
read(5, "\1\0\0\0\0\0\0\0", 16)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 8
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x7f824c2f9160, FUTEX_WAIT_PRIVATE, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 202
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 202
futex(0x7f824c2f9160, FUTEX_WAIT_PRIVATE, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 202
futex(0x7f824c2f9160, FUTEX_WAIT_PRIVATE, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 202
futex(0x7f824c2f9160, FUTEX_WAIT_PRIVATE, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 202
--- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_TKILL, si_pid=11441, si_uid=1000} ---
futex(0x7f825101ebc0, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigreturn({mask=[]})                 = 202
...

And it keeps looping on SIGUSR1 forever.

[jmercouris]

Possibly a starvation issue? Two processes trying to access the same resource? That's the only reason I can think of why it cannot accquire a lock

[Ambrevar]

Do you experience hangs yourself? Possibly after many hours? I do sometimes, but it's hard to reproduce on my end.

[jmercouris]

I never experience hangs, no. Even if a particular view hangs (which I can reliably do by trying to play any audio...) I can always kill the buffer and load another.

[Ambrevar]

I can reproduce the hang after 10 minutes using the Guix recipe.

[jmercouris]

What is the Guix recipe?

[Ambrevar]

build-scripts/guix.scm

[jmercouris]

Are you saying that if you use the Guix recipe to build Next it hangs after 10 minutes, but otherwise it hangs after an indeterminate out of time?

[Ambrevar]

With Guix, I could reproduce the hang after 10 minutes. With Quicklisp, I usually don't get hangs. I did in the past but they may be fixed now.

[Ambrevar]

I've updated most Common Lisp Guix packages: now Next should be using approximately the same Common Lisp library versions when built with Guix or Quicklisp.

That said, I am still experiencing the issue with Guix.
Also see issue #593 which may be related.

• Either I've missed a key library in Guix.
• Or the Guix build system produces libraries different from those loaded from Quicklisp. Guix uses "compile-bundle-op", maybe this breaks CFFI / GTK / WebKit somehow.
• Or...? Any idea?

@khinsen @jellelicht @arunisaac

[Ambrevar]

Tried something else: In Guix, sbcl-cffi uses the gnu-build-system gcc, which is gcc-7 if I'm not mistaken. I tried switching to gcc-9 (the one I use in my profile) to no avail.

[khinsen]

I have never had Next hang at all. I rarely use it for long under Guix (I start the Guix virtual machine only for precise needs, as it occupies a lot of memory), but under macOS I only quit Next to update to a newer commit. Still, it never hangs.

Could the communication between the two processes via dbus be a potential cause? My impression is that all UI events pass through it, so if it blocks, Next would appear to hang.

[Ambrevar]

I'm talking about Next on master which does not use DBus. Have you tried it? Does it ever hang for you? I know it hangs for at least 3 Guix users: @arunisaac, @jellelicht and me :)

[khinsen]

Well, I am using Next on master. I wasn't aware that it doesn't use DBus any more!

[Ambrevar]

Thanks for reporting. The issue could then be a race condition that heavily depends on the hardware.

[jmercouris]

@Ambrevar

what if you run Next in a VM with ssh X forwarding in a Guix build, does it crash then?

[jmercouris]

The VM will help you determine if it is hardware dependent (unless you are using a pass through access to hardware directly)

[Ambrevar]

Not sure it will help: if it's a matter of CPU speed, this issue can happen at random. It could happen in a VM too.

[jmercouris]

I don't know enough about virtualization to comment with any certainty. In any case, I would try it

[arunisaac]

- Or...? Any idea?

I'm sorry I don't have any useful insight to offer. But, if I remember correctly, this problem didn't occur in older versions of Next. Would it be worth bisecting the git commit log?

[Ambrevar]

By older versions, you means 1.5? If it's before the switch to the cl-webkit FFI, yes, this is expected. What I'm going to try next: - Make a Guix package including the Quicklisp distribution: this should work. - Then "diffoscope" the above package with a Guix package that only depends on cl-* inputs (the source libraries). This should highlight the differences.

[arunisaac]

By older versions, you means 1.5?

Yes.

If it's before the switch to the cl-webkit FFI, yes, this is expected.

Ok.

What I'm going to try next: - Make a Guix package including the Quicklisp distribution: this should work. - Then "diffoscope" the above package with a Guix package that only depends on cl-* inputs (the source libraries). This should highlight the differences.

Sure, thank you for your work!

[Ambrevar]

And... I just got it to work with Guix! I've switched to using the cl-* source package directly and that did it! Why are the SBCL packages causing this issue? SBCL packages in Guix use ASDF's `compile-bundle-op` operation. I've seen issue with it in the past (ruricolist/serapeum#42 and ruricolist/serapeum#55 for instance). These issues are usually caught at compilation time, but I don't know if we can be sure that no issue sneaked through unnoticed. My guess is that compile-bundle-op causes issues with CFFI. But this could also be a red herring. It would take time to narrow down this bug more specifically. In the mean time, Next can go forward using cl-* inputs! Before closing this bug, we need to merge https://issues.guix.info/issue/41135 in Guix.

[jmercouris]

Congratulations on the fix!

[jellelicht]

Is there anything I can do to easily test this already? I'm also not quite sure why a patch to guix' asdf-build-system has anything to do with the now-used gnu-build-system 🤔

EDIT: or is it because all of the cl-source packages were kind of 'broken' before?

[Ambrevar]

This is because I've changed the guix.scm recipe to rely on the Makefile for building. I'm using the gnu-build-system only for `make`. The Makefile then takes care of building Next upon its inputs which I've changed from sbcl-* to cl-*. I need to fix asdf-build-system to build cl-* packages properly (this was a long-standing bug in the asdf-build-system). To test, you need to: - Apply the Guix patch (v2 or above). - Apply the pull request patch. - Build the patched Next as usual from your patched Guix: ``` ~/guix/pre-inst-env guix build -f build-scripts/guix.scm ```

[Ambrevar]

After more testing, I've narrowed down the issue to sbcl-cl-cffi-gtk: switching to cl-cffi-gtk fixes the issue. I'll report upstream.

[jellelicht]

Well, it seems to work (20 minutes in and no hangs). Congrats on the fix!

[Ambrevar]

Pfeeeeeeew! Thanks for testing, it really made my day (/week/month) :D

[arunisaac]

I tested and it works for me too! Now, I can finally start using Next full time. Great work! :-)

[Ambrevar]

Thanks a lot for reporting!

[ghost]

I've built current master, than guix package -f build-scripts/guix.scm and getting high CPU usage after 10-ish minutes. There is no info in terminal, not even with -v flag, next just freezes and fails to redisplay after switching windows/desktops. I'm willing to do some swank debugging if someone can guide me through it.

Here is my system info:

Lisp Implementation: SBCL 
Lisp Version: 2.0.4 
Operating System: Linux 5.4.41-gnu 
Features: (WEBKIT2 WEBKIT2-2.28 WEBKIT2-EMOJI WEBKIT2-MEDIA WEBKIT2-SANDBOXING
           GTK-3-22 GTK-3-20 GTK-3-18 GTK-3-16 GTK-3-14 GTK-3-12 GTK-3-10
           GTK-3-8 GTK-3-6 GTK-3-4 GTK GDK-3-22 GDK-3-20 GDK-3-18 GDK-3-16
           GDK-3-14 GDK-3-12 GDK-3-10 GDK-3-8 GDK-3-6 GDK-3-4 CAIRO-1-10
           CAIRO-1-12 GDK-PIXBUF GLIB-2-30 GLIB-2-32 GLIB-2-34 GLIB-2-36
           GLIB-2-38 GLIB-2-40 GLIB-2-42 GLIB-2-44 GLIB-2-46 GLIB-2-48
           GLIB-2-50 GLIB-2-52 GLIB-2-54 GLIB-2-56 GLIB-2-58 GLIB
           FSET-EXT-STRINGS SWANK PLUMP-UTF-32 DECLARE-TYPES PARENSCRIPT
           NAMED-READTABLES OSICAT-FD-STREAMS 21BIT-CHARS CL-FAD CHUNGA
           FLAT-NAMESPACE X86-64 UNIX CFFI FLAT-NAMESPACE FLEXI-STREAMS
           CLOSER-MOP SB-BSD-SOCKETS-ADDRINFO SPLIT-SEQUENCE CL-PPCRE-UNICODE
           CL-UNICODE CL-PPCRE BORDEAUX-THREADS SEQUENCE-EMPTYP ASDF3.3 ASDF3.2
           ASDF3.1 ASDF3 ASDF2 ASDF OS-UNIX NON-BASE-CHARS-EXIST-P ASDF-UNICODE
           X86-64 GENCGC 64-BIT ANSI-CL COMMON-LISP ELF IEEE-FLOATING-POINT
           LINUX LITTLE-ENDIAN PACKAGE-LOCAL-NICKNAMES SB-CORE-COMPRESSION
           SB-LDB SB-PACKAGE-LOCKS SB-THREAD SB-UNICODE SBCL UNIX)

Cheers!

[Ambrevar]

This is because the Guix patch hasn't been pushed to master yet. I'll do it tomorrow, stay tuned!

[Ambrevar]

Fixed in b24e9a3.
You'll need to guix pull first (after commit 0fadc00a1a5bfbb6ca9caf1bfae06e839684843c).

Feel free to reopen if the issue persists.