snapcast icon indicating copy to clipboard operation
snapcast copied to clipboard

snapserver service running on debian has no sound on clients. when started manually everything works fine

Open briantho opened this issue 2 years ago • 1 comments

Describe the bug I'm running debian 11 in a vmware vm, with snapserver installed. I'm piping sound from my windows machine via snap.net broadcast. Everything works fine, but only if snapserver is stated manually. If i reboot the Debain vm running snapserver, the snapserver service starts up. The clients reconnect, and snap net broadcast also reconnects. The issue is when i try to play anything, no sound can be heard from the snapclients. It's only till i kill the snapserver service and start it manually does it work and sound can be heard on all clients

Steps to Reproduce

  1. Set up snapserver and add the "stream = tcp://?port=4953&name=snapbroadcast" line to snapserver.conf
  2. check and see if snapserver is running as a service. sudo systemctl status snapserver.service
  3. Install snap.net and start broadcasting to snapserver
  4. There should be no sound on snapclients
  5. stop snapserver service. sudo systemctl stop snapserver.service
  6. Try running snapserver manually.
  7. Now there is sound on snnapclients

Environment details

  • OS: debian 11
  • Snapcast version 0.26.0
  • Installed from a package

Attach logfile if applicable Generate logs with snapclient --logfilter debug or snapserver --logging.filter debug if possible and paste them in the following codeblock

# snapserver --logging.filter debug
2022-06-06 12-09-00.943 [Info] (Snapserver) Version 0.26.0, revision e30a9f33
2022-06-06 12-09-00.943 [Info] (Snapserver) Adding source: pipe:///tmp/snapfifo?name=Snapcast
2022-06-06 12-09-00.943 [Info] (Snapserver) Adding source: tcp://10.4.44.198?port=4953&name=snapbroadcast
2022-06-06 12-09-00.943 [Notice] (init) Settings file: "/home/brian/.config/snapserver/server.json"
2022-06-06 12-09-00.943 [Info] (Snapserver) Using HTTP host name: streaming-music-server
2022-06-06 12-09-00.945 [Info] (Avahi) Adding service 'Snapcast'
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri: pipe:///tmp/snapfifo?name=Snapcast
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri.toString: pipe:////tmp/snapfifo?name=Snapcast
2022-06-06 12-09-00.947 [Info] (PcmStream) PcmStream: Snapcast, sampleFormat: 48000:16:2
2022-06-06 12-09-00.947 [Debug] (AsioStream) Chunk duration: 20 ms, frames: 960, size: 3840
2022-06-06 12-09-00.947 [Info] (PipeStream) PipeStream mode: create
2022-06-06 12-09-00.947 [Info] (Server) Stream: {"fragment":"","host":"","path":"/tmp/snapfifo","query":{"chunk_ms":"20","codec":"flac","name":"Snapcast","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/snapfifo?chunk_ms=20&codec=flac&name=Snapcast&sampleformat=48000:16:2","scheme":"pipe"}
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri: tcp://10.4.44.198?port=4953&name=snapbroadcast
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri.toString: tcp://10.4.44.198/?name=snapbroadcast&port=4953
2022-06-06 12-09-00.947 [Info] (PcmStream) PcmStream: snapbroadcast, sampleFormat: 48000:16:2
2022-06-06 12-09-00.947 [Debug] (AsioStream) Chunk duration: 20 ms, frames: 960, size: 3840
2022-06-06 12-09-00.947 [Info] (TcpStream) TcpStream host: 10.4.44.198, port: 4953, is server: 1
2022-06-06 12-09-00.947 [Info] (Server) Stream: {"fragment":"","host":"10.4.44.198","path":"","query":{"chunk_ms":"20","codec":"flac","name":"snapbroadcast","port":"4953","sampleformat":"48000:16:2"},"raw":"tcp://10.4.44.198/?chunk_ms=20&codec=flac&name=snapbroadcast&port=4953&sampleformat=48000:16:2","scheme":"tcp"}
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri: pipe:///tmp/snapfifo?name=Snapcast
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri.toString: pipe:////tmp/snapfifo?name=Snapcast
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri: tcp://10.4.44.198?port=4953&name=snapbroadcast
2022-06-06 12-09-00.947 [Debug] (parse) StreamUri.toString: tcp://10.4.44.198/?name=snapbroadcast&port=4953
2022-06-06 12-09-00.947 [Debug] (PcmStream) Start: Snapcast, type: pipe, sampleformat: 48000:16:2, codec: flac
2022-06-06 12-09-00.947 [Info] (FlacEnc) Init - compression level: 2
2022-06-06 12-09-00.947 [Error] (PosixStream) Exception: end of file
2022-06-06 12-09-00.947 [Debug] (PcmStream) Start: snapbroadcast, type: tcp, sampleformat: 48000:16:2, codec: flac
2022-06-06 12-09-00.947 [Info] (FlacEnc) Init - compression level: 2
2022-06-06 12-09-00.948 [Info] (ControlServer) Creating TCP acceptor for address: 0.0.0.0, port: 1705
2022-06-06 12-09-00.948 [Info] (ControlServer) Creating HTTP acceptor for address: 0.0.0.0, port: 1780
2022-06-06 12-09-00.948 [Info] (StreamServer) Creating stream acceptor for address: 0.0.0.0, port: 1704
2022-06-06 12-09-00.948 [Info] (Snapserver) Number of threads: 2, hw threads: 2
2022-06-06 12-09-00.959 [Notice] (StreamServer) StreamServer::NewConnection: 10.4.44.204
2022-06-06 12-09-00.961 [Debug] (StreamSessionTCP) getNextMessage: Hello, size: 230, id: 1404, refers: 0
2022-06-06 12-09-00.961 [Debug] (Server) onMessageReceived: Hello, size: 230, id: 1404, refers: 0, sent: 42377,439012, recv: 1420,794146
2022-06-06 12-09-00.961 [Info] (Server) Hello from e1a27d22-69da-4ffb-89fa-12790cb26f28, host: Redmi Note 9 Pro, v0.26.0, ClientName: Snapclient, OS: Android 11, Arch: arm64-v8a, Protocol version: 2
2022-06-06 12-09-00.961 [Debug] (Server) Sending ServerSettings to e1a27d22-69da-4ffb-89fa-12790cb26f28
2022-06-06 12-09-00.961 [Debug] (Server) Group: a5d85149-5dfb-7dde-489f-fdd8c2391363, stream: snapbroadcast
2022-06-06 12-09-00.961 [Debug] (Server) Sending codec header to e1a27d22-69da-4ffb-89fa-12790cb26f28
2022-06-06 12-09-00.963 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1405, refers: 0
2022-06-06 12-09-00.963 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1405, refers: 0, sent: 42377,439409, recv: 1420,795635
2022-06-06 12-09-01.012 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1406, refers: 0
2022-06-06 12-09-01.012 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1406, refers: 0, sent: 42377,489785, recv: 1420,845028
2022-06-06 12-09-01.015 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1407, refers: 0
2022-06-06 12-09-01.015 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1407, refers: 0, sent: 42377,492831, recv: 1420,847947
2022-06-06 12-09-01.018 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1408, refers: 0
2022-06-06 12-09-01.018 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1408, refers: 0, sent: 42377,495584, recv: 1420,850650
2022-06-06 12-09-01.021 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1409, refers: 0
2022-06-06 12-09-01.021 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1409, refers: 0, sent: 42377,498614, recv: 1420,853647
2022-06-06 12-09-01.023 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1410, refers: 0
2022-06-06 12-09-01.023 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1410, refers: 0, sent: 42377,501370, recv: 1420,856238
2022-06-06 12-09-01.026 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1411, refers: 0
2022-06-06 12-09-01.026 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1411, refers: 0, sent: 42377,503887, recv: 1420,858759
2022-06-06 12-09-01.029 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1412, refers: 0
2022-06-06 12-09-01.029 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1412, refers: 0, sent: 42377,506555, recv: 1420,861544
2022-06-06 12-09-01.031 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1413, refers: 0
2022-06-06 12-09-01.031 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1413, refers: 0, sent: 42377,509167, recv: 1420,864081
2022-06-06 12-09-01.034 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1414, refers: 0
2022-06-06 12-09-01.034 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1414, refers: 0, sent: 42377,511712, recv: 1420,866580
2022-06-06 12-09-01.036 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1415, refers: 0
2022-06-06 12-09-01.036 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1415, refers: 0, sent: 42377,514069, recv: 1420,868928
2022-06-06 12-09-01.038 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1416, refers: 0
2022-06-06 12-09-01.038 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1416, refers: 0, sent: 42377,516355, recv: 1420,871261
2022-06-06 12-09-01.041 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1417, refers: 0
2022-06-06 12-09-01.041 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1417, refers: 0, sent: 42377,518691, recv: 1420,873500
2022-06-06 12-09-01.043 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1418, refers: 0
2022-06-06 12-09-01.043 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1418, refers: 0, sent: 42377,520933, recv: 1420,875782
2022-06-06 12-09-01.045 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1419, refers: 0
2022-06-06 12-09-01.046 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1419, refers: 0, sent: 42377,523265, recv: 1420,878356
2022-06-06 12-09-01.048 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1420, refers: 0
2022-06-06 12-09-01.048 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1420, refers: 0, sent: 42377,525895, recv: 1420,880842
2022-06-06 12-09-01.050 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1421, refers: 0
2022-06-06 12-09-01.051 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1421, refers: 0, sent: 42377,528397, recv: 1420,883314
2022-06-06 12-09-01.053 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1422, refers: 0
2022-06-06 12-09-01.053 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1422, refers: 0, sent: 42377,530769, recv: 1420,885853
2022-06-06 12-09-01.056 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1423, refers: 0
2022-06-06 12-09-01.056 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1423, refers: 0, sent: 42377,533497, recv: 1420,888483
2022-06-06 12-09-01.058 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1424, refers: 0
2022-06-06 12-09-01.058 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1424, refers: 0, sent: 42377,536082, recv: 1420,891244
2022-06-06 12-09-01.061 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1425, refers: 0
2022-06-06 12-09-01.061 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1425, refers: 0, sent: 42377,538875, recv: 1420,893815
2022-06-06 12-09-01.064 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1426, refers: 0
2022-06-06 12-09-01.064 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1426, refers: 0, sent: 42377,541600, recv: 1420,896744
2022-06-06 12-09-01.066 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1427, refers: 0
2022-06-06 12-09-01.067 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1427, refers: 0, sent: 42377,544374, recv: 1420,899321
2022-06-06 12-09-01.069 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1428, refers: 0
2022-06-06 12-09-01.070 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1428, refers: 0, sent: 42377,547275, recv: 1420,902616
2022-06-06 12-09-01.073 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1429, refers: 0
2022-06-06 12-09-01.073 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1429, refers: 0, sent: 42377,550566, recv: 1420,905636
2022-06-06 12-09-01.076 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1430, refers: 0
2022-06-06 12-09-01.076 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1430, refers: 0, sent: 42377,553562, recv: 1420,908622
2022-06-06 12-09-01.079 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1431, refers: 0
2022-06-06 12-09-01.079 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1431, refers: 0, sent: 42377,556332, recv: 1420,911477
2022-06-06 12-09-01.081 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1432, refers: 0
2022-06-06 12-09-01.082 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1432, refers: 0, sent: 42377,559257, recv: 1420,914335
2022-06-06 12-09-01.084 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1433, refers: 0
2022-06-06 12-09-01.084 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1433, refers: 0, sent: 42377,561954, recv: 1420,916851
2022-06-06 12-09-01.087 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1434, refers: 0
2022-06-06 12-09-01.087 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1434, refers: 0, sent: 42377,564449, recv: 1420,919483
2022-06-06 12-09-01.089 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1435, refers: 0
2022-06-06 12-09-01.089 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1435, refers: 0, sent: 42377,567206, recv: 1420,922278
2022-06-06 12-09-01.093 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1436, refers: 0
2022-06-06 12-09-01.093 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1436, refers: 0, sent: 42377,570178, recv: 1420,925868
2022-06-06 12-09-01.096 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1437, refers: 0
2022-06-06 12-09-01.096 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1437, refers: 0, sent: 42377,573428, recv: 1420,928406
2022-06-06 12-09-01.098 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1438, refers: 0
2022-06-06 12-09-01.098 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1438, refers: 0, sent: 42377,575948, recv: 1420,930976
2022-06-06 12-09-01.102 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1439, refers: 0
2022-06-06 12-09-01.102 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1439, refers: 0, sent: 42377,579170, recv: 1420,934844
2022-06-06 12-09-01.105 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1440, refers: 0
2022-06-06 12-09-01.105 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1440, refers: 0, sent: 42377,582478, recv: 1420,937469
2022-06-06 12-09-01.107 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1441, refers: 0
2022-06-06 12-09-01.107 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1441, refers: 0, sent: 42377,585009, recv: 1420,939936
2022-06-06 12-09-01.110 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1442, refers: 0
2022-06-06 12-09-01.110 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1442, refers: 0, sent: 42377,587564, recv: 1420,942409
2022-06-06 12-09-01.112 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1443, refers: 0
2022-06-06 12-09-01.112 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1443, refers: 0, sent: 42377,589954, recv: 1420,944943
2022-06-06 12-09-01.115 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1444, refers: 0
2022-06-06 12-09-01.115 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1444, refers: 0, sent: 42377,592501, recv: 1420,947429
2022-06-06 12-09-01.117 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1445, refers: 0
2022-06-06 12-09-01.117 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1445, refers: 0, sent: 42377,595279, recv: 1420,950230
2022-06-06 12-09-01.120 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1446, refers: 0
2022-06-06 12-09-01.120 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1446, refers: 0, sent: 42377,598054, recv: 1420,952955
2022-06-06 12-09-01.123 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1447, refers: 0
2022-06-06 12-09-01.123 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1447, refers: 0, sent: 42377,600515, recv: 1420,955629
2022-06-06 12-09-01.125 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1448, refers: 0
2022-06-06 12-09-01.126 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1448, refers: 0, sent: 42377,603319, recv: 1420,958314
2022-06-06 12-09-01.128 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1449, refers: 0
2022-06-06 12-09-01.128 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1449, refers: 0, sent: 42377,605875, recv: 1420,960855
2022-06-06 12-09-01.131 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1450, refers: 0
2022-06-06 12-09-01.131 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1450, refers: 0, sent: 42377,608443, recv: 1420,963326
2022-06-06 12-09-01.133 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1451, refers: 0
2022-06-06 12-09-01.133 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1451, refers: 0, sent: 42377,611042, recv: 1420,965980
2022-06-06 12-09-01.136 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1452, refers: 0
2022-06-06 12-09-01.136 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1452, refers: 0, sent: 42377,613604, recv: 1420,968460
2022-06-06 12-09-01.138 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1453, refers: 0
2022-06-06 12-09-01.138 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1453, refers: 0, sent: 42377,616125, recv: 1420,971097
2022-06-06 12-09-01.141 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1454, refers: 0
2022-06-06 12-09-01.141 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1454, refers: 0, sent: 42377,618803, recv: 1420,973801
2022-06-06 12-09-01.144 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1455, refers: 0
2022-06-06 12-09-01.144 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1455, refers: 0, sent: 42377,622035, recv: 1420,976996
2022-06-06 12-09-01.237 [Notice] (ControlServer) ControlServer::NewConnection: 10.4.44.153
2022-06-06 12-09-01.237 [Notice] (ControlServer) ControlServer::NewConnection: 10.4.44.153
2022-06-06 12-09-01.899 [Info] (Avahi) Service 'Snapcast' successfully established.
2022-06-06 12-09-02.147 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1456, refers: 0
2022-06-06 12-09-02.147 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1456, refers: 0, sent: 42378,624283, recv: 1421,979497
2022-06-06 12-09-03.150 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1457, refers: 0
2022-06-06 12-09-03.150 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1457, refers: 0, sent: 42379,627135, recv: 1422,982575
2022-06-06 12-09-03.263 [Debug] (Server) Saving config
2022-06-06 12-09-04.153 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1458, refers: 0
2022-06-06 12-09-04.153 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1458, refers: 0, sent: 42380,630196, recv: 1423,985541
2022-06-06 12-09-05.156 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1459, refers: 0
2022-06-06 12-09-05.156 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1459, refers: 0, sent: 42381,632913, recv: 1424,988347
2022-06-06 12-09-06.158 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1460, refers: 0
2022-06-06 12-09-06.158 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1460, refers: 0, sent: 42382,635893, recv: 1425,991177
2022-06-06 12-09-07.161 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1461, refers: 0
2022-06-06 12-09-07.161 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1461, refers: 0, sent: 42383,638948, recv: 1426,994228
2022-06-06 12-09-07.914 [Error] (ControlSessionTCP) Error while reading from control socket: Connection reset by peer
2022-06-06 12-09-07.914 [Debug] (ControlSessionTCP) ControlSessionTcp::~ControlSessionTcp()
2022-06-06 12-09-07.914 [Debug] (ControlSessionTCP) ControlSession::stop
2022-06-06 12-09-07.914 [Error] (ControlSessionTCP) Error in socket shutdown: Transport endpoint is not connected
2022-06-06 12-09-07.914 [Debug] (ControlSessionTCP) ControlSession ControlSession stopped
2022-06-06 12-09-07.964 [Debug] (TcpStream) New client connection
2022-06-06 12-09-08.166 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1462, refers: 0
2022-06-06 12-09-08.166 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1462, refers: 0, sent: 42384,642221, recv: 1427,998465
2022-06-06 12-09-08.230 [Info] (PcmStream) State changed: snapbroadcast, state: idle => playing
2022-06-06 12-09-08.230 [Info] (Server) onStateChanged (snapbroadcast): playing
2022-06-06 12-09-08.230 [Info] (ControlServer) Removing 1 inactive session(s), active sessions: 1
2022-06-06 12-09-09.169 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1463, refers: 0
2022-06-06 12-09-09.169 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1463, refers: 0, sent: 42385,647254, recv: 1429,2235
2022-06-06 12-09-10.173 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1464, refers: 0
2022-06-06 12-09-10.173 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1464, refers: 0, sent: 42386,650305, recv: 1430,5520
2022-06-06 12-09-11.176 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1465, refers: 0
2022-06-06 12-09-11.176 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1465, refers: 0, sent: 42387,653582, recv: 1431,8456
2022-06-06 12-09-12.179 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1466, refers: 0
2022-06-06 12-09-12.179 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1466, refers: 0, sent: 42388,656613, recv: 1432,11610
2022-06-06 12-09-13.183 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1467, refers: 0
2022-06-06 12-09-13.183 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1467, refers: 0, sent: 42389,660375, recv: 1433,15781
2022-06-06 12-09-14.188 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1468, refers: 0
2022-06-06 12-09-14.188 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1468, refers: 0, sent: 42390,665583, recv: 1434,20640
2022-06-06 12-09-15.191 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1469, refers: 0
2022-06-06 12-09-15.191 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1469, refers: 0, sent: 42391,668499, recv: 1435,23369
2022-06-06 12-09-16.193 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1470, refers: 0
2022-06-06 12-09-16.193 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1470, refers: 0, sent: 42392,671231, recv: 1436,26038
2022-06-06 12-09-17.197 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1471, refers: 0
2022-06-06 12-09-17.197 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1471, refers: 0, sent: 42393,673859, recv: 1437,29608
2022-06-06 12-09-18.207 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1472, refers: 0
2022-06-06 12-09-18.208 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1472, refers: 0, sent: 42394,678036, recv: 1438,40334
2022-06-06 12-09-19.211 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1473, refers: 0
2022-06-06 12-09-19.212 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1473, refers: 0, sent: 42395,689631, recv: 1439,44358
2022-06-06 12-09-20.215 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1474, refers: 0
2022-06-06 12-09-20.215 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1474, refers: 0, sent: 42396,692658, recv: 1440,47467
2022-06-06 12-09-21.217 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1475, refers: 0
2022-06-06 12-09-21.218 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1475, refers: 0, sent: 42397,695411, recv: 1441,50425
2022-06-06 12-09-22.221 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1476, refers: 0
2022-06-06 12-09-22.221 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1476, refers: 0, sent: 42398,698569, recv: 1442,53383
2022-06-06 12-09-23.223 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1477, refers: 0
2022-06-06 12-09-23.223 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1477, refers: 0, sent: 42399,701027, recv: 1443,55843
2022-06-06 12-09-24.227 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1478, refers: 0
2022-06-06 12-09-24.227 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1478, refers: 0, sent: 42400,704763, recv: 1444,59595
2022-06-06 12-09-25.229 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1479, refers: 0
2022-06-06 12-09-25.229 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1479, refers: 0, sent: 42401,707326, recv: 1445,62060
2022-06-06 12-09-26.232 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1480, refers: 0
2022-06-06 12-09-26.232 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1480, refers: 0, sent: 42402,709936, recv: 1446,64732
2022-06-06 12-09-27.235 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1481, refers: 0
2022-06-06 12-09-27.235 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1481, refers: 0, sent: 42403,713041, recv: 1447,68043
2022-06-06 12-09-28.238 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1482, refers: 0
2022-06-06 12-09-28.238 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1482, refers: 0, sent: 42404,716526, recv: 1448,71100
2022-06-06 12-09-29.241 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1483, refers: 0
2022-06-06 12-09-29.241 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1483, refers: 0, sent: 42405,719255, recv: 1449,74085
2022-06-06 12-09-30.244 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1484, refers: 0
2022-06-06 12-09-30.245 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1484, refers: 0, sent: 42406,722546, recv: 1450,77366
2022-06-06 12-09-31.249 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1485, refers: 0
2022-06-06 12-09-31.249 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1485, refers: 0, sent: 42407,727073, recv: 1451,81877
2022-06-06 12-09-32.253 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1486, refers: 0
2022-06-06 12-09-32.253 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1486, refers: 0, sent: 42408,730641, recv: 1452,85559
2022-06-06 12-09-32.678 [Info] (PcmStream) State changed: snapbroadcast, state: playing => idle
2022-06-06 12-09-32.678 [Info] (Server) onStateChanged (snapbroadcast): idle
2022-06-06 12-09-33.257 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1487, refers: 0
2022-06-06 12-09-33.257 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1487, refers: 0, sent: 42409,734878, recv: 1453,89802
2022-06-06 12-09-34.260 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1488, refers: 0
2022-06-06 12-09-34.260 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1488, refers: 0, sent: 42410,737818, recv: 1454,92798
2022-06-06 12-09-35.263 [Debug] (StreamSessionTCP) getNextMessage: Time, size: 8, id: 1489, refers: 0
2022-06-06 12-09-35.263 [Debug] (Server) onMessageReceived: Time, size: 8, id: 1489, refers: 0, sent: 42411,741482, recv: 1455,96230
^C2022-06-06 12-09-35.523 [Info] (Snapserver) Received signal 2: Interrupt
2022-06-06 12-09-35.523 [Info] (Snapserver) Stopping streamServer
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSession::stop
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSession ControlSession stopped
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSession::stop
2022-06-06 12-09-35.524 [Error] (ControlSessionTCP) Error in socket shutdown: Bad file descriptor
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSession ControlSession stopped
2022-06-06 12-09-35.524 [Debug] (StreamSessionTCP) stop
2022-06-06 12-09-35.524 [Debug] (StreamSessionTCP) stopped
2022-06-06 12-09-35.524 [Info] (Snapserver) done
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSessionTcp::~ControlSessionTcp()
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSession::stop
2022-06-06 12-09-35.524 [Error] (ControlSessionTCP) Error in socket shutdown: Bad file descriptor
2022-06-06 12-09-35.524 [Debug] (ControlSessionTCP) ControlSession ControlSession stopped
2022-06-06 12-09-35.524 [Debug] (StreamSessionTCP) ~StreamSessionTcp
2022-06-06 12-09-35.524 [Debug] (StreamSessionTCP) stop
2022-06-06 12-09-35.524 [Notice] (Snapserver) Snapserver terminated.

briantho avatar Jun 06 '22 19:06 briantho

Is the log from the good case? Please try with the latest Snapcast version, maybe the systemd script starts the snapserver before network is available. In the current version, it starts after network-online. I dion't know how it used to be in the v0.26.0

badaix avatar Mar 27 '24 08:03 badaix