Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Problem]: “Bus error (core dumped)” when trying to play a playlist from OwnTone with MQTT enabled #1910

Open
2 tasks done
aaronk6 opened this issue Sep 24, 2024 · 3 comments

Comments

@aaronk6
Copy link

aaronk6 commented Sep 24, 2024

What happened?

When I try to play a playlist from OwnTone on a shairport-sync speaker, shairport-sync crashes with the message “Bus error (core dumped)”.

I’m still investigating this, but I can reliably reproduce this with multiple playlists that contain Spotify tracks. In contrast, radio streams (via OwnTone) work fine.

I will add more findings later, but maybe this is already helpful at this stage. Let me know if there’s anything else I should try to narrow it down.

Relevant log output

bad_dg_1     |         48.034405397 "rtsp.c:5677" Connection 3: New connection from 192.168.88.150:59118 to self at 192.168.88.8:7000.
bad_dg_1     |          0.000695982 "rtsp.c:2632" OPTIONS request
bad_dg_1     |          0.001671129 "rtsp.c:2632"   Type: "CSeq", content: "1"
bad_dg_1     |          0.000050019 "rtsp.c:2632"   Type: "User-Agent", content: "owntone/28.10"
bad_dg_1     |          0.000047611 "rtsp.c:2632"   Type: "Client-Instance", content: "68906BCA5356CD45"
bad_dg_1     |          0.000044815 "rtsp.c:2632"   Type: "DACP-ID", content: "68906BCA5356CD45"
bad_dg_1     |          0.000042963 "rtsp.c:2632"   Type: "Active-Remote", content: "3232258051"
bad_dg_1     |          0.000041074 "rtsp.c:2632"   No Content Plist. Content length: 0.
bad_dg_1     |          0.001705907 "rtsp.c:4497" Connection 3: ANNOUNCE
bad_dg_1     |          0.000074834 "rtsp.c:586" Connection 3: request to acquire principal_conn.
bad_dg_1     |          0.000048240 "rtsp.c:4501" Connection 3: ANNOUNCE has acquired play lock.
bad_dg_1     |          0.003470852 "rtsp.c:4543" Connection 3: Classic AirPlay connection from 192.168.88.150:59118 to self at 192.168.88.8:7000.
bad_dg_1     |          0.000103074 "rtsp.c:4719" Play connection from user agent "owntone/28.10" on RTSP conversation thread 3.
bad_dg_1     |          0.000502148 "rtsp.c:4751" Connection 3: ANNOUNCE has completed.
bad_dg_1     |          0.001764871 "rtsp.c:3453" Connection 3: SETUP
bad_dg_1     |          0.000074592 "rtsp.c:3460" Connection 3: SETUP: Active-Remote string seen: "3232258051".
bad_dg_1     |          0.002293482 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/active_remote_id
bad_dg_1     |          0.000169704 "rtsp.c:3480" Connection 3: SETUP: DACP-ID string seen: "68906BCA5356CD45".
bad_dg_1     |          0.000427518 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/dacp_id
bad_dg_1     |          0.000150222 "rtp.c:1033" Connection 3: SETUP -- Connection from 192.168.88.150 to self at 192.168.88.8.
bad_dg_1     |          0.000282908 "rtsp.c:3542" Connection 3: SETUP DACP-ID "68906BCA5356CD45" from 192.168.88.150 to 192.168.88.8 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
bad_dg_1     |          0.000503537 "metadata_hub.c:570" MH Client IP set to: "192.168.88.150"
bad_dg_1     |          0.000388722 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/client_ip
bad_dg_1     |          0.000563981 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/server_ip
bad_dg_1     |          0.001666482 "rtsp.c:1575" Connection 3: RECORD
bad_dg_1     |          0.000051648 "dbus-service.c:226" Build metadata
bad_dg_1     |          0.000017000 "rtsp.c:1581" Connection 3: Classic AirPlay connection from 192.168.88.150:59118 to self at 192.168.88.8:7000.
bad_dg_1     |          0.000066685 "activity_monitor.c:64" abeg
bad_dg_1     |          0.000564389 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/active_start
bad_dg_1     |          0.000601482 "player.c:3611" Connection 3: player_play.
bad_dg_1     |          0.000787981 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/play_start
bad_dg_1     |          0.000654556 "activity_monitor.c:167" am_state: am_active
bad_dg_1     |          0.001466814 "rtsp.c:3612" Connection 3: request to set AirPlay Volume to: -10.800000.
bad_dg_1     |          0.004714556 "mpris-service.c:167" Build metadata
bad_dg_1     |          0.001986778 "metadata_hub.c:622" MH Server IP set to: "192.168.88.8"
bad_dg_1     |          0.002056685 "dbus-service.c:226" Build metadata
bad_dg_1     |          0.000876981 "dbus-service.c:636" >> setting volume to -10.8000.
bad_dg_1     |          0.000084537 "player.c:3476" Software attenuation set to -1733.400031, i.e 8907.993989 out of 65,536, for airplay volume of -10.800000
bad_dg_1     |          0.000038149 "loudness.c:47" Volume: -17.3 dB - Loudness gain @10Hz: 0.0 dB
bad_dg_1     |          0.000084314 "player.c:3517" player_volume_without_notification: volume mode is 0, airplay volume is -10.80, software_attenuation dB: -17.33, hardware_attenuation dB: 0.00, muting is disabled.
bad_dg_1     |          0.000284778 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/volume
bad_dg_1     |          0.002194259 "mpris-service.c:167" Build metadata
bad_dg_1     |          0.001548815 "dbus-service.c:226" Build metadata
bad_dg_1     |          0.000555834 "mpris-service.c:167" Build metadata
bad_dg_1     |          0.001010222 "mqtt.c:108" [MQTT]: publishing under shairport-sync/bad_dg/title
bad_dg_1     | Bus error (core dumped)
bad_dg_1     | s6-rc: info: service legacy-services: stopping
bad_dg_1     | s6-rc: info: service legacy-services successfully stopped
bad_dg_1     | s6-rc: info: service syslogd: stopping
bad_dg_1     | s6-rc: info: service 04-nqptp: stopping
bad_dg_1     | s6-rc: info: service 03-avahi: stopping
bad_dg_1     | Got SIGTERM, quitting.

System Information.

Raspberry Pi 4 (2 GB)

Configuration Information.

# shairport-sync --displayConfig
         0.000969407 "shairport.c:2129" >> Display Config Start.
         0.006077056 "shairport.c:2129"
         0.000043481 "shairport.c:2129" From "uname -a":
         0.000154334 "shairport.c:2129"  Linux dc15a8711008 6.1.0-rpi4-rpi-v8 #1 SMP PREEMPT Debian 1:6.1.54-1+rpt2 (2023-10-05) aarch64 Linux
         0.008257481 "shairport.c:2129"
         0.000046130 "shairport.c:2129" From /etc/os-release:
         0.000048926 "shairport.c:2129"  Alpine Linux v3.17
         0.003254870 "shairport.c:2129"
         0.000076519 "shairport.c:2129" Shairport Sync Version String:
         0.000042018 "shairport.c:2129"  4.3.4-dirty-AirPlay2-smi10-alac-OpenSSL-Avahi-ALSA-pa-dummy-stdout-pipe-soxr-convolution-metadata-mqtt-dbus-mpris-sysconfdir:/etc
         0.000103778 "shairport.c:2129"
         0.000054148 "shairport.c:2129" Command Line:
         0.000388056 "shairport.c:2129"  shairport-sync --displayConfig
         0.000153870 "shairport.c:2129"
         0.000047482 "shairport.c:2129" Configuration File:
         0.000043666 "shairport.c:2129"  /etc/shairport-sync.conf
         0.000039148 "shairport.c:2129"
         0.000656500 "shairport.c:2129" Configuration File Settings:
         0.000058778 "shairport.c:2129"  general :
         0.000041871 "shairport.c:2129"  {
         0.000043796 "shairport.c:2129"    name = "Bad DG";
         0.000043111 "shairport.c:2129"    output_backend = "pa";
         0.000038926 "shairport.c:2129"    airplay_device_id = 0x242C0A85803L;
         0.000228370 "shairport.c:2129"  };
         0.000227926 "shairport.c:2129"  sessioncontrol :
         0.000024759 "shairport.c:2129"  {
         0.000032112 "shairport.c:2129"    allow_session_interruption = "yes";
         0.000019111 "shairport.c:2129"  };
         0.000027166 "shairport.c:2129"  pa :
         0.000019648 "shairport.c:2129"  {
         0.000019408 "shairport.c:2129"    sink = "bad_dg";
         0.000018852 "shairport.c:2129"  };
         0.000122185 "shairport.c:2129"  diagnostics :
         0.000187759 "shairport.c:2129"  {
         0.000041519 "shairport.c:2129"    log_verbosity = 2;
         0.000060166 "shairport.c:2129"  };
         0.000048871 "shairport.c:2129"  metadata :
         0.000038333 "shairport.c:2129"  {
         0.000037167 "shairport.c:2129"    enabled = "yes";
         0.000117981 "shairport.c:2129"    include_cover_art = "yes";
         0.000071685 "shairport.c:2129"    cover_art_cache_directory = "/tmp/shairport-sync/.cache/coverart";
         0.000070241 "shairport.c:2129"    pipe_name = "/tmp/shairport-sync-metadata";
         0.000056019 "shairport.c:2129"    pipe_timeout = 5000;
         0.000032314 "shairport.c:2129"  };
         0.000019926 "shairport.c:2129"  mqtt :
         0.000019056 "shairport.c:2129"  {
         0.000019259 "shairport.c:2129"    enabled = "yes";
         0.000019241 "shairport.c:2129"    hostname = "homeassistant.example.com";
         0.000193648 "shairport.c:2129"    port = 1883;
         0.000021722 "shairport.c:2129"    username = "shairport";
         0.000017778 "shairport.c:2129"    password = "redacted";
         0.000031519 "shairport.c:2129"    topic = "shairport-sync/bad_dg";
         0.000040592 "shairport.c:2129"    publish_raw = "no";
         0.000038519 "shairport.c:2129"    publish_parsed = "yes";
         0.000038778 "shairport.c:2129"    publish_cover = "no";
         0.000040388 "shairport.c:2129"    enable_autodiscovery = "yes";
         0.000116926 "shairport.c:2129"    enable_remote = "no";
         0.000231463 "shairport.c:2129"  };
         0.000023297 "shairport.c:2129"
         0.000017648 "shairport.c:2129" >> Display Config End.
         0.000031666 "shairport.c:2131" >> Goodbye!
         0.000044389 "shairport.c:1592" exit function called...
         0.000059908 "shairport.c:1602" Stopping the activity monitor.
         0.000040777 "shairport.c:1604" Stopping the activity monitor done.
         0.000063445 "shairport.c:1607" Stopping DACP Monitor
         0.000043333 "shairport.c:1609" Stopping DACP Monitor Done
         0.000038611 "shairport.c:1620" Stopping D-Bus service
         0.000377556 "dbus-service.c:1219" stopping dbus service
         0.000176611 "shairport.c:1622" Stopping D-Bus service done
         0.000139685 "shairport.c:1638" Stopping metadata hub
         0.000022945 "shairport.c:1640" Stopping metadata done
         0.000018000 "shairport.c:1644" Stopping metadata
         0.000038074 "shairport.c:1646" Stopping metadata done
         0.000125018 "shairport.c:1729" normal exit

PulseAudio or PipeWire installed?

  • Check if your system uses a Sound Server.

How did you install Shairport Sync?

Docker

Check previous issues

  • Confirm
@aaronk6
Copy link
Author

aaronk6 commented Sep 24, 2024

Turns out it only happens when MQTT is enabled.

@aaronk6 aaronk6 changed the title [Problem]: Crashing with “Bus error (core dumped)” when trying to play a playlist from OwnTone [Problem]: “Bus error (core dumped)” when trying to play a playlist from OwnTone with MQTT enabled Sep 24, 2024
@mikebrady
Copy link
Owner

Thanks. I’m away from my machines for about the next two weeks, so it’ll take a little while to fix this, I’m afraid.

@aaronk6
Copy link
Author

aaronk6 commented Sep 25, 2024

No worries, I’ll see if I can further narrow it done in the meantime.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants