Hi @noris
Thanks for getting back to me. This occurs in all zones, and is not restricted to ones with a powerline connection, so I think that can be ruled out as a factor.
The zone in the log extract I posted is in a normal zone with airplay over wifi (a few feet from the router).
Do you have any feedback on the recurring pattern I see in the logs every time this happens?
Another reproducible example from just now:
10/22 07:35:03 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [LOADING @ 0:00] Even Solemnity in the Instruments (Farina's Automatic Translation Machine) - Ghostwriter
10/22 07:35:03 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:03 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:03 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:03 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:03 Trace: [musicpowerstate] music is playing, preventing idle sleep
10/22 07:35:03 Info: [Office] [zoneplayer] Playing: /roon/sys/storage/smbmounts/RoonStorage_14fdf0691aee07be6e51cdb4b5d8022e4850bdc4/Audio/Music/Music/Various Artists/VA - Music & Migration (Second Language, 2010) #it/09-ghostwriter - even solemnity in the instruments (farina's automatic translation machine).mp3
10/22 07:35:03 Info: [Office] [zoneplayer] Queueing: /roon/sys/storage/smbmounts/RoonStorage_14fdf0691aee07be6e51cdb4b5d8022e4850bdc4/Audio/Music/Untagged/Dub Narcotic Sound System/Dub Narcotic Sound System - Industrial Breakdown [1995]/01 - Industrial Breakdown.flac
10/22 07:35:03 Info: [Office] [zoneplayer] Open Result (Playing):Result[Status=Success]
10/22 07:35:03 Info: [Office] [zoneplayer] Starting playback
10/22 07:35:03 Trace: [airplay/client] Connecting to airplay server
10/22 07:35:03 Debug: Lastfm 'xvgQyyspgtgB8Rh4yAXSO7EoUPkriT7D' START: Ghostwriter - Even Solemnity in the Instruments (Farina's Automatic Translation Machine)
10/22 07:35:03 Info: [zone Office] OnPlayFeedback Playing
10/22 07:35:03 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [PLAYING @ 0:00] Even Solemnity in the Instruments (Farina's Automatic Translation Machine) - Ghostwriter
10/22 07:35:03 Trace: [airplay/client] Requesting OPTIONS
10/22 07:35:03 Info: [airplay/client] REQUESTING OPTIONS *
10/22 07:35:03 Info: [Office] [zoneplayer] Open result (Queueing): Result[Status=Success]
10/22 07:35:03 Trace: [airplay/client] Got good OPTIONS: ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, FLUSHBUFFERED, TEARDOWN, OPTIONS, POST, GET, PUT
10/22 07:35:03 Info: [airplay] AirPlay device connected: AirPlayDevice[DeviceId=347E5CFCFD4A@Office._raop._tcp.local, Name=Sonos-347E5CFCFD4A.local, Model=SYMFONISK, IPEndPoint=192.168.1.26:7000]
10/22 07:35:03 Trace: [airplay] connected
10/22 07:35:03 Info: [library/albumdetails] Created album details screen for LibraryAlbum[5598255, Various Artists - Music & Migration]
10/22 07:35:03 Info: [library/albumdetails] 3e015f88e25959553c45aea4b73badc175ba, be00373439353037
10/22 07:35:03 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/113 sec
10/22 07:35:03 Debug: [easyhttp] [1102] POST to https://metadata.roonlabs.net/1/albums/translate?c=tidal-fr returned after 120 ms, status code: 200
10/22 07:35:03 Info: [library/albumdetails] found 0 streaming service alternates
10/22 07:35:03 Trace: [airplay/client] Sending ANNOUNCE
10/22 07:35:03 Trace: [airplay/client] ANNOUNCE Succeeded
10/22 07:35:03 Trace: [airplay/client] Sending SETUP
10/22 07:35:03 Trace: [airplay/client] SETUP was successful
10/22 07:35:03 Trace: [airplay/client] Sending RECORD
10/22 07:35:03 Trace: [airplay/client] Record Succeeded
10/22 07:35:03 Trace: [airplay/client] Sending SET_PARAMETER volume -27.9db
10/22 07:35:03 Trace: [airplay/client] Sending first sync packet rtptime=1100448722 synctime=1100536922
10/22 07:35:03 Info:
--[ SignalPath ]---------------------------------------------
SignalPath Quality = LowQuality
Elements:
Source Format=Mp3 44100/24/2 BitRate=224 Quality=LowQuality
Truncate FromBitsPerSample=24 ToBitsPerSample=16 Quality=HighQuality
Output OutputType=AirPlay Quality=HighQuality SubType= Model=SYMFONISK
------------------------------------------------------------
10/22 07:35:05 Trace: [zone Office] Seek 109
10/22 07:35:05 Trace: [airplay/client] Sending FLUSH
10/22 07:35:05 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
10/22 07:35:05 Info: SEEK MS 109000
10/22 07:35:05 Trace: [airplay/client] FLUSH was successful
10/22 07:35:05 Trace: [prebuffer] ready 149940/441000 (34%) @ 109/113 sec
10/22 07:35:05 Trace: [airplay/client] Sending first sync packet rtptime=1100530738 synctime=1100618938
10/22 07:35:05 Trace: [prebuffer] short read: 0 / 8820 fill=272672
10/22 07:35:06 Info:
--[ SignalPath ]---------------------------------------------
SignalPath Quality = LowQuality
Elements:
Source Format=Mp3 44100/24/2 BitRate=224 Quality=LowQuality
Truncate FromBitsPerSample=24 ToBitsPerSample=16 Quality=HighQuality
Output OutputType=AirPlay Quality=HighQuality SubType= Model=SYMFONISK
------------------------------------------------------------
10/22 07:35:08 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [31% buf] [PLAYING @ 1:51/1:53] Even Solemnity in the Instruments (Farina's Automatic Translation Machine) - Ghostwriter
10/22 07:35:13 Info: [library] recorded play for profile 2486800b-377e-4d85-b4ed-da6412e0a732: mediaid=50:1:a7168e34-d69a-4052-8a9f-c72ad5e345d3 metadataid=97:0:6585369109586 contentid= libraryid=50:1:a7168e34-d69a-4052-8a9f-c72ad5e345d3 isfromswim=True
10/22 07:35:13 Info: [zone Office] OnPlayFeedback StoppedEndOfMediaNatural
10/22 07:35:13 Debug: [zone Office] _Advance
10/22 07:35:13 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [1% buf] [LOADING @ 0:00] Industrial Revolution - Dub Narcotic Sound System
10/22 07:35:13 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:13 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:13 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:13 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
10/22 07:35:14 Info: [stats] 29747mb Virtual, 6395mb Physical, 2830mb Managed, 331 Handles, 91 Threads
10/22 07:35:16 Trace: [library] finished with 43361 dirty tracks 2129 dirty albums 11242 dirty performers 10974 dirty works 12338 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 0 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 36684 changed objects
10/22 07:35:16 Trace: updated recents in 3ms
10/22 07:35:16 Trace: updated recents in 0ms
10/22 07:35:16 Trace: updated recents in 1ms
10/22 07:35:16 Trace: updated recents in 0ms
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:16 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryTrack: 43361 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryTrack)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:17 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryTrack: 43361 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryTrack)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2129 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
10/22 07:35:18 Trace: [airplay/client] Sending TEARDOWN
10/22 07:35:18 Trace: [airplay/client] TEARDOWN was successful
10/22 07:35:18 Info: [airplay] AirPlay device disconnected: AirPlayDevice[DeviceId=347E5CFCFD4A@Office._raop._tcp.local, Name=Sonos-347E5CFCFD4A.local, Model=SYMFONISK, IPEndPoint=192.168.1.26:7000]
10/22 07:35:18 Trace: [airplay] disconnected
10/22 07:35:18 Trace: [zone] Office received transport control from endpoint integration: suspend
10/22 07:35:18 Trace: [zone Office] Office received transport control from Office: suspend
10/22 07:35:18 Trace: [zone Office] Suspend
10/22 07:35:18 Info: [zone Office] OnPlayFeedback Stopped
10/22 07:35:18 Info: [zone Office] Canceling Pending Sleep
10/22 07:35:18 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
10/22 07:35:18 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [1% buf] [STOPPED @ 0:00] Industrial Revolution - Dub Narcotic Sound System
10/22 07:35:18 Info: [audio/env] [zoneplayer] All streams were disposed
On the previous tracks (where everything was playing fine) I noticed the signal path had a bit-depth conversion of 24 to 16, and when switching to this track (which is already 16 bit) that changed to just direct from source to the airplay. Rewinding to the previous track it is reproducible: Roon will not play these 2 tracks in a row without stopping.
Also this looks very similar (which you were also running) was there any answer in the end? Occasional long "freeze" between tracks
Thanks