Roon frequently stops playing between tracks

lyroon · October 21, 2020, 2:26pm

Hi @support - I have had the issue for some time that roon will stop playing between songs. It is not reproducible (so I don’t think it is a bitrate switch), and sometimes will happen for a whole evening between every song, and sometimes not happen for a full day. On average it is common: a few times in any few hours of listening.

Core Machine (Operating system/System info/Roon build number)

Rock Version 1.7 (build 667) stable on NUC

Network Details (Including networking gear model/manufacturer and if on WiFi/Ethernet)

Core connected by ethernet to Synology NAS.
Router: “Freebox Delta”

Audio Devices (Specify what device you’re using and its connection type - USB/HDMI/etc.)

A few Sonos and Devialet devices over wifi or powerline adaptor

Description Of Issue

Not very reproducible, but very common. If playing one local album, things are ok. But if shuffling between songs (either local library on random, or roon-radio of local + Tidal). The roon player will stop between songs, just as if I had paused it. If I hit play again it (usually) starts again without issue. It happens independently in all audio zones (so one zone will pause / stop at the end of a track, the others will keep going, but it could be any one one of the zones that stops).

The log snippet below is typical:

Many repeated lines saying: rebuilding query instead of re-sorting item-by-item
Sending TEARDOWN / TEARDOWN was successful

10/21 13:38:06 Debug: [query] Sooloos.Broker.Music.LibraryAlbum: 2128 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=LibraryAlbum)
 183862 10/21 13:38:06 Trace: [airplay/client] Sending TEARDOWN
 183863 10/21 13:38:06 Trace: [airplay/client] TEARDOWN was successful
 183864 10/21 13:38:06 Info: [airplay] AirPlay device disconnected: AirPlayDevice[DeviceId=347E5CFCFD4A@Office._raop._tcp.local, Name=Sonos-347E5CFCFD4A.local, Model=SYMFONISK,
        IPEndPoint=192.168.1.26:7000]
 183865 10/21 13:38:06 Trace: [airplay] disconnected
 183866 10/21 13:38:06 Trace: [zone] Office received transport control from endpoint integration: suspend
 183867 10/21 13:38:06 Trace: [zone Office] Office received transport control from Office: suspend
 183868 10/21 13:38:06 Trace: [zone Office] Suspend
 183869 10/21 13:38:06 Info: [zone Office] OnPlayFeedback Stopped

noris · October 22, 2020, 5:35am

Hi @lyroon,

Powerline adapters have been known to cause issues with Roon in the past and as such we don’t recommend using these kinds of devices, as mentioned in our Networking Best Practices Guide.

As a test here, can you please try to plug in one or a few of the affected zones via Ethernet to the router and verify if you are seeing the same behavior?

lyroon · October 22, 2020, 6:48am

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

lyroon · October 26, 2020, 7:32pm

@support - apologies for replying to my own post, but it seems I can no longer edit the last message here. It has been five days since I posted this information: do you think you can offer any advice on possible solutions to this recurring issue?

Thanks

noris · October 27, 2020, 2:14am

Hi @lyroon,

Thanks for those additional details!

Can you please try to set up a fresh database and let me know if the issue reproduces with this as a test?

Create a Backup of your Roon Database
Stop RoonServer from running in ROCK’s WebUI
Navigate to your Roon’s Database Location
Find the folder that says “RoonServer”
Rename the “RoonServer” folder to “RoonServer_old”
Restart the RoonServer in the WebUI to generate a new Roon database folder
Try fresh database for a few days
Restore from backup

lyroon · November 24, 2020, 10:33am

Hi @noris

Apologies for not getting back to you. I must admit, it is because I really do not want to take the step of starting a new database. I have solved issues by starting with a fresh database before, and it has worked if I add a subset of my library, but when the full library is present, things seem to break down like this. and I am left without my playlists and ratings.

Given the log is giving us the explicit debug messages repeated dozens of times when roon stops playing I was hoping we could actually follow that lead, rather than just starting with a new DB. Are these messages normal? I don’t see them in the logs except when the music stops playing.

I don’t suppose you have any further information based on the log messages from the roon side?

noris · December 4, 2020, 9:51pm

Hi @lyroon,

Thanks for reaching out and apologies for the delay in getting back to you this time.

I spoke to our team regarding the snippets you provided, but they do not contain sufficient info to make a proper analysis.

Can you please reproduce the issue, note the exact local time + date + track and send us a full set of your Roon logs via Dropbox / Google Drive / etc?

Hopefully with a full set we can establish a better pattern, but if not there are also some additional diagnostics tool we can enable for more verbose logging.

lyroon · December 29, 2020, 9:04am

Hi @noris

Thank you for that. As it happened, over the break I was able to do the experiment you suggested.

I backed up the original library, and started totally over with a new database. I kept is small, and just added a few albums. I ran Roon like this with zero issues for two weeks.

Then yesterday, I re-added about half of the library (which is large). Immediately I started having similar issues with long pauses of stops between tracks. I will try to upload this complete log for reference for you, but for now I hope this is a very clear snippet:

In the first bolded line while a track was playing I hit “next / fast forward” and instead of playing the next track it went into “stop” mode with the usual teardown message. In between those two events there are many lines that are not clear to me, but it was immediate, so presumable either they are relevant or we need a higher logging level.
Can you please have a look and I will try to get you the full log if needed.

12/29 08:36:44 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [100% buf] [PLAYING @ 4:30/5:54] Prologus - Sigur Rós / Steindór Andersen / Hilmar Örn Hilmarsson / Maria Huld Markan Sigfúsdóttir / Árni Harðarson / Orchestre de la Société des Concerts du Conservatoire de Paris
12/29 08:36:46 Trace: [broker/accounts] [heartbeat] now=12/29/2020 08:36:46 nextauthrefresh=12/29/2020 09:26:10 nextmachineallocate=12/29/2020 10:21:46
**12/29 08:36:47 Trace: [zone Office] Next**
12/29 08:36:47 Debug: Lastfm 'xvgQyyspgtgB8Rh4yAXSO7EoUPkriT7D' DONE: Sigur Rós - Prologus 
12/29 08:36:47 Info: [zone Office] OnPlayFeedback Stopped
12/29 08:36:47 Info: [zone Office] Canceling Pending Sleep
12/29 08:36:47 Debug: [zone Office] _Advance
12/29 08:36:47 Trace: [airplay/client] Sending FLUSH
12/29 08:36:47 Trace: [zone Office] Selecting Source state=Stopped
12/29 08:36:47 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
12/29 08:36:47 Info: [audio/env] [zoneplayer] All streams were disposed
12/29 08:36:47 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [100% buf] [LOADING @ 0:00] Alföður Orkar - Sigur Rós / Steindór Andersen / Hilmar Örn Hilmarsson / Maria Huld Markan Sigfúsdóttir / Árni Harðarson / Orchestre de la Société des Concerts du Conservatoire de Paris / Schola Cantorum Choir
12/29 08:36:47 Trace: [airplay/client] FLUSH was successful
12/29 08:36:47 Trace: [dbperf] flush 4847 bytes, 2 ops in 0 ms (cumulative 3269709133 bytes, 3729880 ops in 642451 ms)
12/29 08:36:47 Trace: [library] endmutation in 3554ms
12/29 08:36:47 Trace: [dbperf] flush 0 bytes, 0 ops in 6 ms (cumulative 3269709133 bytes, 3729880 ops in 642457 ms)
12/29 08:36:47 Trace: [dbperf] flush 0 bytes, 0 ops in 7 ms (cumulative 3269709133 bytes, 3729880 ops in 642464 ms)
12/29 08:36:47 Info: [library] recorded play for profile 2486800b-377e-4d85-b4ed-da6412e0a732: mediaid=50:1:8dbb816c-34d4-4d4d-8591-e9441b17b0ab metadataid=123:0:MT0058493566 contentid= libraryid=50:1:8dbb816c-34d4-4d4d-8591-e9441b17b0ab isfromswim=False
12/29 08:36:48 Trace: [library] finished with 91 dirty tracks 13 dirty albums 14 dirty performers 67 dirty works 72 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 166 changed objects
12/29 08:36:48 Trace: updated recents in 14ms
12/29 08:36:48 Trace: updated recents in 0ms
12/29 08:36:48 Trace: updated recents in 1ms
12/29 08:36:48 Trace: updated recents in 0ms
12/29 08:36:48 Trace: updated recents in 1ms
12/29 08:36:48 Trace: updated recents in 0ms
**12/29 08:36:52 Trace: [airplay/client] Sending TEARDOWN**
**12/29 08:36:52 Trace: [airplay/client] TEARDOWN was successful**
**12/29 08:36:52 Info: [airplay] AirPlay device disconnected:** AirPlayDevice[DeviceId=347E5CFCFD4A@Office._raop._tcp.local, Name=Sonos-347E5CFCFD4A.local, Model=SYMFONISK, IPEndPoint=192.168.1.26:7000]

and already a second example from just now: hit play on a new album, but Roon immiately goes into stopped mode:

12/29 09:06:15 Trace: [zone Office] Playing 8 Items
12/29 09:06:15 Debug: Lastfm 'xvgQyyspgtgB8Rh4yAXSO7EoUPkriT7D' DONE: Sigur Rós - Stendur Æva 
12/29 09:06:15 Info: [zone Office] OnPlayFeedback Stopped
12/29 09:06:15 Info: [zone Office] Canceling Pending Sleep
12/29 09:06:15 Info: [library] recorded play for profile 2486800b-377e-4d85-b4ed-da6412e0a732: mediaid=50:1:6da412bf-c7ad-47ce-a46f-674f669a4390 metadataid=123:0:MT0058493569 contentid= libraryid=50:1:6da412bf-c7ad-47ce-a46f-674f669a4390 isfromswim=False
12/29 09:06:15 Trace: [zone Office] Playing TransportItem
12/29 09:06:15 Info: [zone Office] Canceling Pending Sleep
12/29 09:06:15 Trace: [airplay/client] Sending FLUSH
12/29 09:06:15 Trace: [zone Office] Selecting Source state=Stopped
12/29 09:06:15 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
12/29 09:06:15 Info: [audio/env] [zoneplayer] All streams were disposed
12/29 09:06:15 Trace: [Office] [LowQuality, 24/44 MP3 => 16/44] [47% buf] [LOADING @ 0:00] Enters - Nils Frahm
12/29 09:06:15 Trace: [library] finished with 91 dirty tracks 13 dirty albums 14 dirty performers 67 dirty works 72 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 166 changed objects
12/29 09:06:15 Trace: updated recents in 13ms
12/29 09:06:15 Trace: updated recents in 0ms
12/29 09:06:15 Trace: updated recents in 1ms
12/29 09:06:15 Trace: updated recents in 0ms
12/29 09:06:15 Trace: updated recents in 1ms
12/29 09:06:15 Trace: updated recents in 0ms
12/29 09:06:15 Trace: [airplay/client] FLUSH was successful
12/29 09:06:20 Trace: [airplay/client] Sending TEARDOWN
12/29 09:06:20 Trace: [airplay/client] TEARDOWN was successful
12/29 09:06:20 Info: [airplay] AirPlay device disconnected: AirPlayDevice[DeviceId=347E5CFCFD4A@Office._raop._tcp.local, Name=Sonos-347E5CFCFD4A.local, Model=SYMFONISK, IPEndPoint=192.168.1.26:7000]
12/29 09:06:20 Trace: [airplay] disconnected
12/29 09:06:20 Trace: [zone] Office received transport control from endpoint integration: suspend
12/29 09:06:20 Trace: [zone Office] Office received transport control from Office: suspend
12/29 09:06:20 Trace: [zone Office] Suspend

noris · December 30, 2020, 5:39pm

Hi @lyroon,

Thanks for these log snippets, let me get them over to the team for further review. It may take a bit to hear back due to the holiday queue, so your patience here is appreciated!

Sometimes seeing what happens before a log can be helpful, if you can also please submit the full set, I can attach it to your case notes. You can also send me the log via private message (click my name -> message) to avoid having it in public.

Thank you and Happy Holidays

noris · January 8, 2021, 9:21pm

Hi @lyroon,

Hope you had a Happy New Year and thanks for your patience here!

I spoke to the team regarding your new log set, but unfortunately they don’t reveal much information.

We would like to enable some more verbose logging to try to get more information, but we can only leave this logging active for a short period of time - a few days to a week.

Can you please let me know when would be a good window of time for us to enable this logging and for you to reproduce the issue? Thanks!

Mike_Weaver · March 21, 2022, 4:26pm

Was there ever any closure on this. I am having similar issues. Random stops when advancing transport with “next track” button. Often on tracks on same album. Running v 1.8 build 118 on core and client.

lyroon · March 28, 2022, 9:28am

I don’t think this was ever resolved. I changed many of the components of my system over time, and the stopping between tracks got less frequent and I have just been living with it.

It does seem to have gotten much more common again recently though, so maybe @support will be able to look into it again.

Geoff_Coupe · March 28, 2022, 9:43am

Well, if you want Support to look at this again (you didn’t respond to their last request), then I suggest you start again by listing your current setup. Since you have changed many of the components, it will be necessary for Support to have a clear understanding of the current setup to help in any diagnosis.

noris · June 4, 2022, 3:00pm

This topic was automatically closed after 68 days. New replies are no longer allowed.