badaix / snapcast

Synchronous multiroom audio player
GNU General Public License v3.0
6.12k stars 454 forks source link

Connecting to metadata from shairport-sync fails on FreeBSD - Race condition? #624

Closed jonahquark81 closed 4 years ago

jonahquark81 commented 4 years ago

Running the latest version on FreeBSD the initial setup of the metadata pipe from shairport-sync fails.

root@multimedia:/usr/local/src/shairport-sync-metadata-reader # /usr/local/bin/snapserver --stream.stream 'airplay:///usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast' --logging.filter \*:debug
2020-05-20 18-54-52.026 [Warn] (main) unknown configuration option: --logging.filter
2020-05-20 18-54-52.026 [Info] (main) Adding stream: airplay:///usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast
2020-05-20 18-54-52.026 [Notice] (init) Settings file: "/root/.config/snapserver/server.json"
2020-05-20 18-54-52.029 [Info] (Avahi) Adding service 'Snapcast'
2020-05-20 18-54-52.030 [Info] (start) Creating TCP acceptor for address: 0.0.0.0, port: 1705
2020-05-20 18-54-52.030 [Info] (start) Creating HTTP acceptor for address: 0.0.0.0, port: 1780
2020-05-20 18-54-52.030 [Debug] (parse) StreamUri: airplay:///usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast
2020-05-20 18-54-52.030 [Debug] (parse) StreamUri decoded: airplay:///usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast
2020-05-20 18-54-52.030 [Debug] (parse) scheme: 'airplay' tmp: '///usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast'
2020-05-20 18-54-52.030 [Debug] (parse) host: '' tmp: '/usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast' path: '/usr/local/bin/shairport-sync?name=Airplay&devicename=SnapCast'
2020-05-20 18-54-52.030 [Debug] (parse) path: '/usr/local/bin/shairport-sync' tmp: 'name=Airplay&devicename=SnapCast' query: 'name=Airplay&devicename=SnapCast'
2020-05-20 18-54-52.030 [Debug] (parse) StreamUri.toString: airplay:////usr/local/bin/shairport-sync?devicename=SnapCast&name=Airplay
2020-05-20 18-54-52.030 [Info] (PcmStream) PcmStream sampleFormat: 44100:16:2
2020-05-20 18-54-52.030 [Info] (PcmStream) metadata={
2020-05-20 18-54-52.030 [Info] (PcmStream)     "STREAM": "Airplay"
2020-05-20 18-54-52.030 [Info] (PcmStream) }
2020-05-20 18-54-52.030 [Debug] (onMetaChanged) metadata = {
2020-05-20 18-54-52.030 [Debug] (onMetaChanged)    "STREAM": "Airplay"
2020-05-20 18-54-52.030 [Debug] (onMetaChanged) }
2020-05-20 18-54-52.030 [Info] (onMetaChanged) onMetaChanged (Airplay)
2020-05-20 18-54-52.030 [Debug] (AsioStream) Chunk duration: 20 ms, frames: 882, size: 3528
2020-05-20 18-54-52.030 [Debug] (ProcessStream) Watchdog timeout: 0
2020-05-20 18-54-52.030 [Info] (start) Stream: {"fragment":"","host":"","path":"/usr/local/bin/shairport-sync","query":{"chunk_ms":"20","codec":"flac","devicename":"SnapCast","name":"Airplay","sampleformat":"44100:16:2"},"raw":"airplay:////usr/local/bin/shairport-sync?chunk_ms=20&codec=flac&devicename=SnapCast&name=Airplay&sampleformat=44100:16:2","scheme":"airplay"}
2020-05-20 18-54-52.030 [Debug] (ProcessStream) Launching: '/usr/local/bin/shairport-sync', with params: '"--name=SnapCast" --output=stdout --use-stderr --get-coverart "--metadata-pipename=/tmp/shairmeta.1124.5000" --port=5000', in path: '/usr/local/bin/'
2020-05-20 18-54-52.031 [Debug] (PosixStream) First read, initializing nextTick to now
2020-05-20 18-54-52.031 [Info] (AirplayStream) Metadata pipe opened: /tmp/shairmeta.1124.5000
2020-05-20 18-54-52.031 [Info] (start) Creating stream acceptor for address: 0.0.0.0, port: 1704
2020-05-20 18-54-52.031 [Info] (main) number of threads: 4, hw threads: 8
2020-05-20 18-54-52.031 [Error] (AirplayStream) Error while reading from metadata pipe: Bad file descriptor

This appears to be a race condition. snapserver is trying to access the pipe before shairport-sync has got going and once it gets this error it gives up trying to read the metadata.

This is running on a FreeNAS server in an iocage jail, might be a FreeBSD specific problem.

badaix commented 4 years ago

thanks, PR is merged