[Problem]: Assertion 'e->mainloop->n_enabled_defer_events > 0'

[Benksterinho]

What happened?

Streaming music from iphone to shairport-sync. When music is stopped shairpoint-sync aboards with error;

Assertion 'e->mainloop->n_enabled_defer_events > 0' failed at ../src/pulse/mainloop.c:261, function mainloop_defer_enable(). Aborting.

Relevant log output

shairport-sync -v
         0.001681157 "shairport.c:1729" Started!
         0.000115158 "shairport.c:1756" software version: "3.3.8-libdaemon-OpenSSL-Avahi-ALSA-jack-pa-dummy-stdout-pipe-soxr-convolution-metadata-mqtt-dbus-mpris-sysconfdir:/etc"
         0.000025052 "shairport.c:1762" log verbosity is 1.
         0.013970200 "shairport.c:1810" disable resend requests is off.
         0.000143439 "shairport.c:1811" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000068750 "shairport.c:1815" statistics_requester status is 0.
         0.000058907 "shairport.c:1817" daemon status is 0.
         0.000058177 "shairport.c:1818" daemon pid file path is "/run/shairport-sync/shairport-sync.pid".
         0.000055990 "shairport.c:1820" rtsp listening port is 5000.
         0.000055313 "shairport.c:1821" udp base port is 6001.
         0.000053386 "shairport.c:1822" udp port range is 10.
         0.000056511 "shairport.c:1823" player name is "Jimbos Box".
         0.000053594 "shairport.c:1824" backend is "pa".
         0.000054792 "shairport.c:1825" run_this_before_play_begins action is "(null)".
         0.000076042 "shairport.c:1826" run_this_after_play_ends action is "(null)".
         0.000054271 "shairport.c:1827" wait-cmd status is 0.
         0.000054532 "shairport.c:1828" run_this_before_play_begins may return output is 0.
         0.000065469 "shairport.c:1829" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000170782 "shairport.c:1830" run_this_before_entering_active_state action is  "(null)".
         0.000060574 "shairport.c:1831" run_this_after_exiting_active_state action is  "(null)".
         0.000054063 "shairport.c:1832" active_state_timeout is  10.000000 seconds.
         0.000061250 "shairport.c:1833" mdns backend "(null)".
         0.000053334 "shairport.c:1835" interpolation setting is "auto".
         0.000053542 "shairport.c:1838" interpolation soxr_delay_threshold is 30.
         0.000052917 "shairport.c:1839" resync time is 0.050000 seconds.
         0.000055990 "shairport.c:1840" allow a session to be interrupted: 0.
         0.000053177 "shairport.c:1841" busy timeout time is 120.
         0.000052344 "shairport.c:1842" drift tolerance is 0.001995 seconds.
         0.000054897 "shairport.c:1843" password is "(null)".
         0.000052552 "shairport.c:1844" ignore_volume_control is 0.
         0.000052917 "shairport.c:1848" volume_max_db is not set
         0.000052396 "shairport.c:1849" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000054949 "shairport.c:1851" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000054375 "shairport.c:1855" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000054115 "shairport.c:1857" disable_synchronization is 0.
         0.000058646 "shairport.c:1858" use_mmap_if_available is 1.
         0.000053125 "shairport.c:1859" output_format automatic selection is enabled.
         0.000053751 "shairport.c:1863" output_rate automatic selection is enabled.
         0.000053229 "shairport.c:1867" audio backend desired buffer length is 0.350000 seconds.
         0.000053855 "shairport.c:1869" audio_backend_buffer_interpolation_threshold_in_seconds is 0.020000 seconds.
         0.000057552 "shairport.c:1871" audio backend latency offset is 0.000000 seconds.
         0.000055522 "shairport.c:1873" audio backend silence lead-in time is "auto".
         0.000051823 "shairport.c:1877" zeroconf regtype is "_raop._tcp".
         0.000053021 "shairport.c:1878" decoders_supported field is 1.
         0.000052969 "shairport.c:1879" use_apple_decoder is 0.
         0.000052553 "shairport.c:1880" alsa_use_hardware_mute is 0.
         0.000053125 "shairport.c:1884" no special mdns service interface was requested.
         0.000091667 "shairport.c:1887" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000059011 "shairport.c:1894" metadata enabled is 1.
         0.000053438 "shairport.c:1895" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000054271 "shairport.c:1896" metadata socket address is "(null)" port 0.
         0.000053438 "shairport.c:1898" metadata socket packet size is "500".
         0.000053750 "shairport.c:1899" get-coverart is 1.
         0.000059636 "shairport.c:1902" mqtt is disabled.
         0.000056042 "shairport.c:1903" mqtt hostname is (null), port is 1883.
         0.000052761 "shairport.c:1904" mqtt topic is /Jimbos Box.
         0.000068073 "shairport.c:1905" mqtt will not publish raw metadata.
         0.000111460 "shairport.c:1906" mqtt will not publish parsed metadata.
         0.000056771 "shairport.c:1907" mqtt will not publish cover Art.
         0.000054740 "shairport.c:1908" mqtt remote control is disabled.
         0.000053594 "shairport.c:1912" convolution is 0.
         0.000054636 "shairport.c:1913" convolution IR file is "(null)"
         0.000063177 "shairport.c:1914" convolution max length 8192
         0.000052761 "shairport.c:1915" convolution gain is 0.000000
         0.000054271 "shairport.c:1917" loudness is 0.
         0.000052240 "shairport.c:1918" loudness reference level is -20.000000
         0.000463962 "rtsp.c:1665" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.019233309 "dbus-service.c:1053" *warning: could not acquire a Shairport Sync native D-Bus interface "org.gnome.ShairportSync.i2781" on the system bus.
         0.000270471 "mpris-service.c:348" *warning: could not acquire an MPRIS interface named "org.mpris.MediaPlayer2.ShairportSync.i2781" on the system bus.
         0.008933499 "mdns_avahi.c:375" avahi_dacp_monitor_start Avahi DACP monitor successfully started
         1.474814733 "shairport.c:200" "soxr" interpolation has been chosen.
         3.137574934 "rtsp.c:1057" Connection 1: SETUP DACP-ID "6CF452E154B00B83" from 2003:d5:6f2e:9400:6880:6125:25a:b72e to 2003:d5:6f2e:9400:5e06:5e57:53e8:93f3 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
        10.533687031 "rtsp.c:1057" Connection 2: SETUP DACP-ID "54A78AD06D36897C" from 2003:d5:6f2e:9400:6880:6125:25a:b72e to 2003:d5:6f2e:9400:5e06:5e57:53e8:93f3 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
Assertion 'e->mainloop->n_enabled_defer_events > 0' failed at ../src/pulse/mainloop.c:261, function mainloop_defer_enable(). Aborting.

System Information.

Raspi Zero 2 W 
Running raspian:
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm

Kernel:#1 SMP PREEMPT Debian 1:6.6.51-1+rpt3 (2024-10-08)

$ sudo aptitude show shairport-sync
Package: shairport-sync
Version: 3.3.8-1+b2
State: installed
Automatically installed: no
Priority: optional
Section: sound
Maintainer: Chris Boot <[email protected]>
Architecture: arm64
Uncompressed Size: 680 k
Depends: adduser, avahi-daemon, libasound2 (>= 1.0.17), libavahi-client3 (>= 0.6.16), libavahi-common3 (>= 0.6.16), libc6 (>= 2.34), libconfig9, libdaemon0 (>= 0.14), libgcc-s1 (>= 3.0), libglib2.0-0 (>= 2.37.3),
         libjack-jackd2-0 (>= 1.9.10+20150825) | libjack-0.125, libmosquitto1 (>= 1.0), libpopt0 (>= 1.14), libpulse0 (>= 0.99.1), libsndfile1 (>= 1.0.20), libsoxr0 (>= 0.1.0), libssl3 (>= 3.0.0), libstdc++6 (>=
         4.3)
PreDepends: init-system-helpers (>= 1.54~)
Conflicts: shairport-sync:armhf
Description: AirPlay audio player
 Plays audio streamed from iTunes, iOS devices and third-party AirPlay sources such as ForkedDaapd and others. Audio played by a Shairport Sync-powered device stays synchronised with the source and hence with
 similar devices playing the same source. In this way, synchronised multi-room audio is possible without difficulty.

 Shairport Sync does not support AirPlay video or photo streaming.
Homepage: https://github.com/mikebrady/shairport-sync

Configuration Information.

Linux piclt 6.6.51+rpt-rpi-v8 #1 SMP PREEMPT Debian 1:6.6.51-1+rpt3 (2024-10-08) aarch64 GNU/Linux

3.3.8-libdaemon-OpenSSL-Avahi-ALSA-jack-pa-dummy-stdout-pipe-soxr-convolution-metadata-mqtt-dbus-mpris-sysconfdir:/etc

PulseAudio or PipeWire installed?

• Check if your system uses a Sound Server.

How did you install Shairport Sync?

A package manager (apt, apt install, yum, pkg, etc.)

Check previous issues

• Confirm

[Benksterinho]

Output - Verbose 3

         0.000083491 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000032396 "rtsp.c:610"     CSeq: 19.
         0.000020625 "rtsp.c:610"     DACP-ID: 54A78AD06D36897C.
         0.000027396 "rtsp.c:610"     Active-Remote: 3109392711.
         0.000019688 "rtsp.c:610"     User-Agent: AirPlay/800.74.1.
         0.000027969 "rtsp.c:475" msg_init message 76
         0.000020989 "rtsp.c:2661" Connection 2: Received an RTSP Packet of type "OPTIONS":
         0.000033750 "rtsp.c:507"   Type: "CSeq", content: "19"
         0.000020469 "rtsp.c:507"   Type: "DACP-ID", content: "54A78AD06D36897C"
         0.000018594 "rtsp.c:507"   Type: "Active-Remote", content: "3109392711"
         0.000018282 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/800.74.1"
         0.000022604 "rtsp.c:901" Connection 2: OPTIONS
         0.000020677 "rtsp.c:2706" Connection 2: RTSP Response:
         0.000017969 "rtsp.c:507"   Type: "CSeq", content: "19"
         0.000017552 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000017969 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000128387 "rtsp.c:556" msg_free freed message 76
         0.000036719 "rtsp.c:556" msg_free freed message 75
         0.075464818 "rtsp.c:475" msg_init message 77
         0.000429066 "rtsp.c:580" RTSP Message Received: "TEARDOWN rtsp://2003:d5:6f2e:9400:5e06:5e57:53e8:93f3/5475953583297545449 RTSP/1.0".
         0.000095782 "rtsp.c:610"     CSeq: 20.
         0.000058802 "rtsp.c:610"     DACP-ID: 54A78AD06D36897C.
         0.000056043 "rtsp.c:610"     Active-Remote: 3109392711.
         0.000058437 "rtsp.c:610"     User-Agent: AirPlay/800.74.1.
         0.000063178 "rtsp.c:475" msg_init message 78
         0.000057344 "rtsp.c:2661" Connection 2: Received an RTSP Packet of type "TEARDOWN":
         0.000056146 "rtsp.c:507"   Type: "CSeq", content: "20"
         0.000278179 "rtsp.c:507"   Type: "DACP-ID", content: "54A78AD06D36897C"
         0.000062709 "rtsp.c:507"   Type: "Active-Remote", content: "3109392711"
         0.000055522 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/800.74.1"
         0.000062292 "rtsp.c:911" Connection 2: TEARDOWN
         0.000059740 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000318439 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000066563 "rtsp.c:915" TEARDOWN: synchronously terminating the player thread of RTSP conversation thread 2 (2).
         0.000057657 "player.c:3130" player_stop
         0.000061146 "player.c:3132" player_thread cancel...
         0.000080782 "player.c:3134" player_thread join...
         0.000114584 "player.c:1631" Connection 2: player thread main loop exit via player_thread_cleanup_handler.
         0.000397660 "common.c:1390" mutex_lock "&dacp_server_information_lock" at "dacp.c:383".
         0.000045260 "common.c:1413" mutex_unlock "&dacp_server_information_lock" at "dacp.c:386".
         0.000021615 "player.c:1658" Cancelling timing, control and audio threads...
         0.000018750 "player.c:1659" Cancel timing thread.
         0.000042605 "player.c:1661" Join timing thread.
         0.000176668 "rtp.c:526" Timing Receiver Cleanup.
         0.000047031 "rtp.c:551" Cancel Timing Requester.
         0.000040053 "rtp.c:555" Join Timing Requester.
         0.000160574 "rtp.c:457" Connection 2: Timing Sender Cleanup.
         0.000151876 "rtp.c:557" Timing Receiver Cleanup Successful.
         0.000131824 "player.c:1663" Timing thread terminated.
         0.000036406 "player.c:1664" Cancel control thread.
         0.000044532 "player.c:1666" Join control thread.
         0.000191512 "rtp.c:232" Control Receiver Cleanup Done.
         0.000145469 "player.c:1668" Control thread terminated.
         0.000029115 "player.c:1669" Cancel audio thread.
         0.000035521 "player.c:1671" Join audio thread.
         0.000216148 "rtp.c:97" Audio Receiver Cleanup Done.
         0.000275627 "player.c:1673" Audio thread terminated.
         0.000865683 "common.c:1390" mutex_lock "&conn->reference_time_mutex" at "rtp.c:1052".
         0.000248960 "common.c:1413" mutex_unlock "&conn->reference_time_mutex" at "rtp.c:1055".
         0.000382451 "player.c:3141" player_thread joined.
         0.000085000 "player.c:3146" pend
         0.000001354 "common.c:1390" mutex_lock "&activity_monitor_mutex" at "activity_monitor.c:115".
         0.000044948 "rtsp.c:920" TEARDOWN: successful termination of playing thread of RTSP conversation thread 2.
         0.000024480 "rtsp.c:2706" Connection 2: RTSP Response:
         0.000003593 "rtsp.c:507"   Type: "CSeq", content: "20"
         0.000010365 "rtsp.c:288" metadata queue- "hub" 0/500.
         0.000025885 "rtsp.c:1602"                     hub: type 73736e63, code 70656e64, length 0.
         0.000012136 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000085782 "rtsp.c:1606"                     hub: done.         0.000006354 "rtsp.c:288" metadata queue- "multicast" 0/500.
         0.000249690 "rtsp.c:288" metadata queue- "pipe" 0/500.
         0.000058022 "rtsp.c:1531"      pipe: type 73736e63, code 70656e64, length 0.
         0.000087344 "rtsp.c:1534"      pipe: done.

         0.000014688 "rtsp.c:507"   Type: "Connection", content: "close"
         0.000017344 "rtsp.c:288" metadata queue- "mqtt" 0/500.
         0.000071406 "rtsp.c:1565"                                                                     multicast: type 73736e63, code 70656e64, length 0.
         0.000018855 "rtsp.c:556" msg_free freed message 78
Assertion 'e->mainloop->n_enabled_defer_events > 0' failed at ../src/pulse/mainloop.c:261, function mainloop_defer_enable(). Aborting.
         0.000037708 "rtsp.c:556" msg_free freed message 77Aborted

[mikebrady]

Thanks for the report. The version of Shairport Sync you are using is very old indeed. You should update to the latest version.

[Benksterinho]

Thanks Mike
Seems - this one is the latest one in the repo. Let me pull the latest one from here. I will keep you postet

[Benksterinho]

I build the latest version out of your git repo - and so far it worked without any problems
Thanks for your time and sorry I did not realize that the version in the repo was outdated