search

mikebrady / shairport-sync

AirPlay and AirPlay 2 audio player
Other
7.29k stars 574 forks source link

frequent crash at startup #698

Closed dheijl closed 6 years ago

dheijl commented 6 years ago

The Latest release and development version, running on Linux Lite 32 bit: when starting shairport-sync it very frequently crashes with an illegal instruction. Try to restart it a couple of times and it will finally startup normally.

Llast part of log when crashing:

_SETUP connection from 192.168.0.135 to self at 192.168.0.240 on RTSP conversation thread 1. listening for audio, control and timing on ports 6003, 6001, 6002. RTSP thread 1: RTSP Response: Type: "CSeq", content: "5" Type: "Server", content: "AirTunes/105.1" Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;serverport=6003" Type: "Session", content: "1" Range: npt=0-. RTP-Info: seq=4515;rtptime=0. CSeq: 6. User-Agent: iTunes/7.6.2 (Windows; N;). Client-Instance: 53B0A49840BFEB15. DACP-ID: 73E5AD98093F797A. Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c. Session: 1. RTSP thread 1 received an RTSP Packet of type "RECORD": Type: "Range", content: "npt=0-" Type: "RTP-Info", content: "seq=4515;rtptime=0" Type: "CSeq", content: "6" Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)" Type: "Client-Instance", content: "53B0A49840BFEB15" Type: "DACP-ID", content: "73E5AD98093F797A" Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c" Type: "Session", content: "1" Connection 1: RECORD pbeg Flush requested up to 4294967295. It seems as if 0 is special. Flush requested up to 4294967295. It seems as if 0 is special. RTSP thread 1: RTSP Response: Type: "CSeq", content: "6" Type: "Server", content: "AirTunes/105.1" Type: "Audio-Latency", content: "11025" Illegal instruction

When running it from gdb in the hope of getting a stack trace it refuses to crash...

EDIT: finally got a crash with gdb:

(gdb) run Starting program: /home/danny/Github/shairport-sync/shairport-sync [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/i386-linux-gnu/libthread_db.so.1". [New Thread 0xb7420b40 (LWP 9373)] [New Thread 0xb6c1fb40 (LWP 9374)] [New Thread 0xb62ffb40 (LWP 9375)] [New Thread 0xb5afeb40 (LWP 9376)]

Thread 5 "shairport-sync" received signal SIGILL, Illegal instruction. [Switching to Thread 0xb5afeb40 (LWP 9376)]_ __GI___pthread_rwlock_unlock (rwlock=0x808590c) at pthread_rwlock_unlock.c:38 38 pthread_rwlock_unlock.c: No such file or directory. (gdb) Quit (gdb)

dheijl commented 6 years ago

Here is a crash with -vvv running inside gdb, should enable you to locate the offending thread:

danny@danny-Amilo-Si-1520:~/Github/shairport-sync$ gdb shairport-sync 
GNU gdb (Ubuntu 7.11.1-0ubuntu1~16.5) 7.11.1
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i686-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from shairport-sync...done.
(gdb) run -vvv
Starting program: /home/danny/Github/shairport-sync/shairport-sync -vvv
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/i386-linux-gnu/libthread_db.so.1".
Looking for configuration file at full path "/etc/shairport-sync.conf"
alsa output device name is "default".
The processor is running little-endian.
Version: "3.2d50-OpenSSL-Avahi-ALSA-pa-soxr-metadata-sysconfdir:/etc"
statistics_requester status is 0.
daemon status is 0.
deamon pid file is "/var/run/shairport-sync/shairport-sync.pid".
rtsp listening port is 5000.
udp base port is 6001.
udp port range is 100.
player name is "Danny-Amilo-Si-1520".
backend is "(null)".
on-start action is "(null)".
on-stop action is "(null)".
wait-cmd status is 0.
on-start returns output is 0.
mdns backend "(null)".
userSuppliedLatency is 0.
stuffing option is "0" (0-basic, 1-soxr).
resync time is 0.050000 seconds.
allow a session to be interrupted: 0.
busy timeout time is 120.
drift tolerance is 0.001995 seconds.
password is "(null)".
ignore_volume_control is 0.
volume_max_db is not set
playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
disable_synchronization is 1.
use_mmap_if_available is 1.
output_rate is 44100.
output_format is 3 (0-unknown, 1-S8, 2-U8, 3-S16, 4-S24, 5-S24_3LE, 6-S24_3BE, 7-S32).
audio backend desired buffer length is 1.000000 seconds.
audio backend latency offset is 0.000000 seconds.
audio backend silence lead-in time is -1.000000 seconds. A value -1.0 means use the default.
volume range in dB (zero means use the range specified by the mixer): 0.
zeroconf regtype is "_raop._tcp".
decoders_supported field is 1.
use_apple_decoder is 0.
alsa_use_playback_switch_for_mute is 0.
no special mdns service interface was requested.
configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
metadata enabled is 0.
metadata pipename is "(null)".
metadata socket address is "(null)" port 0.
metadata socket packet size is "500".
get-coverart is 0.
loudness is 0.
loudness reference level is -20.000000
disable resend requests is off.
diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
[New Thread 0xb7420b40 (LWP 9735)]
avahi: service '7C41F9D07FDF@Danny-Amilo-Si-1520' group is not yet committed.
avahi: request to add "_raop._tcp" service without metadata
[New Thread 0xb6c1fb40 (LWP 9736)]
avahi: service '7C41F9D07FDF@Danny-Amilo-Si-1520' group is registering.
avahi: service '7C41F9D07FDF@Danny-Amilo-Si-1520' successfully added.
New RTSP connection from 192.168.0.135:53609 to self at 192.168.0.240:5000 on conversation thread 1.
[New Thread 0xb62ffb40 (LWP 9737)]
Successfully created RTSP receiver thread 1.
    Apple-Challenge: pJOB/CCvxt6L0UYHpDeuRw.
    CSeq: 1.
    User-Agent: iTunes/7.6.2 (Windows; N;).
    Client-Instance: 48FB6BA44E967793.
    DACP-ID: 73E5AD98093F797A.
    Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c.
RTSP thread 1 received an RTSP Packet of type "OPTIONS":
  Type: "Apple-Challenge", content: "pJOB/CCvxt6L0UYHpDeuRw"
  Type: "CSeq", content: "1"
  Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)"
  Type: "Client-Instance", content: "48FB6BA44E967793"
  Type: "DACP-ID", content: "73E5AD98093F797A"
  Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c"
Connection 1: OPTIONS
RTSP thread 1: RTSP Response:
  Type: "Apple-Response", content: "wX3x6bZpKF04NW+VOjyQsA5IYkTH9It18p5E+yWN0wxhuIIj/BLJ2/00QmpkA2jaH4lczeVeg7q2JFjZpK1sB8wY4pk/CbqP4+zxjmOuCstpnrbA/k0s/SIWUsoZQPqSHt5mt8cEDjwCMQhQYjfhgo5/4okWWBcM0DH2I+sSMkdCB3gnDlDPz6l++XPYmNqIIoOpuEV5DumFix2UlczIN4QK/vjWGXNWuzOjrIEsWDtmR+cMgJFN6/OARnu6CSnQdSpIv8SmCPaV8RC5GMO5W6C6IrFcfsGMQSMi71qdEiD4BLuMdKikQ78F8QM1PP1YdrpIobJ5yHA1xi4uNvlmRw"
  Type: "CSeq", content: "1"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
    Apple-Challenge: Lt/upDbjpCeFGIJXqBFsdg.
    CSeq: 2.
    User-Agent: iTunes/7.6.2 (Windows; N;).
    Client-Instance: 48FB6BA44E967793.
    DACP-ID: 73E5AD98093F797A.
    Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c.
RTSP thread 1 received an RTSP Packet of type "OPTIONS":
  Type: "Apple-Challenge", content: "Lt/upDbjpCeFGIJXqBFsdg"
  Type: "CSeq", content: "2"
  Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)"
  Type: "Client-Instance", content: "48FB6BA44E967793"
  Type: "DACP-ID", content: "73E5AD98093F797A"
  Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c"
Connection 1: OPTIONS
RTSP thread 1: RTSP Response:
  Type: "Apple-Response", content: "z1FxVa+xb1ENBMF+A9zsDIWyRO63C5Rf5THT0RFbJ9gXWr4FLjq88TMVXqYmgTlBnF0QCQQSIcIf4Gwm0UqtkVpPzzFPaU3TmQ68LlKPLNSmcPE0QQTcAfzuDZhb/Y0/jSNdFvfAbr1JFb7CjopZ6GghsmlH+Zw5KIBRuPyqncMJMKO0cAR5oY8B5wEgRutAF2t3N/Wsocyj+rVJW8Fl5crcc9KOyOtXSlSpFw4SZ0mBlgoXPOAY01uvJWEG95BH4gZXSY2vJb2GJw6P43eaPOv6pWTXmQSRCEc70T3VfMvGzlJ3f9/sGFfbi+dGSE65nKvtnU0tBAmTtxdvP6eQPQ"
  Type: "CSeq", content: "2"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
    Apple-Challenge: 5O+bXjA5gTxmx1gYIW/BoQ.
    CSeq: 3.
    User-Agent: iTunes/7.6.2 (Windows; N;).
    Client-Instance: 48FB6BA44E967793.
    DACP-ID: 73E5AD98093F797A.
    Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c.
RTSP thread 1 received an RTSP Packet of type "OPTIONS":
  Type: "Apple-Challenge", content: "5O+bXjA5gTxmx1gYIW/BoQ"
  Type: "CSeq", content: "3"
  Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)"
  Type: "Client-Instance", content: "48FB6BA44E967793"
  Type: "DACP-ID", content: "73E5AD98093F797A"
  Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c"
Connection 1: OPTIONS
RTSP thread 1: RTSP Response:
  Type: "Apple-Response", content: "u1QskrdOBwsY5pX9OBIGFfV6dnJu0GOSYyBzBa6UMU/+j1KhS0yFBkez9u5IKbrSwesrZfxGjU/Kbhs6hDQIgYEwajc9LH+aPW7e9We4DRydkRvhviyxigUSBJQjTa6jcJwcC28EXwvjU4GDGMMahzdpGc1vzGd3tUyFkkP0+aKps3inGujViVy0gDksUeFIwizWOYsAEt/TKmdenZiORwhfzV/Zb2DVaJGd/5R8y9S6M6QYIDlZfr3JI9xKys5brnGD0fbJ0V4TqNFYD5mKrS52XJclbcuXd/zb71CaknP+u6kvww7QQUcWnMXQw3Zq6km+A89zUK345Sy/QD4Fyg"
  Type: "CSeq", content: "3"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
    Client-computer-name: DANNY-PC.
    Content-Type: application/sdp.
    Content-Length: 574.
    CSeq: 4.
    User-Agent: iTunes/7.6.2 (Windows; N;).
    Client-Instance: 48FB6BA44E967793.
    DACP-ID: 73E5AD98093F797A.
    Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c.
RTSP thread 1 received an RTSP Packet of type "ANNOUNCE":
  Type: "Client-computer-name", content: "DANNY-PC"
  Type: "Content-Type", content: "application/sdp"
  Type: "Content-Length", content: "574"
  Type: "CSeq", content: "4"
  Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)"
  Type: "Client-Instance", content: "48FB6BA44E967793"
  Type: "DACP-ID", content: "73E5AD98093F797A"
  Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c"
Connection 1: ANNOUNCE
RTSP conversation thread 1 has acquired play lock.
Play connection from user agent "iTunes/7.6.2 (Windows; N;)" on RTSP conversation thread 1.
RTSP thread 1: RTSP Response:
  Type: "CSeq", content: "4"
  Type: "Server", content: "AirTunes/105.1"
    Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6002;timing_port=6003.
    CSeq: 5.
    User-Agent: iTunes/7.6.2 (Windows; N;).
    Client-Instance: 48FB6BA44E967793.
    DACP-ID: 73E5AD98093F797A.
    Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c.
RTSP thread 1 received an RTSP Packet of type "SETUP":
  Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6002;timing_port=6003"
  Type: "CSeq", content: "5"
  Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)"
  Type: "Client-Instance", content: "48FB6BA44E967793"
  Type: "DACP-ID", content: "73E5AD98093F797A"
  Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c"
Connection 1: SETUP
Note: no Active-Remote information  the SETUP Record.
DACP-ID string seen: "73E5AD98093F797A".
rtp_setup: cport=6002 tport=6003.
SETUP connection from 192.168.0.135 to self at 192.168.0.240 on RTSP conversation thread 1.
listening for audio, control and timing on ports 6003, 6001, 6002.
RTSP thread 1: RTSP Response:
  Type: "CSeq", content: "5"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
  Type: "Session", content: "1"
    Range: npt=0-.
    RTP-Info: seq=6319;rtptime=0.
    CSeq: 6.
    User-Agent: iTunes/7.6.2 (Windows; N;).
    Client-Instance: 48FB6BA44E967793.
    DACP-ID: 73E5AD98093F797A.
    Client-instance-identifier: d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c.
    Session: 1.
RTSP thread 1 received an RTSP Packet of type "RECORD":
  Type: "Range", content: "npt=0-"
  Type: "RTP-Info", content: "seq=6319;rtptime=0"
  Type: "CSeq", content: "6"
  Type: "User-Agent", content: "iTunes/7.6.2 (Windows; N;)"
  Type: "Client-Instance", content: "48FB6BA44E967793"
  Type: "DACP-ID", content: "73E5AD98093F797A"
  Type: "Client-instance-identifier", content: "d1c2f19e-1b60-4e70-9e26-98fef7a9cf4c"
  Type: "Session", content: "1"
Connection 1: RECORD
pbeg
[New Thread 0xb5afeb40 (LWP 9743)]
Flush requested up to 4294967295. It seems as if 0 is special.
Flush requested up to 4294967295. It seems as if 0 is special.
RTSP thread 1: RTSP Response:
  Type: "CSeq", content: "6"
  Type: "Server", content: "AirTunes/105.1"
  Type: "Audio-Latency", content: "11025"

Thread 5 "shairport-sync" received signal SIGILL, Illegal instruction.
[Switching to Thread 0xb5afeb40 (LWP 9743)]
__GI___pthread_rwlock_unlock (rwlock=0x8085914) at pthread_rwlock_unlock.c:38
38  pthread_rwlock_unlock.c: No such file or directory.
(gdb)
mikebrady commented 6 years ago

This is great, thanks. Let me try to track it down.

mikebrady commented 6 years ago

Hi there. What program are you using to send the audio please? It identifies as iTunes/7.6.2 (Windows; N;), but I wonder if it is something else?

dheijl commented 6 years ago

It's Airfoil for Windows.

mikebrady commented 6 years ago

Thanks.

dheijl commented 6 years ago

Forgot to add the backtrace, sorry:

Thread 5 "shairport-sync" received signal SIGILL, Illegal instruction.
[Switching to Thread 0xb5afeb40 (LWP 14320)]
__GI___pthread_rwlock_unlock (rwlock=0x8085914) at pthread_rwlock_unlock.c:38
38  pthread_rwlock_unlock.c: No such file or directory.
(gdb) bt
#0  __GI___pthread_rwlock_unlock (rwlock=0x8085914) at pthread_rwlock_unlock.c:38
#1  0x0805a38d in player_thread_func (arg=0x8085788) at player.c:1437
#2  0xb7ba3295 in start_thread (arg=0xb5afeb40) at pthread_create.c:333
#3  0xb7a4b0ae in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:114
(gdb)
mikebrady commented 6 years ago

Fantastic stuff. I found a silly mhistake and pushed a fix just now as 3.2d51. If you got a chance to check if it removes the crash, I'd be grateful. (I can't get it to crash on my system, but there is definitely a mistake that could cause the problem.)

In your first post, did you mean this crash occurs on the master branch as well as the development branch? (I hope not!)

Many thanks.

dheijl commented 6 years ago

I had it both on the published branch (apt-get install) and on the development branch... Give me 10 minutes. EDIT: I'm not sure about the master branch now that I think about it, I used a shortcut that might have pointed to the development branch, sorry about that.

dheijl commented 6 years ago

And it's fixed in the development branch, thanks!

mikebrady commented 6 years ago

Great, and thanks for your help finding that bug!