search

lanoxx / tilda

A Gtk based drop down terminal for Linux and Unix
GNU General Public License v2.0
1.26k stars 162 forks source link

Tilda crash when hiding/showing #428

Closed whitty closed 3 years ago

whitty commented 3 years ago

Hi - I see some potentially related crash issues logged as #348 and #318 and I don't want to to add to the spam.

I've been using tilda for years now (2010 maybe?) but having just updated to Ubuntu 18.04 for work (could be worse we were running 14.04 12 months ago) I'm seeing crashes with the native Ubuntu version 1.4.1-2.

Because I'd seen fixes for #318 I built a PPA of tilda from 20.04:

https://launchpad.net/~greg-whiteley/+archive/ubuntu/tilda-backport/+packages

This is a rebuild of 1.5.0-1.1 from Ubuntu 20.04. I don't know if the #318 fix is in this code yet.

The issue looks most like #348 - even though the trigger is more like #318

Steps to reproduce (Sadly I don't know):

  1. Run a default gnome-session in 18.04
  2. Run tilda for a number of days flawlessly toggling whenever
  3. Hit the "raise" key (F1)
  4. Faint outline of tilda shows up, disappears and all processes started from those shells die. Tilda crashed

For reference I've seen the issue with both nVidia and AMD proprietary drivers (two different machines).

dmesg says:

[587455.005547] do_trap: 36 callbacks suppressed
[587455.005549] traps: tilda[8183] trap int3 ip:7f71ee752ea1 sp:7ffc4eac8910 error:0 in libglib-2.0.so.0.5600.4[7f71ee701000+114000]

journalctl says:

Aug 07 16:23:42 sodium tilda[8183]: X Error: BadMatch (invalid parameter attributes)
Aug 07 16:23:42 sodium kernel: do_trap: 36 callbacks suppressed
Aug 07 16:23:42 sodium kernel: traps: tilda[8183] trap int3 ip:7f71ee752ea1 sp:7ffc4eac8910 error:0 in libglib-2.0.so.0.5600.4[7f71ee701000+114000]
Aug 07 16:23:42 sodium systemd[1]: Started Process Core Dump (PID 18114/UID 0).
Aug 07 16:23:43 sodium gnome-shell[31235]: [AppIndicatorSupport-WARN] Attempting to re-register :1.66/org/ayatana/NotificationItem/multiload; resetting instead
Aug 07 16:23:43 sodium gnome-shell[31235]: [AppIndicatorSupport-WARN] Item :1.66/org/ayatana/NotificationItem/multiload is already registered
Aug 07 16:23:43 sodium gnome-shell[31235]: [AppIndicatorSupport-WARN] Attempting to re-register :1.66/org/ayatana/NotificationItem/multiload; resetting instead
Aug 07 16:23:43 sodium gnome-shell[31235]: [AppIndicatorSupport-WARN] Item :1.66/org/ayatana/NotificationItem/multiload is already registered
Aug 07 16:23:43 sodium systemd-coredump[18115]: Process 8183 (tilda) of user 1000 dumped core.

                                                Stack trace of thread 8183:
                                                #0  0x00007f71ee752ea1 _g_log_abort (libglib-2.0.so.0)
                                                #1  0x00007f71ee755819 g_log_writer_default (libglib-2.0.so.0)
                                                #2  0x00007f71ee753a8e g_log_structured_array (libglib-2.0.so.0)
                                                #3  0x00007f71ee7544ce g_log_structured_standard (libglib-2.0.so.0)
                                                #4  0x0000562111c27d79 n/a (tilda)
                                                #5  0x00007f71edf998fa _XError (libX11.so.6)
                                                #6  0x00007f71edf9682b n/a (libX11.so.6)
                                                #7  0x00007f71edf968d5 n/a (libX11.so.6)
                                                #8  0x00007f71edf97205 _XEventsQueued (libX11.so.6)
                                                #9  0x00007f71edf88d3d XPending (libX11.so.6)
                                                #10 0x00007f71ef4e4001 n/a (libgdk-3.so.0)
                                                #11 0x00007f71ee74cfe1 g_main_context_check (libglib-2.0.so.0)
                                                #12 0x00007f71ee74d570 g_main_context_iterate (libglib-2.0.so.0)
                                                #13 0x00007f71ee74d962 g_main_loop_run (libglib-2.0.so.0)
                                                #14 0x00007f71ef9a1a25 gtk_main (libgtk-3.so.0)
                                                #15 0x0000562111c19220 n/a (tilda)
                                                #16 0x00007f71ed96ab97 __libc_start_main (libc.so.6)

                                                #17 0x0000562111c197ca n/a (tilda)

                                                Stack trace of thread 8188:
                                                #0  0x00007f71eda5dcf9 __GI___poll (libc.so.6)
                                                #1  0x00007f71ee74d5c9 g_main_context_poll (libglib-2.0.so.0)
                                                #2  0x00007f71ee74d962 g_main_loop_run (libglib-2.0.so.0)
                                                #3  0x00007f71eed3b276 gdbus_shared_thread_func (libgio-2.0.so.0)
                                                #4  0x00007f71ee775175 g_thread_proxy (libglib-2.0.so.0)
                                                #5  0x00007f71edd416db start_thread (libpthread.so.0)
                                                #6  0x00007f71eda6aa3f __clone (libc.so.6)

                                                Stack trace of thread 8187:
                                                #0  0x00007f71eda5dcf9 __GI___poll (libc.so.6)
                                                #1  0x00007f71ee74d5c9 g_main_context_poll (libglib-2.0.so.0)
                                                #2  0x00007f71ee74d6dc g_main_context_iteration (libglib-2.0.so.0)
                                                #3  0x00007f71ee74d721 glib_worker_main (libglib-2.0.so.0)
                                                #4  0x00007f71ee775175 g_thread_proxy (libglib-2.0.so.0)
                                                #5  0x00007f71edd416db start_thread (libpthread.so.0)
                                                #6  0x00007f71eda6aa3f __clone (libc.so.6)

coredumpctl gdb gives me the following backtrace

(gdb) 
#0  0x00007f71ee752ea1 in _g_log_abort (breakpoint=breakpoint@entry=1)
    at ../../../../glib/gmessages.c:583
#1  0x00007f71ee755819 in g_log_writer_default (log_level=6, 
    log_level@entry=G_LOG_LEVEL_ERROR, fields=fields@entry=0x7ffc4eac89d0, n_fields=n_fields@entry=6, user_data=user_data@entry=0x0) at ../../../../glib/gmessages.c:2735
#2  0x00007f71ee753a8e in g_log_structured_array (log_level=G_LOG_LEVEL_ERROR, fields=0x7ffc4eac89d0, n_fields=6) at ../../../../glib/gmessages.c:1970
#3  0x00007f71ee7544ce in g_log_structured_standard (log_domain=log_domain@entry=0x562111c2898c "tilda", log_level=log_level@entry=G_LOG_LEVEL_ERROR, file=file@entry=0x562111c2bb6f "src/xerror.c", line=line@entry=0x562111c2bb6c "38", func=func@entry=0x562111c2bb80 <__func__.13045> "xerror_handler", message_format=<optimised out>)
    at ../../../../glib/gmessages.c:2027
#4  0x0000562111c27d79 in xerror_handler (d=<optimised out>, e=<optimised out>)
    at src/xerror.c:38
#5  0x00007f71edf998fa in _XError (dpy=dpy@entry=0x562112b6b9c0, rep=rep@entry=0x5621134276e0) at ../../src/XlibInt.c:1434
#6  0x00007f71edf9682b in handle_error (dpy=0x562112b6b9c0, err=0x5621134276e0, in_XReply=<optimised out>) at ../../src/xcb_io.c:199
#7  0x00007f71edf968d5 in handle_response (dpy=dpy@entry=0x562112b6b9c0, response=0x5621134276e0, in_XReply=in_XReply@entry=0) at ../../src/xcb_io.c:320
#8  0x00007f71edf97205 in _XEventsQueued (dpy=dpy@entry=0x562112b6b9c0, mode=mode@entry=2) at ../../src/xcb_io.c:359
#9  0x00007f71edf88d3d in XPending (dpy=0x562112b6b9c0) at ../../src/Pending.c:55
#10 0x00007f71ef4e4001 in gdk_check_xpending (display=<optimised out>)
    at ../../../../../gdk/x11/gdkeventsource.c:269
#11 0x00007f71ef4e4001 in gdk_event_source_check (source=0x562112b98ae0)
    at ../../../../../gdk/x11/gdkeventsource.c:306
#12 0x00007f71ee74cfe1 in g_main_context_check (context=context@entry=0x562112b98bd0, max_priority=2147483647, fds=fds@entry=0x562113238490, n_fds=n_fds@entry=10)
    at ../../../../glib/gmain.c:3735
#13 0x00007f71ee74d570 in g_main_context_iterate (context=0x562112b98bd0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimised out>) at ../../../../glib/gmain.c:3899
#14 0x00007f71ee74d962 in g_main_loop_run (loop=0x5621131a5d30)
    at ../../../../glib/gmain.c:4098
#15 0x00007f71ef9a1a25 in gtk_main () at ../../../../gtk/gtkmain.c:1323
#16 0x0000562111c19220 in main (argc=<optimised out>, argv=<optimised out>)
    at src/tilda.c:779

I'm a novice* in repackaging/backporting so could do with some assistance to try to track your latest 1.5.x code more closely than "what was in 20.04" - hopefully I'll have some time this weekend to update to your latest code in case there are upstream fixes.

* actually not a novice with building debs, but very novice with "debian style" "tarball based" "orig package" source packages. Something about the maintainer workflow breaks my poor shrivelled developer mind. Something about the way you have to get a tarball out of a perfectly good git repo and then the packaging is in an unrelated repo makes my head unable to follow simple instructions.

whitty commented 3 years ago

OK - caught under GDB built with maintainer mode on - built from

commit 0c5bdc8f681dee45d1e0bd14d6849e429710fc52 (HEAD -> master, origin/master, origin/HEAD)
Author: Sebastian Geiger <sbastig@gmx.net>
Date:   Sun May 10 17:02:40 2020 +0200

    Hacking.md: update packaging notes

Last part of log:

(tilda:9058): tilda-DEBUG: 12:52:44.242: Calling handler for 'F1'...
(tilda:9058): tilda-DEBUG: 12:52:44.242: key_grabber.c: FUNCTION ENTERED: onKeybindingPull
(tilda:9058): tilda-DEBUG: 12:52:44.242: key_grabber.c: FUNCTION ENTERED: pull
(tilda:9058): tilda-DEBUG: 12:52:44.247: tilda_window.c: FUNCTION ENTERED: focus_term
(tilda:9058): tilda-DEBUG: 12:52:44.247: key_grabber.c: FUNCTION ENTERED: tilda_window_set_active
(tilda:9058): tilda-DEBUG: 12:52:44.249: pull_down(): MOVED DOWN
(tilda:9058): tilda-DEBUG: 12:52:44.284: tilda_window.c: FUNCTION ENTERED: mouse_enter
(tilda:9058): tilda-DEBUG: 12:52:44.378: Got KeyRelease!
(tilda:9058): tilda-DEBUG: 12:52:48.769: tilda_window.c: FUNCTION ENTERED: mouse_leave
(tilda:9058): tilda-DEBUG: 12:52:49.212: tilda_window.c: FUNCTION ENTERED: focus_out_event_cb
(tilda:9058): tilda-DEBUG: 12:52:49.466: tilda_window.c: FUNCTION ENTERED: mouse_enter
(tilda:9058): tilda-DEBUG: 12:52:49.610: tilda_window.c: FUNCTION ENTERED: mouse_leave
(tilda:9058): tilda-DEBUG: 12:53:17.281: tilda_window.c: FUNCTION ENTERED: mouse_enter
(tilda:9058): tilda-DEBUG: 12:53:17.860: tilda_terminal.c: FUNCTION ENTERED: button_press_cb
(tilda:9058): tilda-DEBUG: 12:53:31.880: tilda_window.c: FUNCTION ENTERED: mouse_leave
(tilda:9058): tilda-DEBUG: 12:53:32.145: tilda_window.c: FUNCTION ENTERED: focus_out_event_cb
(tilda:9058): tilda-DEBUG: 12:56:24.686: tilda_window.c: FUNCTION ENTERED: mouse_enter
(tilda:9058): tilda-DEBUG: 12:56:24.806: tilda_window.c: FUNCTION ENTERED: mouse_leave
(tilda:9058): tilda-DEBUG: 12:56:25.117: tilda_window.c: FUNCTION ENTERED: mouse_enter
(tilda:9058): tilda-DEBUG: 12:56:25.622: tilda_window.c: FUNCTION ENTERED: mouse_leave
(tilda:9058): tilda-DEBUG: 12:56:26.174: tilda_window.c: FUNCTION ENTERED: mouse_enter
(tilda:9058): tilda-DEBUG: 12:56:26.462: tilda_window.c: FUNCTION ENTERED: focus_out_event_cb
(tilda:9058): tilda-DEBUG: 12:56:26.462: Got KeyPress! keycode: 67, modifiers: 16
(tilda:9058): tilda-DEBUG: 12:56:26.462: Current event time 91031842
(tilda:9058): tilda-DEBUG: 12:56:26.462: Calling handler for 'F1'...
(tilda:9058): tilda-DEBUG: 12:56:26.462: key_grabber.c: FUNCTION ENTERED: onKeybindingPull
(tilda:9058): tilda-DEBUG: 12:56:26.462: key_grabber.c: FUNCTION ENTERED: pull
(tilda:9058): tilda-DEBUG: 12:56:26.463: pull_up(): MOVED UP
(tilda:9058): tilda-DEBUG: 12:56:26.463: tilda_window.c: FUNCTION ENTERED: mouse_leave
(tilda:9058): tilda-DEBUG: 12:56:26.489: xerror.c: FUNCTION ENTERED: xerror_handler

(tilda:9058): tilda-ERROR **: 12:56:26.490: X Error: BadMatch (invalid parameter attributes)

Thread 1 "tilda" received signal SIGTRAP, Trace/breakpoint trap.
_g_log_abort (breakpoint=breakpoint@entry=1)
    at ../../../../glib/gmessages.c:583
583 ../../../../glib/gmessages.c: No such file or directory.
(gdb) 
(gdb) 
(gdb) bt
#0  0x00007ffff64adea1 in _g_log_abort (breakpoint=breakpoint@entry=1)
    at ../../../../glib/gmessages.c:583
#1  0x00007ffff64b0819 in g_log_writer_default (log_level=6, 
    log_level@entry=G_LOG_LEVEL_ERROR, fields=fields@entry=0x7fffffffcc90, n_fields=n_fields@entry=6, user_data=user_data@entry=0x0)
    at ../../../../glib/gmessages.c:2735
#2  0x00007ffff64aea8e in g_log_structured_array (log_level=G_LOG_LEVEL_ERROR, fields=0x7fffffffcc90, n_fields=6) at ../../../../glib/gmessages.c:1970
#3  0x00007ffff64af4ce in g_log_structured_standard (log_domain=0x55555557c739 "tilda", log_level=G_LOG_LEVEL_ERROR, file=<optimised out>, line=<optimised out>, func=<optimised out>, message_format=<optimised out>)
    at ../../../../glib/gmessages.c:2027
#4  0x00005555555757f9 in xerror_handler (d=0x5555557d1930, e=0x7fffffffd2d0)
    at src/xerror.c:38
#5  0x00007ffff5cf48fa in _XError (dpy=dpy@entry=0x5555557d1930, rep=rep@entry=0x555556223720) at ../../src/XlibInt.c:1434
#6  0x00007ffff5cf182b in handle_error (dpy=0x5555557d1930, err=0x555556223720, in_XReply=<optimised out>) at ../../src/xcb_io.c:199
#7  0x00007ffff5cf18d5 in handle_response (dpy=dpy@entry=0x5555557d1930, response=0x555556223720, in_XReply=in_XReply@entry=0) at ../../src/xcb_io.c:320
#8  0x00007ffff5cf2205 in _XEventsQueued (dpy=dpy@entry=0x5555557d1930, mode=mode@entry=2) at ../../src/xcb_io.c:359
#9  0x00007ffff5ce3d3d in XPending (dpy=0x5555557d1930)
    at ../../src/Pending.c:55
#10 0x00007ffff723f001 in gdk_check_xpending (display=<optimised out>)
    at ../../../../../gdk/x11/gdkeventsource.c:269
#11 0x00007ffff723f001 in gdk_event_source_check (source=0x5555557feb20)
    at ../../../../../gdk/x11/gdkeventsource.c:306
#12 0x00007ffff64a7fe1 in g_main_context_check (context=context@entry=0x5555557fec10, max_priority=2147483647, fds=fds@entry=0x55555595ff30, n_fds=n_fds@entry=11) at ../../../../glib/gmain.c:3735
#13 0x00007ffff64a8570 in g_main_context_iterate (context=0x5555557fec10, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimised out>)
    at ../../../../glib/gmain.c:3899
#14 0x00007ffff64a8962 in g_main_loop_run (loop=0x555555df8460)
    at ../../../../glib/gmain.c:4098
#15 0x00007ffff76fca25 in gtk_main () at ../../../../gtk/gtkmain.c:1323
#16 0x0000555555562ffe in main (argc=1, argv=0x7fffffffd868) at src/tilda.c:779
(gdb)

Full log here here

whitty commented 3 years ago

Perhaps relevant information might be that I have focus follows mouse (aka Sloppy Focus)?

Also looks like its probably actually during hiding

whitty commented 3 years ago

A little bit more information - I've been running under GDB and xtrace. The failed message is SetInputFocus.

The output from xtrace around that time is below - I'm going to re-run with timestamps to ensure I can find all of the operations at the point where the fatal event is happening:

005:>:022b: Event PropertyNotify(28) window=0x06e00005 atom=0x155("_NET_WM_STATE") time=0x098c93b1 state=NewValue(0x00)
002:>:2dc5: Event PropertyNotify(28) window=0x00000289 atom=0x14a("_NET_ACTIVE_WINDOW") time=0x098c93b1 state=NewValue(0x00)
000:>:18855: Event PropertyNotify(28) window=0x06800007 atom=0x155("_NET_WM_STATE") time=0x098c93b1 state=NewValue(0x00)
005:>:022b: Event PropertyNotify(28) window=0x06e00005 atom=0x180("_GTK_EDGE_CONSTRAINTS") time=0x098c93b1 state=NewValue(0x00)
005:<:022c:  8: XInputExtension-Request(131,48): XIQueryDevice device=unknown:0x000b
000:>:18855: Event PropertyNotify(28) window=0x06800007 atom=0x180("_GTK_EDGE_CONSTRAINTS") time=0x098c93b1 state=NewValue(0x00)
005:>:022c: Event PropertyNotify(28) window=0x00000289 atom=0x14a("_NET_ACTIVE_WINDOW") time=0x098c93b1 state=NewValue(0x00)
000:>:18855: Event PropertyNotify(28) window=0x00000289 atom=0x14a("_NET_ACTIVE_WINDOW") time=0x098c93b1 state=NewValue(0x00)
000:>:18855: Event (generated) ClientMessage(33) format=0x20 window=0x06800007 type=0x147("WM_PROTOCOLS") data=0x48,0x01,0x00,0x00,0xa3,0x93,0x8c,0x09,0x1f,0x00,0x00,0x00,0x60,0x98,0xc5,0x03,0x60,0x98,0xc5,0x03;
005:>:022c:556: Reply to XIQueryDevice: deviceinfo={device=11 use=SlavePointer(0x0003) attachment=0x0002 enabled=true(0x01) name='bcm5974' classes={type=ButtonClass(0x0001) sourceid=11 state=0x00000000 labels=0x9b("Button Left"),0x9c("Button Middle"),0x9d("Button Right"),0x9e("Button Wheel Up"),0x9f("Button Wheel Down"),0xa0("Button Horiz Wheel Left"),0xa1("Button Horiz Wheel Right"),0x0,0x0,0x0,0x0,0x0;},{type=AxisClass(0x0002) sourceid=11 label=0xa2("Rel X") min=-4750/0 max=5280/0 value=-1608/2765669749 resolution=94000 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0xa3("Rel Y") min=-150/0 max=6730/0 value=2371/1519109364 resolution=92000 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x115("Rel Horiz Scroll") min=0/0 max=-1/0 value=-38071/3033105904 resolution=0 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x114("Rel Vert Scroll") min=0/0 max=-1/0 value=-28153/36721971 resolution=0 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x116("Abs MT Touch Major") min=-1/0 max=-1/0 value=0/0 resolution=0 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x117("Abs MT Touch Minor") min=-1/0 max=-1/0 value=0/0 resolution=0 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x118(unrecognized atom) min=-1/0 max=-1/0 value=0/0 resolution=0 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x119(unrecognized atom) min=-1/0 max=-1/0 value=0/0 resolution=0 mode=0x00 },{type=AxisClass(0x0002) sourceid=11 label=0x11a("Abs MT Orientation") min=-1/0 max=-1/0 value=0/0 resolution=0 mode=0x00 },{type=unknown:0x0003 sourceid=11 pad=0x00060003,0x0002000b,0x00000002,0x00000000,0x000000f3,0x00000000;},{type=unknown:0x0003 sourceid=11 pad=0x00060003,0x0003000b,0x00000001,0x00000000,0x000000f3,0x00000000;};};
000:<:18856: 24: Request(20): GetProperty delete=false(0x00) window=0x06800007 property=0x155("_NET_WM_STATE") type=0x4("ATOM") long-offset=0x00000000 long-length=0xffffffff
000:>:8856:44: Reply to GetProperty: type=0x4("ATOM") bytes-after=0x00000000 data=0x156("_NET_WM_STATE_ABOVE"),0x15f("_NET_WM_STATE_STICKY"),0x170("_NET_WM_STATE_FOCUSED");
005:<:022d: 24: Request(20): GetProperty delete=false(0x00) window=0x06e00005 property=0x155("_NET_WM_STATE") type=0x4("ATOM") long-offset=0x00000000 long-length=0x00000400
005:>:022d:32: Reply to GetProperty: type=0x4("ATOM") bytes-after=0x00000000 data=;
005:<:022e: 16: Request(2): ChangeWindowAttributes window=0x06e00005 value-list={cursor=0x06e00011}
000:<:18857: 24: Request(20): GetProperty delete=false(0x00) window=0x06800007 property=0x180("_GTK_EDGE_CONSTRAINTS") type=0x6("CARDINAL") long-offset=0x00000000 long-length=0xffffffff
000:>:8857:36: Reply to GetProperty: type=0x6("CARDINAL") bytes-after=0x00000000 data=0x000000aa;
000:<:18858: 12: Request(42): SetInputFocus revert-to=Parent(0x02) focus=0x06800008 time=0x098c93a3
000:>:8858:Error 8=Match: major=42, minor=0, bad=109051912

Now I don't undertstand much except the "BadMatch" says: bad=109051912 which is 0x06800008 the focus parameter of the SetInputFocus. I note that that is not the window that was being checked immediately above 0x06800007. I can't map this to the tilda code yet though.

whitty commented 3 years ago

Attaching X logs from just before the trigger key (F1) was pressed. I really can't see what the problem could be.

last3.txt.gz

On the failing window 0x06800008 I only see _NET_WM_USER_TIME sets and SetInputFocus messages which look like standard "set focus" boilerplate. I don't see any obvious difference accounting for the failure (but then I don't know X)

ranjan-purbey commented 3 years ago

Disabling "Always on Top" option apparently fixes the crash for me

kabel-voidship commented 3 years ago

Can confirm -- disabling "Always on Top" fixes issue.

ranjan-purbey commented 3 years ago

Possibly fixed by https://github.com/lanoxx/tilda/pull/434

lanoxx commented 3 years ago

Unfortunately I have no idea why disabling the "Always on Top" option affects this. But I have merged pull request #434 today which I believe should fix this problem. The comments on the pull request also provide some additional information about this problem.

This issue should be fixed in version 1.5.3 through commit f7d5ffd0381cb3815873efcf15d53ae0c7e16a98.