Closed aarondill closed 11 months ago
aarondill
commented
1 year ago The only output on stderr without the debug parameter is this message that is output on startup:
(pasystray:30798): Gdk-CRITICAL **: 02:24:45.149: gdk_window_thaw_toplevel_updates: assertion 'window->update_and_descendants_freeze_count > 0' failedIt is likely worth mentioning that nm-applet also outputs this message (and doesn't segfault), and it seems to have no effect on either application's function.
aarondill
commented
1 year ago Looking back, this can't actually be certainly ruled to even systemctl suspend, as each time this has happened, I have actually run this sequence of commands (by a keymap in my WM):
> xset +dpms dpms 5 5 5
> sleep .5 && xset dpms force off &
> i3lock -n -f -e -c 000000 && { xset dpms force on && xset dpms 0 0 0; } &
> systemctl suspendIt is theoretically possible that the issue occurs on any of these commands, however, systemctl suspend or else the i3lock command seem to be the most likely issues.
christophgysin
commented
1 year ago Could you try to reproduce the problem with the latest version from master? If so, could you open the core dump in gdb and provide a stack trace?
aarondill
commented
1 year ago Well, I have not had this issue in a few days (I have not yet updated), so I'm going to close this issue for now. I'll reopen it if and when the issue occurs.
aarondill
commented
1 year ago This issue reoccurred. I'm still on version 0.7.1, so I suppose this may not be too helpful, but I will update following this comment. The debug output of pasystray (stderr) is below. The segfault occured at 1:30 (on resume), while the last log is at 01:19 (before suspend), so it likely won't be very helpful, but here it is.
Here is the file at /var/crash/_usr_bin_pasystray.1000.crash which includes as much debugging information as I can currently provide. I am now going to update to latest, and if this bug reoccurs, I will reopen this then.
_usr_bin_pasystray.1000.crash.txt
aarondill
commented
11 months ago After updating to latest and using this for a week, I have now reproduced this.
Sadly, this time I don't have a core dump to share, because apport was not configured for non-package executables. Hopefully next time this occurs I'll have a core dump and stack trace to share.
I had a pair of headphones wirelessly connected when I suspended, then closed my laptop at 03:24, then when I came back at 03:28 and opened the laptop pasystray segfaulted.
On pressing the suspend button, my window manager runs i3lock and systemctl suspend.
When my laptop is shut, logind activates suspend-then-hibernate through HandleLidSwitch=suspend-then-hibernate.
Note: HibernateDelaySec is 30min and my laptop did not hibernate.
I have not (ever) reproduced this without having headphones connected before suspend and disconnected after suspend (they disconnect as soon as my laptop suspends).
I have not (yet) reproduced this without suspend before closing my laptop (thusly enacting suspend-then-hibernate).
I am reopening this issue as it has been reproduced on latest, however, I'd imagine we won't get anywhere with just the information I can currently provide.
aarondill
commented
11 months ago So far, the only way I can seem to reproduce this is to
i3lock and systemctl suspend)suspend-then-hibernate, the headphones now disconnect)Obviously this leaves much to be desired in terms of reproducibility, but hopefully it's a starting point for finding the issue at least.
christophgysin
commented
11 months ago If you can get it to segfault, please open the core dump in gdb and provide a stack trace.
aarondill
commented
11 months ago @christophgysin This issue occurred again. This time though, we have a core dump!
Opening the core dump in gdb results in this (truncated to only include useful information):
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `pasystray --no-icon-tooltip -d'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00007f9a623321dd in pa_sample_spec_valid () from /lib/x86_64-linux-gnu/libpulse.so.0
[Current thread is 1 (Thread 0x7f9a60b8a380 (LWP 2651))]
(gdb) bt
#0 0x00007f9a623321dd in pa_sample_spec_valid () from /lib/x86_64-linux-gnu/libpulse.so.0
#1 0x00007f9a62332b73 in pa_sample_spec_snprint () from /lib/x86_64-linux-gnu/libpulse.so.0
#2 0x000055607b9dcbef in server_info_str (i=0x0) at pulseaudio_info.c:47
#3 0x000055607b9db0ff in pulseaudio_server_add (i=0x0, userdata=0x55607d6f0010, is_new=0) at pulseaudio.c:338
#4 0x000055607b9db0d1 in pulseaudio_server_change_cb (c=0x55607da67000, i=0x0, userdata=0x55607d6f0010) at pulseaudio.c:332
#5 0x00007f9a6231bd89 in ?? () from /lib/x86_64-linux-gnu/libpulse.so.0
#6 0x00007f9a61682383 in ?? () from /usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-15.99.so
#7 0x00007f9a62e2c8df in ?? () from /lib/x86_64-linux-gnu/libpulse-mainloop-glib.so.0
#8 0x00007f9a623b4d3b in g_main_context_dispatch () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#9 0x00007f9a6240a258 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#10 0x00007f9a623b42b3 in g_main_loop_run () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#11 0x000055607b9da2eb in main (argc=1, argv=0x7ffc7a3dcbe8) at pasystray.c:54Some other potentially useful files are included in this zip: crash.zip
The files included are:
2651-stderr.log -- The stderr of the process (with a header added by my WM)
2651-stdout.log -- The stdout of the process (with a header added by my WM) (empty)
_usr_local_bin_pasystray.1000.crash - The full /var/crash/_usr_local_bin_pasystray.1000.crash file generated by apport
apport-crash/ - The unpacked /var/crash file, which includes information about the environment and the core dump itself
backtrace.log - The full output of gdb while opening the core dump.
aarondill
commented
11 months ago Here are my system logs from between the time I suspended, to just after pasystray segfaulted. There are over 300 lines, but maybe there's something helpful in them.
Also, having looked at these logs, it actually seems like suspending my system is stopping logind from detecting the lid shut, and therefore stopping suspend-then-hibernate from taking place (so step 4 in the above reproduction steps should be entirely unneeded).
aarondill
commented
11 months ago This is about as much information as I think I can provide, but if there's anything else that would help, let me know
christophgysin
commented
11 months ago 2 0x000055607b9dcbef in server_info_str (i=0x0) at pulseaudio_info.c:47
This seems to be the issue, the callback is invoked with NULL instead of a valid pa_server_info.
@aarondill Can you build from branch issue-168-segfault-after-suspend and see if that fixes the issue?
aarondill
commented
11 months ago I compiled the issue-168-segfault-after-suspend branch and still got a segfault after resume. It seems to be in a different location than the above one, so perhaps it's a second bug, but here's the backtrace:
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `pasystray --no-icon-tooltip -d'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x000055c7c52053e4 in pulseaudio_server_add (i=0x0, userdata=0x55c7c5a77010, is_new=0) at pulseaudio.c:339
339 menu_info_item_update(mi, 0, "localhost", i->host_name, NULL, 0, tooltip, NULL, NULL, -1);
[Current thread is 1 (Thread 0x7f8ff065aa80 (LWP 2853))]
b(gdb) bt full
#0 0x000055c7c52053e4 in pulseaudio_server_add (i=0x0, userdata=0x55c7c5a77010, is_new=0) at pulseaudio.c:339
mi = 0x55c7c5a77010
tooltip = 0x0
#1 0x000055c7c52053a0 in pulseaudio_server_change_cb (c=0x55c7c5bd2a90, i=0x0, userdata=0x55c7c5a77010) at pulseaudio.c:332
#2 0x00007f8ff2865d89 in () at /lib/x86_64-linux-gnu/libpulse.so.0
#3 0x00007f8ff1156383 in () at /usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-15.99.so
#4 0x00007f8ff28ab8df in () at /lib/x86_64-linux-gnu/libpulse-mainloop-glib.so.0
#5 0x00007f8ff1e14d3b in g_main_context_dispatch () at /lib/x86_64-linux-gnu/libglib-2.0.so.0
#6 0x00007f8ff1e6a258 in () at /lib/x86_64-linux-gnu/libglib-2.0.so.0
#7 0x00007f8ff1e142b3 in g_main_loop_run () at /lib/x86_64-linux-gnu/libglib-2.0.so.0
#8 0x000055c7c52045ba in main (argc=1, argv=0x7fff73a33608) at pasystray.c:54
options = 0x55c7c5211060 <entries>
error = 0x0
settings = {volume_max = 0, volume_inc = 2, reverse_scroll = 0, icon_tooltip = 1, monitors = 0, key_grabbing = 0, symbolic_icons = 0, n_new = 1, n_sink = 0, n_sink_default = 0, n_source = 0, n_source_default = 0, n_stream = 0, n_stream_output = 0, n_stream_input = 0, n_systray_action = 1}Here is another zip file, containing the same files as the one above: crash.zip
Edit: updated backtrace to run bt full in gdb
aarondill
commented
11 months ago I think menu_info_item_update can't have NULL as the tooltip. Perhaps it should be replaced with an empty string if it's NULL?
christophgysin
commented
11 months ago I think
menu_info_item_updatecan't haveNULLas the tooltip. Perhaps it should be replaced with an empty string if it'sNULL?
Give it a try, and let me know if that stops it from segfaulting.
aarondill
commented
11 months ago Wait, no.
It's the i->host_name that's causing the immediate issue. i is NULL, so this is attempting to dereference a NULL pointer.
menu_info_item_update(mi, 0, "localhost", i->host_name, NULL, 0, tooltip, NULL, NULL, -1);0 0x000055c7c52053e4 in pulseaudio_server_add (i=0x0, userdata=0x55c7c5a77010, is_new=0) at pulseaudio.c:339
339 menu_info_item_update(mi, 0, "localhost", i->host_name, NULL, 0, tooltip, NULL, NULL, -1);
Actually, this time, the crash is because of i->hostname, where i is NULL.
aarondill
commented
11 months ago Looking through the code, tooltip being NULL is actually handled in all cases, so there's no need to check that in particular. just fixing the i==NULL issue
christophgysin
commented
11 months ago Yes, the previous crash was due to server_info_str not tolerating NULL.
I updated the branch to just skip the event if pa_server_info is NULL. Can you give that a try?
aarondill
commented
11 months ago Will do. I just built it, I'm going to try it for a day or two and I'll let you know if I run into any issues.
aarondill
commented
11 months ago @christophgysin over the last two days, I've used the patch and not encountered any issues. I'll keep you updated if something happens, but it seems like that may have fixed the issue :smile:
christophgysin
commented
11 months ago @aarondill Great! I'll probably update the PR to print a warning whenever this happens and we ignore the event.
I'll also try to figure out why the callback is invoked with NULL in the first place.
christophgysin
commented
11 months ago I reported the possible bug upstream: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/-/issues/3776
christophgysin
commented
11 months ago @aarondill The fix is now merged. Please build from latest master and run from a terminal. It should not crash anymore but log an error message with possibly more details what exactly caused the NULL response. Thanks!
aarondill
commented
11 months ago @christophgysin oddly enough, on initial startup, I get this output (and successful startup):
> pasystray --no-icon-tooltip
pasystray-Message: 04:27:11.166: Failed to get sink information: OK
pasystray-Message: 04:27:11.167: Failed to get source information: OK
pasystray-Message: 04:27:11.167: Failed to get sink input information: OK
pasystray-Message: 04:27:11.167: Failed to get source output information: OK
pasystray-Message: 04:27:11.168: Failed to get module information: OK
And upon connecting my headphones, I get the following additional output (with successful connection):
pasystray-Message: 04:30:24.757: Failed to get sink information: OK
pasystray-Message: 04:30:24.757: Failed to get source information: OK
pasystray-Message: 04:30:24.757: Failed to get source information: OK
pasystray-Message: 04:30:24.857: Failed to get sink information: OK
pasystray-Message: 04:30:24.858: Failed to get module information: OK
pasystray-Message: 04:30:24.859: Failed to get sink information: OK
pasystray-Message: 04:30:29.788: Failed to get sink information: OK
pasystray-Message: 04:30:29.788: Failed to get source information: OK
pasystray-Message: 04:30:29.788: Failed to get sink information: OKAfter disconnecting and reconnecting the same headphones (with the same pasystray running), I got this instead:
pasystray-Message: 04:32:22.255: Failed to get module information: No such entity
pasystray-Message: 04:32:26.048: Failed to get module information: No such entity
pasystray-Message: 04:32:28.178: Failed to get sink information: No such entity
pasystray-Message: 04:32:28.178: Failed to get source information: No such entity
pasystray-Message: 04:32:28.178: Failed to get source information: No such entity
pasystray-Message: 04:32:28.242: Failed to get sink information: No such entity
pasystray-Message: 04:32:28.242: Failed to get module information: No such entity
pasystray-Message: 04:32:28.242: Failed to get sink information: No such entity
pasystray-Message: 04:32:33.222: Failed to get sink information: No such entity
pasystray-Message: 04:32:33.222: Failed to get source information: No such entity
pasystray-Message: 04:32:33.223: Failed to get sink information: No such entity
pasystray-Message: 04:32:42.442: Failed to get sink information: No such entity
pasystray-Message: 04:32:42.442: Failed to get source information: No such entity
pasystray-Message: 04:32:42.443: Failed to get sink input information: No such entity
pasystray-Message: 04:32:42.443: Failed to get sink information: No such entity
pasystray-Message: 04:32:42.444: Failed to get sink information: No such entity
pasystray-Message: 04:32:42.444: Failed to get sink input information: No such entityThen when I played a video:
pasystray-Message: 04:32:52.296: Failed to get sink input information: No such entity
pasystray-Message: 04:32:52.296: Failed to get sink information: No such entity
pasystray-Message: 04:32:53.252: Failed to get sink input information: No such entity
pasystray-Message: 04:32:53.254: Failed to get sink information: No such entity
pasystray-Message: 04:32:53.254: Failed to get sink input information: No such entity
pasystray-Message: 04:33:33.612: Failed to get sink input information: No such entity
pasystray-Message: 04:33:33.613: Failed to get sink information: No such entity
pasystray-Message: 04:33:38.664: Failed to get sink information: No such entity
pasystray-Message: 04:33:38.664: Failed to get source information: No such entity
pasystray-Message: 04:33:38.665: Failed to get sink information: No such entityIt seems like this commit makes pasystray very noisy. Perhaps this information should be moved behind the debug flag?
christophgysin
commented
11 months ago @aarondill Thanks for testing. I added another commit to reduce the error messages, could you try the latest build from master? Also I would be interested to see the output if you manage to reproduce the original issue. It should not crash anymore, but instead provide some more detailed information why we can't get information from your pulseaudio server.
aarondill
commented
11 months ago Recompiled. Much quieter now :smile:. Will let you know if I can reproduce the issue again
aarondill
commented
11 months ago @christophgysin I finally reproduced this issue and when I checked the output, I have only this one line (I disabled debug mode):
pasystray-Message: 23:43:22.553: Failed to get server information: TimeoutI resumed my system at 11:43 PM, so this seems to be the same issue.
christophgysin
commented
11 months ago Awesome, thanks for reporting back.
This is not a consistent issue, and I'm not certain yet what the cause is, but occasionally on resume from
systemctl suspend, pasystray segfaults. I have recently set my configuration to launch with the debug parameter and I will update with more info next time this occurs. My suspicion is that it must be suspended for a certain duration, however, I run quite a few system tray applications (for example:nm-applet,blueman, etc) and this is the only one that I experience this issue with.Some Version Info
```shell > lsb_release -a No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 22.04.2 LTS Release: 22.04 Codename: jammy > cat /etc/os-release PRETTY_NAME="Ubuntu 22.04.2 LTS" NAME="Ubuntu" VERSION_ID="22.04" VERSION="22.04.2 LTS (Jammy Jellyfish)" VERSION_CODENAME=jammy ID=ubuntu ID_LIKE=debian HOME_URL="https://www.ubuntu.com/" SUPPORT_URL="https://help.ubuntu.com/" BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/" PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy" UBUNTU_CODENAME=jammy > pasystray --version 0.7.1 > > sudo Xorg -version X.Org X Server 1.21.1.4 X Protocol Version 11, Revision 0 Current Operating System: Linux aaron-HP-Laptop-15-dy2xxx 5.19.0-45-generic #46~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Wed Jun 7 15:06:04 UTC 20 x86_64 Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.19.0-45-generic root=UUID=1a3ca66f-5c7f-4d45-9401-b86ba5e29b0a ro loglevel=3 i8042.reset atkbd.reset=1 i8042.dumbkbd i8042.direct fbcon=nodefer reboot=efi,cold resume=UUID=251a8ad6-5c96-4fbe-b2b0-52ca549f45a8 3 xorg-server 2:21.1.4-2ubuntu1.7~22.04.1 (For technical support please see http://www.ubuntu.com/support) Current version of pixman: 0.40.0 Before reporting problems, check http://wiki.x.org to make sure that you have the latest version. > pstree "$(pgrep Xorg)" -s systemd───login───bash───startx───xinit───Xorg───16*[{Xorg}] > awesome --version awesome v4.3 (Too long) • Compiled against Lua 5.3.6 (running with Lua 5.3) • D-Bus support: ✔ • execinfo support: ✔ • xcb-randr version: 1.6 • LGI version: 0.9.2 > pstree "$(pgrep x-window)" -s systemd───login───bash───startx───xinit───x-window-manage─┬─blueman-applet───3*[{blueman-applet}] ├─diodon───18*[{diodon}] ├─nm-applet───10*[{nm-applet}] ├─picom───8*[{picom}] ├─polkit-gnome-au───9*[{polkit-gnome-au}] ├─systemd-inhibit───sleep ├─udiskie───2*[{udiskie}] ├─xss-lock───2*[{xss-lock}] └─2*[{x-window-manage}] ```Please let me know if there's any other information I can provide to help find the source of this issue.