owntone / owntone-server

Linux/FreeBSD DAAP (iTunes) and MPD audio server with support for AirPlay 1 and 2 speakers (multiroom), Apple Remote (and compatibles), Chromecast, Spotify and internet radio.
https://owntone.github.io/owntone-server
GNU General Public License v2.0
2.09k stars 237 forks source link

OT crashes after waking up Laptop (Elementary OS 5.1, Pulseaudio) #1268

Closed LordMyschkin closed 3 years ago

LordMyschkin commented 3 years ago

Most recent Owntone version from github. uname -a: Linux eOS-MBA 5.4.0-74-generic #83~18.04.1-Ubuntu SMP Tue May 11 16:01:00 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Most of the times when I wake my Laptop up by opening the lid, OT stops Log tells: [2021-06-09 13:18:54] [ LOG] main: Got SIGTERM or SIGINT [2021-06-09 13:18:54] [ LOG] main: Stopping gracefully [2021-06-09 13:18:54] [ LOG] main: mDNS deinit [2021-06-09 13:18:54] [ LOG] main: Remote pairing deinit [2021-06-09 13:18:54] [ LOG] main: MPD deinit [2021-06-09 13:18:54] [ LOG] main: HTTPd deinit [2021-06-09 13:19:02] [ LOG] main: Player deinit [2021-06-09 13:19:02] [ LOG] web: LWS Cannot write to dummy pipe[2021-06-09 13:19:02] [ LOG] web: LWS Cannot write to dummy pipe[2021-06-09 13:19:02] [ LOG] laudio: Pulseaudio terminated [2021-06-09 13:19:02] [ LOG] event: event.c:1643: Assertion ev != NULL failed in event_process_active_single_queue

Syslog tells:

Jun 9 13:18:53 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] ratelimit.c: 490 events suppressed Jun 9 13:18:53 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 13:18:53 eOS-MBA pulseaudio[1477]: message repeated 10 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 13:18:54 eOS-MBA systemd[1]: Reloading OpenBSD Secure Shell server. Jun 9 13:18:54 eOS-MBA systemd[1]: Reloaded OpenBSD Secure Shell server. Jun 9 13:18:54 eOS-MBA avahi-daemon[5552]: Got SIGTERM, quitting. Jun 9 13:18:54 eOS-MBA systemd[1]: Stopping Avahi mDNS/DNS-SD Stack... Jun 9 13:18:54 eOS-MBA avahi-daemon[5552]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address fe80::ab71:40af:3e6d:2d9e. Jun 9 13:18:54 eOS-MBA owntone[6788]: [2021-06-09 13:18:54] [ LOG] main: Got SIGTERM or SIGINT Jun 9 13:18:54 eOS-MBA owntone[6788]: [2021-06-09 13:18:54] [ LOG] main: Stopping gracefully Jun 9 13:18:54 eOS-MBA owntone[6788]: [2021-06-09 13:18:54] [ LOG] main: mDNS deinit Jun 9 13:18:54 eOS-MBA owntone[6788]: [2021-06-09 13:18:54] [ LOG] main: Remote pairing deinit Jun 9 13:18:54 eOS-MBA owntone[6788]: [2021-06-09 13:18:54] [ LOG] main: MPD deinit Jun 9 13:18:54 eOS-MBA owntone[6788]: [2021-06-09 13:18:54] [ LOG] main: HTTPd deinit Jun 9 13:18:54 eOS-MBA systemd[1]: Stopping DAAP/DACP (iTunes), RSP and MPD server, supports AirPlay and Remote... Jun 9 13:18:54 eOS-MBA avahi-daemon[5552]: Leaving mDNS multicast group on interface wlp1s0.IPv4 with address 192.168.4.15. Jun 9 13:18:54 eOS-MBA dbus-daemon[527]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.212' (uid=0 pid=2055 comm="/usr/sbin/cups-browsed " label="/usr/sbin/cups-browsed (enforce)") Jun 9 13:18:54 eOS-MBA avahi-daemon[5552]: Leaving mDNS multicast group on interface lo.IPv6 with address ::1. Jun 9 13:18:54 eOS-MBA avahi-daemon[5552]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jun 9 13:18:54 eOS-MBA nm-dispatcher[10526]: Job for avahi-daemon.socket canceled. Jun 9 13:18:54 eOS-MBA avahi-daemon[5552]: avahi-daemon 0.7 exiting. Jun 9 13:18:54 eOS-MBA systemd[1]: Stopped Avahi mDNS/DNS-SD Stack. Jun 9 13:18:54 eOS-MBA avahi: Avahi detected that your currently configured local DNS server serves Jun 9 13:18:54 eOS-MBA avahi: a domain .local. This is inherently incompatible with Avahi and thus Jun 9 13:18:54 eOS-MBA avahi: Avahi stopped itself. If you want to use Avahi in this network, please Jun 9 13:18:54 eOS-MBA avahi: contact your administrator and convince him to use a different DNS domain, Jun 9 13:18:54 eOS-MBA avahi: since .local should be used exclusively for Zeroconf technology. Jun 9 13:18:54 eOS-MBA avahi: For more information, see http://avahi.org/wiki/AvahiAndUnicastDotLocal Jun 9 13:18:54 eOS-MBA systemd[1]: Reloading OpenBSD Secure Shell server. Jun 9 13:18:54 eOS-MBA CapNetAssist: DetectCaptivePortal script triggered Jun 9 13:18:54 eOS-MBA systemd[1]: Reloaded OpenBSD Secure Shell server. Jun 9 13:18:54 eOS-MBA nm-dispatcher[10526]: <15>Jun 9 13:18:54 CapNetAssist: DetectCaptivePortal script triggered Jun 9 13:18:58 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] ratelimit.c: 490 events suppressed Jun 9 13:18:58 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 13:18:58 eOS-MBA pulseaudio[1477]: message repeated 10 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 13:19:01 eOS-MBA nm-dispatcher: req:2 'connectivity-change': new request (2 scripts) Jun 9 13:19:01 eOS-MBA nm-dispatcher: req:2 'connectivity-change': start running ordered scripts... Jun 9 13:19:02 eOS-MBA owntone[6788]: [2021-06-09 13:19:02] [ LOG] main: Player deinit Jun 9 13:19:02 eOS-MBA owntone[6788]: [2021-06-09 13:19:02] [ LOG] web: LWS Cannot write to dummy pipe[2021-06-09 13:19:02] [ LOG] web: LWS Cannot write to dummy pipe[2021-06-09 13:19:02] [ LOG] laudio: Pulseaudio terminated Jun 9 13:19:02 eOS-MBA owntone[6788]: [2021-06-09 13:19:02] [ LOG] event: event.c:1643: Assertion ev != NULL failed in event_process_active_single_queue Jun 9 13:19:02 eOS-MBA systemd[1]: owntone.service: Main process exited, code=killed, status=6/ABRT Jun 9 13:19:02 eOS-MBA systemd[1]: owntone.service: Failed with result 'signal'. Jun 9 13:19:02 eOS-MBA systemd[1]: Stopped DAAP/DACP (iTunes), RSP and MPD server, supports AirPlay and Remote. Jun 9 13:19:46 eOS-MBA acpid: client 647[0:0] has disconnected

ejurgensen commented 3 years ago

Do I understand correctly that this didn't happen with earlier versions? According to the log the process is being requested to terminate, but the process termination isn't going as it should.

If it is a new thing, would it then be possible for you to go back to commit df3a95b8 ('git checkout df3a95b880727384d7e21dd68935ca65c5b57882'), build & run that and see if that also has the error? It looks like the issue is related to libwebsockets, and there were some changes to that after that commit.

LordMyschkin commented 3 years ago

I am not sure if this would have happened earlier because I have setup that laptop just a few days ago, but a very similar setting (wich behaves quite differently in some other ways too) did not show that problem . But I did step done to the above mentioned buid (thanks for your clear instructions, I do know nothing about git) and I'll report.

LordMyschkin commented 3 years ago

About the same in the older branch: Jun 9 16:48:56 eOS-MBA systemd[19887]: Closed GnuPG cryptographic agent and passphrase cache. Jun 9 16:48:56 eOS-MBA systemd[19887]: Closed GnuPG network certificate management daemon. Jun 9 16:48:56 eOS-MBA systemd[19887]: Closed GnuPG cryptographic agent (ssh-agent emulation). Jun 9 16:48:56 eOS-MBA systemd[19887]: Closed D-Bus User Message Bus Socket. Jun 9 16:48:56 eOS-MBA systemd[19887]: Stopped target Paths. Jun 9 16:48:56 eOS-MBA systemd[19887]: Reached target Shutdown. Jun 9 16:48:56 eOS-MBA systemd[19887]: Starting Exit the Session... Jun 9 16:48:56 eOS-MBA systemd[19887]: Received SIGRTMIN+24 from PID 20156 (kill). Jun 9 16:48:57 eOS-MBA systemd[1]: Stopped User Manager for UID 110. Jun 9 16:48:57 eOS-MBA systemd[1]: Removed slice User Slice of lightdm. Jun 9 16:48:57 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] ratelimit.c: 748 events suppressed Jun 9 16:48:57 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 16:48:57 eOS-MBA pulseaudio[1477]: message repeated 2 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 16:48:57 eOS-MBA acpid: client connected from 647[0:0] Jun 9 16:48:57 eOS-MBA acpid: 1 client rule loaded Jun 9 16:48:57 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 16:48:57 eOS-MBA pulseaudio[1477]: message repeated 7 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 16:49:02 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] ratelimit.c: 711 events suppressed Jun 9 16:49:02 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 16:49:02 eOS-MBA pulseaudio[1477]: message repeated 10 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 16:49:07 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] ratelimit.c: 489 events suppressed Jun 9 16:49:07 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 16:49:07 eOS-MBA pulseaudio[1477]: message repeated 10 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 16:49:12 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] ratelimit.c: 489 events suppressed Jun 9 16:49:12 eOS-MBA pulseaudio[1477]: [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue Jun 9 16:49:12 eOS-MBA pulseaudio[1477]: message repeated 10 times: [ [alsa-sink-CS4206 Analog] protocol-native.c: Failed to push data into queue] Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] mdns: Avahi state change: Client connecting Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: Got SIGTERM or SIGINT Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: Stopping gracefully Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: mDNS deinit Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: Remote pairing deinit Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: MPD deinit Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: HTTPd deinit Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] main: Player deinit Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] laudio: Pulseaudio terminated Jun 9 16:49:15 eOS-MBA owntone[19501]: [2021-06-09 16:49:15] [ LOG] player: Bug! Unsubscription request for a quality level that there is no subscription for Jun 9 16:49:15 eOS-MBA owntone[19501]: double free or corruption (fasttop) Jun 9 16:49:15 eOS-MBA systemd[1]: owntone.service: Main process exited, code=killed, status=6/ABRT Jun 9 16:49:15 eOS-MBA systemd[1]: owntone.service: Failed with result 'signal'. Jun 9 16:49:15 eOS-MBA systemd[1]: Stopped DAAP/DACP (iTunes), RSP and MPD server, supports AirPlay and Remote.

LordMyschkin commented 3 years ago

oh, this is completely unrelated to your fix of #1265 which i did not yet try out because i noticed it right now. Sorry for confusing you.

LordMyschkin commented 3 years ago

I recommend to close that one - I cannot reproduce it, because I left Elementary OS, I cannot contribute to a solution; and neither Ubuntu nor Solus shows the problem.