crash while resizing in notcurses-demo [view] #844

dankamongmen commented 2021年12月15日 00:46:11 +01:00

I was attempting to reproduce the crash seen in notcurses-demo as reported by @dnkl at https://github.com/dankamongmen/notcurses/issues/2471. I have not yet been able to do so, but I did crash foot a few times. I'll try and get you a stack trace. Here's what I have thus far:

warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1
info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-Regular.ttf: size=10.00pt/
25px, dpi=181.63
info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-BoldItalic.ttf: size=10.00
pt/25px, dpi=181.63
info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-Italic.ttf: size=10.00pt/2
5px, dpi=181.63
info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-Bold.ttf: size=10.00pt/25p
x, dpi=181.63
info: terminal.c:694: cell width=15, height=30
warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1
warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
warn: sixel.c:887: destroyed sixel that now crossed history
 err: shm.c:197: BUG in buffer_release(): assertion failed: 'buffer->busy'
Aborted (core dumped)

I was attempting to reproduce the crash seen in `notcurses-demo` as reported by @dnkl at https://github.com/dankamongmen/notcurses/issues/2471. I have not yet been able to do so, but I did crash foot a few times. I'll try and get you a stack trace. Here's what I have thus far: ``` warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1 info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-Regular.ttf: size=10.00pt/ 25px, dpi=181.63 info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-BoldItalic.ttf: size=10.00 pt/25px, dpi=181.63 info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-Italic.ttf: size=10.00pt/2 5px, dpi=181.63 info: fcft.c:757: /usr/share/fonts/truetype/hack/Hack-Bold.ttf: size=10.00pt/25p x, dpi=181.63 info: terminal.c:694: cell width=15, height=30 warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1 warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1 warn: csi.c:1517: unimplemented: modifyFunctionKeys = 1 warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history warn: sixel.c:887: destroyed sixel that now crossed history err: shm.c:197: BUG in buffer_release(): assertion failed: 'buffer->busy' Aborted (core dumped) ```

dankamongmen commented 2021年12月15日 00:58:32 +01:00

Thread 7 (Thread 0x7ffff5f3c640 (LWP 1116511) "foot:render:2"):
#0 0x00007ffff7aec0fa in __futex_abstimed_wait_common64 (futex_word=futex_word@
entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry=0, abstim
e=abstime@entry=0x0, private=<optimized out>, cancel=cancel@entry=true) at ../sy
sdeps/nptl/futex-internal.c:74
#1 0x00007ffff7aec15b in __GI___futex_abstimed_wait_cancelable64 (futex_word=fu
tex_word@entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry=
0, abstime=abstime@entry=0x0, private=<optimized out>) at ../sysdeps/nptl/futex-
internal.c:123
#2 0x00007ffff7ae844f in do_futex_wait (sem=sem@entry=0x555555671a98, abstime=0
x0, clockid=0) at sem_waitcommon.c:112
#3 0x00007ffff7ae84e8 in __new_sem_wait_slow64 (sem=0x555555671a98, abstime=0x0
, clockid=0) at sem_waitcommon.c:184
#4 0x0000555555589922 in render_worker_thread (_ctx=0x55555566efb0) at ../rende
r.c:1451
#5 0x00007ffff7adfe4a in start_thread (arg=0x7ffff5f3c640) at pthread_create.c:
478
#6 0x00007ffff7a0ab6f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:
95
Thread 6 (Thread 0x7ffff573b640 (LWP 1116509) "foot:render:1"):
#0 0x00007ffff7aec0fa in __futex_abstimed_wait_common64 (futex_word=futex_word@
entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry=0, abstim
e=abstime@entry=0x0, private=<optimized out>, cancel=cancel@entry=true) at ../sy
sdeps/nptl/futex-internal.c:74
#1 0x00007ffff7aec15b in __GI___futex_abstimed_wait_cancelable64 (futex_word=fu
tex_word@entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry=
0, abstime=abstime@entry=0x0, private=<optimized out>) at ../sysdeps/nptl/futex-
internal.c:123
#2 0x00007ffff7ae844f in do_futex_wait (sem=sem@entry=0x555555671a98, abstime=0
x0, clockid=0) at sem_waitcommon.c:112
#3 0x00007ffff7ae84e8 in __new_sem_wait_slow64 (sem=0x555555671a98, abstime=0x0
, clockid=0) at sem_waitcommon.c:184
#4 0x0000555555589922 in render_worker_thread (_ctx=0x555555681eb0) at ../rende
r.c:1451
#5 0x00007ffff7adfe4a in start_thread (arg=0x7ffff573b640) at pthread_create.c:
478
#6 0x00007ffff7a0ab6f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:
95
Thread 1 (Thread 0x7ffff7664900 (LWP 1116487) "foot"):
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49
#1 0x00007ffff7934536 in __GI_abort () at abort.c:79
#2 0x00005555555ccb87 in bug (file=0x5555555e282b "shm.c", line=197, func=0x555
5555e2db8 <__func__.14> "buffer_release", fmt=0x5555555e2814 "assertion failed: 
'%s'") at ../debug.c:46
#3 0x00005555555978e1 in buffer_release (data=0x555555825000, wl_buffer=0x55555
5682c90) at ../shm.c:197
#4 0x00007ffff79089da in ?? () from /usr/lib/x86_64-linux-gnu/libffi.so.8
#5 0x00007ffff7907b21 in ?? () from /usr/lib/x86_64-linux-gnu/libffi.so.8
#6 0x00007ffff7d942d2 in ?? () from /usr/lib/x86_64-linux-gnu/libwayland-client
.so.0
#7 0x00007ffff7d9097a in ?? () from /usr/lib/x86_64-linux-gnu/libwayland-client
.so.0
#8 0x00007ffff7d9203c in wl_display_dispatch_queue_pending () from /usr/lib/x86
_64-linux-gnu/libwayland-client.so.0
#9 0x00005555555a2998 in fdm_wayl (fdm=0x55555566fca0, fd=5, events=1, data=0x5
5555566eeb0) at ../wayland.c:1163
#10 0x000055555557ad68 in fdm_poll (fdm=0x55555566fca0) at ../fdm.c:463
#11 0x000055555558443a in main (argc=0, argv=0x7fffffffddd0) at ../main.c:563

``` Thread 7 (Thread 0x7ffff5f3c640 (LWP 1116511) "foot:render:2"): #0 0x00007ffff7aec0fa in __futex_abstimed_wait_common64 (futex_word=futex_word@ entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry=0, abstim e=abstime@entry=0x0, private=<optimized out>, cancel=cancel@entry=true) at ../sy sdeps/nptl/futex-internal.c:74 #1 0x00007ffff7aec15b in __GI___futex_abstimed_wait_cancelable64 (futex_word=fu tex_word@entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry= 0, abstime=abstime@entry=0x0, private=<optimized out>) at ../sysdeps/nptl/futex- internal.c:123 #2 0x00007ffff7ae844f in do_futex_wait (sem=sem@entry=0x555555671a98, abstime=0 x0, clockid=0) at sem_waitcommon.c:112 #3 0x00007ffff7ae84e8 in __new_sem_wait_slow64 (sem=0x555555671a98, abstime=0x0 , clockid=0) at sem_waitcommon.c:184 #4 0x0000555555589922 in render_worker_thread (_ctx=0x55555566efb0) at ../rende r.c:1451 #5 0x00007ffff7adfe4a in start_thread (arg=0x7ffff5f3c640) at pthread_create.c: 478 #6 0x00007ffff7a0ab6f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 95 Thread 6 (Thread 0x7ffff573b640 (LWP 1116509) "foot:render:1"): #0 0x00007ffff7aec0fa in __futex_abstimed_wait_common64 (futex_word=futex_word@ entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry=0, abstim e=abstime@entry=0x0, private=<optimized out>, cancel=cancel@entry=true) at ../sy sdeps/nptl/futex-internal.c:74 #1 0x00007ffff7aec15b in __GI___futex_abstimed_wait_cancelable64 (futex_word=fu tex_word@entry=0x555555671a98, expected=expected@entry=0, clockid=clockid@entry= 0, abstime=abstime@entry=0x0, private=<optimized out>) at ../sysdeps/nptl/futex- internal.c:123 #2 0x00007ffff7ae844f in do_futex_wait (sem=sem@entry=0x555555671a98, abstime=0 x0, clockid=0) at sem_waitcommon.c:112 #3 0x00007ffff7ae84e8 in __new_sem_wait_slow64 (sem=0x555555671a98, abstime=0x0 , clockid=0) at sem_waitcommon.c:184 #4 0x0000555555589922 in render_worker_thread (_ctx=0x555555681eb0) at ../rende r.c:1451 #5 0x00007ffff7adfe4a in start_thread (arg=0x7ffff573b640) at pthread_create.c: 478 #6 0x00007ffff7a0ab6f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 95 Thread 1 (Thread 0x7ffff7664900 (LWP 1116487) "foot"): #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49 #1 0x00007ffff7934536 in __GI_abort () at abort.c:79 #2 0x00005555555ccb87 in bug (file=0x5555555e282b "shm.c", line=197, func=0x555 5555e2db8 <__func__.14> "buffer_release", fmt=0x5555555e2814 "assertion failed: '%s'") at ../debug.c:46 #3 0x00005555555978e1 in buffer_release (data=0x555555825000, wl_buffer=0x55555 5682c90) at ../shm.c:197 #4 0x00007ffff79089da in ?? () from /usr/lib/x86_64-linux-gnu/libffi.so.8 #5 0x00007ffff7907b21 in ?? () from /usr/lib/x86_64-linux-gnu/libffi.so.8 #6 0x00007ffff7d942d2 in ?? () from /usr/lib/x86_64-linux-gnu/libwayland-client .so.0 #7 0x00007ffff7d9097a in ?? () from /usr/lib/x86_64-linux-gnu/libwayland-client .so.0 #8 0x00007ffff7d9203c in wl_display_dispatch_queue_pending () from /usr/lib/x86 _64-linux-gnu/libwayland-client.so.0 #9 0x00005555555a2998 in fdm_wayl (fdm=0x55555566fca0, fd=5, events=1, data=0x5 5555566eeb0) at ../wayland.c:1163 #10 0x000055555557ad68 in fdm_poll (fdm=0x55555566fca0) at ../fdm.c:463 #11 0x000055555558443a in main (argc=0, argv=0x7fffffffddd0) at ../main.c:563 ```

dnkl commented 2021年12月15日 10:08:39 +01:00

Eye for an eye, huh? :D

This is an interresting bug... buffer->busy is set by foot before handing it over to the compositor for rendering. buffer_release() is called by the compositor when it's done with it.

Thus, the failing assertion you're hitting basically says "the compositor gave us back this buffer, but we have no memory of ever handing it over to the compositor".

Pretty sure it is a bug in foot somewhere, but your compositor of choice may be an important factor. I.e. which compositor are you running?

Eye for an eye, huh? :D This is an interresting bug... `buffer->busy` is set by foot before handing it over to the compositor for rendering. `buffer_release()` is called by the compositor when it's done with it. Thus, the failing assertion you're hitting basically says "the compositor gave us back this buffer, but we have no memory of ever handing it over to the compositor". Pretty sure it _is_ a bug in foot somewhere, but your compositor of choice may be an important factor. I.e. which compositor are you running?

dankamongmen commented 2021年12月15日 10:50:16 +01:00

Pretty sure it is a bug in foot somewhere, but your compositor of choice may be an important factor. I.e. which compositor are you running?

weston 9.0.0

> Pretty sure it _is_ a bug in foot somewhere, but your compositor of choice may be an important factor. I.e. which compositor are you running? weston 9.0.0

dnkl commented 2021年12月15日 11:29:02 +01:00

Are you running weston nested inside X, or directly from a VT? Weston will be using different backends, and that will affect how/when it releases buffers.

I haven't been able to trigger the crash in a Wayland-nested weston. I'm having trouble getting weston to run from a VT at the moment, and would be nice to know if I should spend more time on that problem or not...

Are you running weston nested inside X, or directly from a VT? Weston will be using different backends, and that will affect how/when it releases buffers. I haven't been able to trigger the crash in a Wayland-nested weston. I'm having trouble getting weston to run from a VT at the moment, and would be nice to know if I should spend more time on that problem or not...

dnkl commented 2021年12月15日 12:50:57 +01:00

Btw, I assume you are running a debug build? We disable assertions by default in release builds.

There are quite a few assertions in the hot path that we really don't want in release builds.

(fwiw: in debug builds, the sixel code is riddled with, not only assertions, but calls to verification functions that loop all sixels and verify the consistency of the internal state - slow).

Btw, I assume you are running a debug build? We disable assertions by default in release builds. There are quite a few assertions in the hot path that we really don't want in release builds. (fwiw: in debug builds, the sixel code is riddled with, not only assertions, but calls to verification functions that loop all sixels and verify the consistency of the internal state - _slow_).

dankamongmen commented 2021年12月15日 18:34:02 +01:00

Are you running weston nested inside X, or directly from a VT? Weston will be using different backends, and that will affect how/when it releases buffers.

I haven't been able to trigger the crash in a Wayland-nested weston. I'm having trouble getting weston to run from a VT at the moment, and would be nice to know if I should spend more time on that problem or not...

nested inside X (i.e. I have X running and run weston from inside it).

> Are you running weston nested inside X, or directly from a VT? Weston will be using different backends, and that will affect how/when it releases buffers. > > I haven't been able to trigger the crash in a Wayland-nested weston. I'm having trouble getting weston to run from a VT at the moment, and would be nice to know if I should spend more time on that problem or not... nested inside X (i.e. I have X running and run weston from inside it).