01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 0 bytes, 0 ops in 14 ms (cumulative 659018 bytes, 257 ops in 6067 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [identification] <670767> status: CouldNotIdentify 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [identification] <728879> Identifying album [Yuri Korzunov - Through [DSD/FLAC HD Format Test]] with 8 tracks 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 14 dirty tracks 1 dirty albums 1 dirty performers 1 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 14 dirty tracks 1 dirty albums 2 dirty performers 5 dirty works 5 dirty performances 1 dirty genres 1 dirty folders 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 14 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 29 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] removed in 0ms: 0 album documents, 14 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 69920 bytes, 30 ops in 18 ms (cumulative 728938 bytes, 287 ops in 6085 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] added in 6ms: 0 album documents, 14 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 1 dirty performers 1 dirty works 1 dirty places , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 2 dirty performers 1 dirty works 1 dirty places 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 3 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 0 bytes, 0 ops in 5 ms (cumulative 728938 bytes, 287 ops in 6090 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [easyhttp] [40] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=191:0:547353&type=biography&sourceLangs=Wikipedia:fr,Wikipedia:en,Rovi-compositions:en,Rovi-artists:en,Rovi-albums:en,Wikipedia:en-simple&contentPreferences=preferMqa&tidal=max returned after 71 ms, status code: 200, request body size: 0 B 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 1 dirty performers 1 dirty places , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 1 dirty performers 1 dirty places 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 1 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 728938 bytes, 287 ops in 6091 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [easyhttp] [41] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=191:0:538684&type=biography&sourceLangs=Wikipedia:fr,Wikipedia:en,Rovi-compositions:en,Rovi-artists:en,Rovi-albums:en,Wikipedia:en-simple&contentPreferences=preferMqa&tidal=max returned after 76 ms, status code: 200, request body size: 0 B 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [easyhttp] [42] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=191:0:538683&type=biography&sourceLangs=Wikipedia:fr,Wikipedia:en,Rovi-compositions:en,Rovi-artists:en,Rovi-albums:en,Wikipedia:en-simple&contentPreferences=preferMqa&tidal=max returned after 79 ms, status code: 200, request body size: 0 B 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 728938 bytes, 287 ops in 6092 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [easyhttp] [39] POST to https://api.roonlabs.net/identifier/identifier/2/album?tidal=max returned after 189 ms, status code: 200, request body size: 2 KB 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [identification] <728879> status: CouldNotIdentify 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [identification] <687919> Identifying album [Quatuor Arditti - Stockhausen: Helikopter Streichquartett] with 1 tracks 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 8 dirty tracks 1 dirty albums 1 dirty performers 3 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 8 dirty tracks 1 dirty albums 5 dirty performers 7 dirty works 8 dirty performances 3 dirty genres 1 dirty folders 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 8 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 33 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] removed in 0ms: 0 album documents, 8 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] added in 0ms: 0 album documents, 8 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library/playlist] saving playlist folder 10:1:2fbd43db-3328-4514-91b5-3303e447c95c [root] 01/05 21:28:33 [Local 01/05 22:28:33] Trace: finished updating 2 dirty playlists and 1 dirty playlist folders 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 39974 bytes, 18 ops in 5 ms (cumulative 768912 bytes, 305 ops in 6097 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] endmutation in 14ms 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [metadatasvc] GOT [4] (275ms) Sooloos.Msg.Metadata.GetMetadataResponse: 01/05 21:28:33 [Local 01/05 22:28:33] Info: [updatemetadata] advancing metadata timestamp on 64 tracks 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 64 dirty tracks 3 dirty albums 5 dirty performers 7 dirty works 3 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [clumping] clumping 602 tracks and 48 auxfiles 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [clumping] finished 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 64 dirty tracks 3 dirty albums 5 dirty performers 7 dirty works 9 dirty performances 3 dirty genres 2 dirty folders 64 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 64 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 93 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] removed in 0ms: 2 album documents, 64 track documents, 7 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] added in 9ms: 2 album documents, 64 track documents, 7 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library/playlist] saving playlist folder 10:1:2fbd43db-3328-4514-91b5-3303e447c95c [root] 01/05 21:28:33 [Local 01/05 22:28:33] Trace: finished updating 1 dirty playlists and 1 dirty playlist folders 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:3 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 660454 bytes, 255 ops in 135 ms (cumulative 1429366 bytes, 560 ops in 6232 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] endmutation in 100ms 01/05 21:28:33 [Local 01/05 22:28:33] Info: [updatemetadata] spinqueue _q size=68 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [metadatasvc] REQ [5] https://metadataserver.roonlabs.net/md/4/updatemetadata?uid=e0c287db-e590-4bf2-a9ac-e64f126fa4bb&lid=&token=e20928e7-d545-4266-b0df-b06b3c0a3014&metadataid[]=6100323938363236383334313836393432&metadataid[]=6100323938363236383334313836393730&metadataid[]=6100323938363236383334313836393737&metadataid[]=6100323938363236383334313836393439&metadataid[]=6100323938363236383334313836393536&metadataid[]=6100323938363236383334313836393633&metadataid[]=6100323938363236383334313836393336&metadataid[]=6100323938363236383334313836393634&metadataid[]=6100323938363236383334313836393731&metadataid[]=6100323938363236383334313836393433&metadataid[]=6100323938363236383334313836393530&metadataid[]=6100323938363236383334313836393537&metadataid[]=6100323938363236383334313836393631&metadataid[]=6100323938363236383334313836393735&metadataid[]=6100323938363236383334313836393337&metadataid[]=6100323938363236383334313836393338&metadataid[]=6100323938363236383334313836393339&metadataid[]=6100323938363236383334313836393635&metadataid[]=6100323938363236383334313836393636&metadataid[]=6100323938363236383334313836393637&metadataid[]=6100323938363236383334313836393638&metadataid[]=6100323938363236383334313836393732&metadataid[]=6100323938363236383334313836393733&metadataid[]=6100323938363236383334313836393734&metadataid[]=6100323938363236383334313836393434&metadataid[]=6100323938363236383334313836393435&metadataid[]=6100323938363236383334313836393436&metadataid[]=6100323938363236383334313836393531&metadataid[]=6100323938363236383334313836393532&metadataid[]=6100323938363236383334313836393533&metadataid[]=6100323938363236383334313836393538&metadataid[]=6100323938363236383334313836393539&metadataid[]=6100323938363236383334313836393630&metadataid[]=6100323938363236383334313836393430&metadataid[]=6100323938363236383334313836393534&metadataid[]=6100323938363236383334313836393437&metadataid[]=6100323938363236383334313836393431&metadataid[]=6100323938363236383334313836393535&metadataid[]=6100323938363236383334313836393632&metadataid[]=6100323938363236383334313836393438&metadataid[]=6100323938363236383334313836393736&metadataid[]=6100323938363236383334313836393639&metadataid[]=6100323536323738393239373934383232&metadataid[]=6100323536323738393239373934383138&metadataid[]=6100323536323738393239373934383139&metadataid[]=6100323536323738393239373934383233&metadataid[]=6100323536323738393239373934383235&metadataid[]=6100323536323738393239373934383231&metadataid[]=6100323536323738393239373934383130&metadataid[]=6100323536323738393239373934383131&metadataid[]=6100323536323738393239373934383030&metadataid[]=6100323536323738393239373934383039&metadataid[]=6100323536323738393239373934383137&metadataid[]=6100323536323738393239373934383031&metadataid[]=6100323536323738393239373934383033&metadataid[]=6100323536323738393239373934383132&metadataid[]=6100323536323738393239373934383134&metadataid[]=6100323536323738393239373934383032&metadataid[]=6100323536323738393239373934383133&metadataid[]=6100323536323738393239373934383234&metadataid[]=6100323536323738393239373934383230&metadataid[]=6100323536323738393239373934383136&metadataid[]=6100323536323738393239373934383034&metadataid[]=6100323536323738393239373934383135&metadataid[]=6100323536323738393239373934383036&metadataid[]=6100323536323738393239373934383037&metadataid[]=6100323536323738393239373934383038&metadataid[]=6100323536323738393239373934383035&metadataid[]=79004d5730303031333433353132&metadataid[]=3e014c5445e2db31c647930d71c332f7de60&tidal=max 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [easyhttp] [43] POST to https://api.roonlabs.net/identifier/identifier/2/album?tidal=max returned after 327 ms, status code: 200, request body size: 593 B 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [identification] <687919> status: CouldNotIdentify 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [identification] <2568495> Identifying album [R. Fasano, R. Scotto, S. Bruscantini, Renato Fasano, Sesto Bruscantini, Renata Scotto, I virtuosi di Roma - Pergolesi: La Serva Padrona] with 2 tracks 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 1 dirty tracks 1 dirty albums 1 dirty performers 1 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 1 dirty tracks 1 dirty albums 2 dirty performers 1 dirty works 1 dirty performances 1 dirty genres 1 dirty folders 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 8 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] removed in 0ms: 0 album documents, 1 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 5731 bytes, 4 ops in 3 ms (cumulative 1435097 bytes, 564 ops in 6235 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] added in 0ms: 0 album documents, 1 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [metadatasvc] GOT [5] (181ms) Sooloos.Msg.Metadata.UpdateMetadataResponse: 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [metadatasvc] REQ [6] https://metadataserver.roonlabs.net/md/4/getmetadata?uid=e0c287db-e590-4bf2-a9ac-e64f126fa4bb&lid=&token=e20928e7-d545-4266-b0df-b06b3c0a3014&mode=2.0&metadataid[]=6100323938363236383334313836393432&metadataid[]=5e0167b916e2901b27458a2c186bf590873b&metadataid[]=5e01b048adddb915c94b96939407398ff57e&metadataid[]=3e01bcf73c1933c1824ea90b2816b88d2d29&metadataid[]=5e0112ccdf102f960a47b4401f9d2b291c02&metadataid[]=6100323938363236383334313836393730&metadataid[]=6100323938363236383334313836393737&metadataid[]=6100323938363236383334313836393439&metadataid[]=6100323938363236383334313836393536&metadataid[]=6100323938363236383334313836393633&metadataid[]=6100323938363236383334313836393336&metadataid[]=6100323938363236383334313836393634&metadataid[]=6100323938363236383334313836393731&metadataid[]=6100323938363236383334313836393433&metadataid[]=6100323938363236383334313836393530&metadataid[]=6100323938363236383334313836393537&metadataid[]=6100323938363236383334313836393631&metadataid[]=6100323938363236383334313836393735&metadataid[]=6100323938363236383334313836393337&metadataid[]=6100323938363236383334313836393338&metadataid[]=6100323938363236383334313836393339&metadataid[]=6100323938363236383334313836393635&metadataid[]=6100323938363236383334313836393636&metadataid[]=6100323938363236383334313836393637&metadataid[]=6100323938363236383334313836393638&metadataid[]=6100323938363236383334313836393732&metadataid[]=6100323938363236383334313836393733&metadataid[]=6100323938363236383334313836393734&metadataid[]=6100323938363236383334313836393434&metadataid[]=6100323938363236383334313836393435&metadataid[]=6100323938363236383334313836393436&metadataid[]=6100323938363236383334313836393531&metadataid[]=6100323938363236383334313836393532&metadataid[]=6100323938363236383334313836393533&metadataid[]=6100323938363236383334313836393538&metadataid[]=6100323938363236383334313836393539&metadataid[]=6100323938363236383334313836393630&metadataid[]=6100323938363236383334313836393430&metadataid[]=6100323938363236383334313836393534&metadataid[]=6100323938363236383334313836393437&metadataid[]=6100323938363236383334313836393431&metadataid[]=6100323938363236383334313836393535&metadataid[]=6100323938363236383334313836393632&metadataid[]=6100323938363236383334313836393438&metadataid[]=6100323938363236383334313836393736&metadataid[]=6100323938363236383334313836393639&metadataid[]=6100323536323738393239373934383232&metadataid[]=5e0135f913f0cee77f4f94a69df576bf56b9&metadataid[]=7c004d4330303032343938343636&metadataid[]=3e014c5445e2db31c647930d71c332f7de60&metadataid[]=5e016f5001797ff27f49bc05e96685ca930b&metadataid[]=5e014030de8191be42459eba4036d910d3f8&metadataid[]=6100323536323738393239373934383138&metadataid[]=7c004d4330303032353135323431&metadataid[]=6100323536323738393239373934383139&metadataid[]=6100323536323738393239373934383233&metadataid[]=6100323536323738393239373934383235&metadataid[]=6100323536323738393239373934383231&metadataid[]=6100323536323738393239373934383130&metadataid[]=7c004d4330303032343634323436&metadataid[]=6100323536323738393239373934383131&metadataid[]=6100323536323738393239373934383030&metadataid[]=ae010979dfa824b33a49884b5ab49a1fc344&metadataid[]=6100323536323738393239373934383039&metadataid[]=6100323536323738393239373934383137&metadataid[]=7c004d4330303032353831333630&metadataid[]=6100323536323738393239373934383031&metadataid[]=6100323536323738393239373934383033&metadataid[]=6100323536323738393239373934383132&metadataid[]=6100323536323738393239373934383134&metadataid[]=6100323536323738393239373934383032&metadataid[]=6100323536323738393239373934383133&metadataid[]=6100323536323738393239373934383234&metadataid[]=6100323536323738393239373934383230&metadataid[]=6100323536323738393239373934383136&metadataid[]=6100323536323738393239373934383034&metadataid[]=7c004d4330303032333839303531&metadataid[]=6100323536323738393239373934383135&metadataid[]=6100323536323738393239373934383036&metadataid[]=6100323536323738393239373934383037&metadataid[]=6100323536323738393239373934383038&metadataid[]=6100323536323738393239373934383035&metadataid[]=79004d5730303031333433353132&tidal=max 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 0 bytes, 0 ops in 8 ms (cumulative 1435097 bytes, 564 ops in 6243 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [easyhttp] [45] POST to https://api.roonlabs.net/identifier/identifier/2/album?tidal=max returned after 239 ms, status code: 200, request body size: 1 KB 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [identification] <2568495> status: CouldNotIdentify 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] starting cleanup with 2 dirty tracks 1 dirty albums 7 dirty performers 1 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] finished with 2 dirty tracks 1 dirty albums 8 dirty performers 2 dirty works 2 dirty performances 1 dirty genres 1 dirty folders 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 2 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 17 changed objects 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] removed in 0ms: 0 album documents, 2 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [music/searchindex] [search-index] added in 0ms: 0 album documents, 2 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library/playlist] saving playlist folder 10:1:2fbd43db-3328-4514-91b5-3303e447c95c [root] 01/05 21:28:33 [Local 01/05 22:28:33] Trace: finished updating 1 dirty playlists and 1 dirty playlist folders 01/05 21:28:33 [Local 01/05 22:28:33] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [dbperf] flush 12363 bytes, 6 ops in 0 ms (cumulative 1447460 bytes, 570 ops in 6243 ms) 01/05 21:28:33 [Local 01/05 22:28:33] Trace: [library] endmutation in 13ms 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [metadatasvc] GOT [6] (293ms) Sooloos.Msg.Metadata.GetMetadataResponse: 01/05 21:28:34 [Local 01/05 22:28:34] Info: [updatemetadata] advancing metadata timestamp on 68 tracks 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [library] starting cleanup with 68 dirty tracks 2 dirty albums 12 dirty performers 6 dirty works 9 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [clumping] clumping 559 tracks and 47 auxfiles 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [clumping] finished 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [library/compute] computing 62 / 62 tracks 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [dbperf] flush 824692 bytes, 235 ops in 100 ms (cumulative 2272152 bytes, 805 ops in 6343 ms) 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [library] finished with 68 dirty tracks 3 dirty albums 15 dirty performers 12 dirty works 12 dirty performances 9 dirty genres 2 dirty folders 68 clumping tracks, 0 clumping auxfiles 62 compute tracks, 0 deleted tracks, 68 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 121 changed objects 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [music/searchindex] [search-index] removed in 1ms: 1 album documents, 68 track documents, 6 work documents, 4 performer documents, 9 genre documents, 0 label documents, 0 tag documents 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [music/searchindex] [search-index] added in 12ms: 1 album documents, 68 track documents, 6 work documents, 4 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [library/playlist] saving playlist folder 10:1:2fbd43db-3328-4514-91b5-3303e447c95c [root] 01/05 21:28:34 [Local 01/05 22:28:34] Trace: finished updating 2 dirty playlists and 1 dirty playlist folders 01/05 21:28:34 [Local 01/05 22:28:34] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:3 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:28:34 [Local 01/05 22:28:34] Trace: [library] endmutation in 136ms 01/05 21:28:34 [Local 01/05 22:28:34] Info: [updatemetadata] finished processing all _q items 01/05 21:28:35 [Local 01/05 22:28:35] Trace: [appupdater] initial check for updates 01/05 21:28:35 [Local 01/05 22:28:35] Trace: [remoting/remotingserverv2] SENT NONFINAL DistributedBroker.UpdatesChangedResponse={ IsSupported=True WasJustUpdated=False Status='Checking' HasChangeLog=False CurrentVersion={ MachineValue=205701599 DisplayValue='2.57 (build 1599) earlyaccess' Branch='earlyaccess' } } 01/05 21:28:35 [Local 01/05 22:28:35] Debug: [base/updater] Checking for updates: https://updates.roonlabs.net/update/?v=2&serial=2ED3E935-8568-4F0F-B3C7-1430BF126930&userid=e0c287db-e590-4bf2-a9ac-e64f126fa4bb&platform=linuxx64&product=RoonServer&branding=roon&curbranch=earlyaccess&version=205701599&branch=earlyaccess&coredeviceid=a1f6742e-ae32-4f43-8e8b-a0746048d49d&deviceid=a1f6742e-ae32-4f43-8e8b-a0746048d49d&osversion=RoonOS+2.1+(build+271)+production&os64bit=true&ROONBOX_IMAGE_PLATFORM=linuxx64&ROONBOX_IMAGE_MODEL=nuc4&ROONBOX_OS_VER_MAJOR=2&ROONBOX_OS_VER_MINOR=1&ROONBOX_OS_VER_BUILD=271&ROONBOX_OS_VER_MACH=200100271&ROONBOX_OS_BRANCH=production&ROONBOX_OS_VER_DISPLAY=2.1+(build+271)+production&ROONBOX_IMAGE_TIMESTAMP=20240909144255&ROONBOX_DEVICE_VENDOR=Roon+Labs&ROONBOX_DEVICE_MODEL=Roon+Optimized+Core+Kit&ROONBOX_HOSTNAME=ROCK&ROONBOX_BRANDING=d52b2cb7-02c5-48fc-981b-a10f0aadd93b&ROONBOX_SERIAL_NUMBER=10FFE00ED7A7 01/05 21:28:35 [Local 01/05 22:28:35] Debug: [easyhttp] [47] POST to https://api.roonlabs.net/roonmobile/1/cores/announce returned after 79 ms, status code: 200, request body size: 692 B 01/05 21:28:36 [Local 01/05 22:28:36] Info: [updatemetadata] spinqueue _q size=0 01/05 21:28:36 [Local 01/05 22:28:36] Info: [updatemetadata] spinqueue _q size=0 01/05 21:28:36 [Local 01/05 22:28:36] Info: [mobile] GOT HTTP API /hello 01/05 21:28:36 [Local 01/05 22:28:36] Trace: [mobile] Got Hello Request body={"coreId":"a1f6742e-ae32-4f43-8e8b-a0746048d49d"} 01/05 21:28:36 [Local 01/05 22:28:36] Debug: [easyhttp] [48] GET to https://api.roonlabs.net/updates/update/?v=2&serial=2ED3E935-8568-4F0F-B3C7-1430BF126930&userid=e0c287db-e590-4bf2-a9ac-e64f126fa4bb&platform=linuxx64&product=RoonServer&branding=roon&curbranch=earlyaccess&version=205701599&branch=earlyaccess&coredeviceid=a1f6742e-ae32-4f43-8e8b-a0746048d49d&deviceid=a1f6742e-ae32-4f43-8e8b-a0746048d49d&osversion=RoonOS+2.1+(build+271)+production&os64bit=true&ROONBOX_IMAGE_PLATFORM=linuxx64&ROONBOX_IMAGE_MODEL=nuc4&ROONBOX_OS_VER_MAJOR=2&ROONBOX_OS_VER_MINOR=1&ROONBOX_OS_VER_BUILD=271&ROONBOX_OS_VER_MACH=200100271&ROONBOX_OS_BRANCH=production&ROONBOX_OS_VER_DISPLAY=2.1+(build+271)+production&ROONBOX_IMAGE_TIMESTAMP=20240909144255&ROONBOX_DEVICE_VENDOR=Roon+Labs&ROONBOX_DEVICE_MODEL=Roon+Optimized+Core+Kit&ROONBOX_HOSTNAME=ROCK&ROONBOX_BRANDING=d52b2cb7-02c5-48fc-981b-a10f0aadd93b&ROONBOX_SERIAL_NUMBER=10FFE00ED7A7 returned after 548 ms, status code: 204, request body size: 0 B 01/05 21:28:36 [Local 01/05 22:28:36] Debug: [appupdater] Update not needed 01/05 21:28:36 [Local 01/05 22:28:36] Trace: [remoting/remotingserverv2] SENT NONFINAL DistributedBroker.UpdatesChangedResponse={ IsSupported=True WasJustUpdated=False Status='UpToDate' HasChangeLog=False CurrentVersion={ MachineValue=205701599 DisplayValue='2.57 (build 1599) earlyaccess' Branch='earlyaccess' } } 01/05 21:28:36 [Local 01/05 22:28:36] Debug: [easyhttp] [49] POST to https://api.roonlabs.net/roonmobile/1/cores/announce returned after 88 ms, status code: 200, request body size: 692 B 01/05 21:28:36 [Local 01/05 22:28:36] Trace: [raatserver] [sood] Refreshing device list 01/05 21:28:36 [Local 01/05 22:28:36] Trace: [library] endmutation in 13ms 01/05 21:28:36 [Local 01/05 22:28:36] Debug: [easyhttp] [50] POST to https://api.roonlabs.net/discovery/1/register returned after 247 ms, status code: 200, request body size: 1 KB 01/05 21:28:36 [Local 01/05 22:28:36] Trace: [inetdiscovery] registered 1 devices, 5 services 01/05 21:28:36 [Local 01/05 22:28:36] Info: [stats] 6309mb Virtual, 1174mb Physical, 752mb Managed, 422mb estimated Unmanaged, 363 Handles, 96 Threads, 24.14% of runtime in GC pauses, 12ms last GC pause duration 01/05 21:28:36 [Local 01/05 22:28:36] Info: [mobile] GOT HTTP API /hello 01/05 21:28:36 [Local 01/05 22:28:36] Trace: [mobile] Got Hello Request body={"coreId":"a1f6742e-ae32-4f43-8e8b-a0746048d49d"} 01/05 21:28:43 [Local 01/05 22:28:43] Debug: [easyhttp] [51] POST to https://api.roonlabs.net/device-map/1/register returned after 207 ms, status code: 200, request body size: 8 KB 01/05 21:28:43 [Local 01/05 22:28:43] Trace: [devicemap] device map updated 01/05 21:28:46 [Local 01/05 22:28:46] Info: [mobile] [multinat] Network Hop 1..Found Router: 192.168.1.1 01/05 21:28:46 [Local 01/05 22:28:46] Info: [mobile] [multinat] Network Hop 2..Found Router: 10.2.0.143 01/05 21:28:46 [Local 01/05 22:28:46] Warn: [mobile] [multinat] Network Hop 3...Request timed out, Stopping trace 01/05 21:28:46 [Local 01/05 22:28:46] Info: [mobile] [multinat] Discovering Primary Router... 01/05 21:28:46 [Local 01/05 22:28:46] Info: [mobile] [multinat] Sending M-SEARCH to 239.255.255.250... 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] M-SEARCH sent. Waiting for response... 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Response received! IP: 192.168.1.1 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Primary Router Found! 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Router 1: 192.168.1.1 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Device description URL: http://192.168.1.1:5000/rootDesc.xml 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Retrieving device description... 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Port mapping control URL: http://192.168.1.1:5000/ctl/IPConn 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Creating port mapping on service: urn:schemas-upnp-org:service:WANIPConnection:1... 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Port mapped successfully! 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Mapped Port: 192.168.1.4:55000 -> 192.168.1.1:55000 (TCP) 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Router External IP: 45.83.230.98 01/05 21:28:47 [Local 01/05 22:28:47] Info: [mobile] [multinat] Reached WAN - Done! 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Multi-NAT Finished. Success: True, Error: None 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 3, Tasks: DiscoverIPv4, DiscoverIPv6, MultiNAT 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: DiscoverIPv4 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity for 45.83.230.98... 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Authorize 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Authorization Complete! 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Port Check 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 3, Tasks: DiscoverIPv6, MultiNAT, VerifyConnectivityIPv4 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: DiscoverIPv6 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 2, Tasks: MultiNAT, VerifyConnectivityIPv4 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: MultiNAT 01/05 21:28:47 [Local 01/05 22:28:47] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 1, Tasks: VerifyConnectivityIPv4 01/05 21:28:48 [Local 01/05 22:28:48] Info: [mobile] GOT HTTP API /portverify/653d7631-8b96-49ee-af56-7e84f9f789be 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] Got PortVerify Request from_guid=653d7631-8b96-49ee-af56-7e84f9f789be 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] Returning guid for verification: 012e47cd-de6a-464e-8dfe-566ff4ef2ceb 01/05 21:28:48 [Local 01/05 22:28:48] Debug: [easyhttp] [52] POST to https://api.roonlabs.net/porttest/1/port/check returned after 636 ms, status code: 200, request body size: 745 B 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Port Check Requested: 200 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Result: Success 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: VerifyConnectivityIPv4 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] All Connectivity tasks completed! Tasks Pending 0 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Processing results... 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Gathering diagnostics data... 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] New Status: Success 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Status Changed: Ready 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Announcing... 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] OnChanged Event 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Status Change Done! 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Exiting Verification Task: {"ipv4_connectivity":{"status":"Success","status_code":200,"error":""},"external_ip":{"actual_external_ip":"45.aaa.bbb.ccc","actual_external_ipv6":"null","router_external_ip":"45.aaa.bbb.ccc"},"natpmp_autoconfig":{"status":"NotFound"},"upnp_autoconfig":{"status":"NotFound"},"multinat_autoconfig":{"status":"Success","error":"No Error","routers":2,"routers_mapped":1}} 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Verification Task Completed! 01/05 21:28:48 [Local 01/05 22:28:48] Trace: [mobile] [remoteconnectivity] Got Verification Task Result: {"ipv4_connectivity":{"status":"Success","status_code":200,"error":""},"external_ip":{"actual_external_ip":"45.aaa.bbb.ccc","actual_external_ipv6":"null","router_external_ip":"45.aaa.bbb.ccc"},"natpmp_autoconfig":{"status":"NotFound"},"upnp_autoconfig":{"status":"NotFound"},"multinat_autoconfig":{"status":"Success","error":"No Error","routers":2,"routers_mapped":1}} 01/05 21:28:48 [Local 01/05 22:28:48] Debug: [easyhttp] [53] POST to https://api.roonlabs.net/roonmobile/1/cores/announce returned after 91 ms, status code: 200, request body size: 734 B 01/05 21:28:49 [Local 01/05 22:28:49] Info: [mobile] GOT HTTP API /hello 01/05 21:28:49 [Local 01/05 22:28:49] Trace: [mobile] Got Hello Request body={"coreId":"a1f6742e-ae32-4f43-8e8b-a0746048d49d"} 01/05 21:28:51 [Local 01/05 22:28:51] Info: [stats] 6189mb Virtual, 1175mb Physical, 752mb Managed, 423mb estimated Unmanaged, 369 Handles, 81 Threads, 17.89% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:29:01 [Local 01/05 22:29:01] Debug: [easyhttp] [54] POST to https://api.roonlabs.net/discovery/1/query returned after 241 ms, status code: 200, request body size: 74 B 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [devicemanager/sonos] FOUND Device IP=192.168.1.48 UDN=uuid:RINCON_347E5C33053401400 Manufacturer=Sonos, Inc. ModelName=SYMFONISK Bookshelf ModelNumber=S21 01/05 21:29:06 [Local 01/05 22:29:06] Warn: [client/sonos] Client created for id: uuid:RINCON_347E5C33053401400 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [device/sonos] [sonos] device constructor, UDN: uuid:RINCON_347E5C33053401400 modelname: ISK BOOKSHELF remoteIP: 192.168.1.48 01/05 21:29:06 [Local 01/05 22:29:06] Info: [transport] creating endpoint for sonos device 23:1:e6bd9722-13a2-8791-edc9-bf5b22e56a38 in Thread[Id=14, Name=Broker:Transport] 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [dspengine] created new dsp config {"version":4,"items":[{"type":"bs2b","enabled":false},{"type":"parametric_equalizer","enabled":false},{"type":"ohd_presets","enabled":false}]} 01/05 21:29:06 [Local 01/05 22:29:06] Debug: [open headphone database] HeadphoneEqItem constructor start 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [devicemanager/sonos] found device UUID: RINCON_347E5C33053401400 from zone state, searching by ip: 192.168.1.48 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [devicemanager/sonos] found device UUID: RINCON_347E5C33068E01400 from zone state, searching by ip: 192.168.1.35 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [devicemanager/sonos] found device UUID: RINCON_347E5CF014C201400 from zone state, searching by ip: 192.168.1.62 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [devicedb] [autodetect] No Match for DeviceAutodetectData[Type=Sonos Vendor=Sonos Model=ISK BOOKSHELF DescriptiveName=Atelier (ISK BOOKSHELF)] 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [zone Atelier (Sonos)] Loading from /roon/data/RoonServer/Database/Core/e0c287dbe5904bf2a9ace64f126fa4bb/transport/zone_16012297bde6a2139187edc9bf5b22e56a38.db 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [zone Atelier (Sonos)] Suspend 01/05 21:29:06 [Local 01/05 22:29:06] Info: [zone Atelier (Sonos)] Canceling Pending Sleep 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [Atelier (Sonos)] [zoneplayer/sonos] constructor, zonecoordinator: RINCON_347E5C33053401400 01/05 21:29:06 [Local 01/05 22:29:06] Info: [transport] created zone Atelier (Sonos) 01/05 21:29:06 [Local 01/05 22:29:06] Info: [transport] with endpoint Atelier (ISK BOOKSHELF) (23:1:e6bd9722-13a2-8791-edc9-bf5b22e56a38) [IsAvailable=True] 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [Atelier (Sonos)] [Inactive] [STOPPED @ 0:00] 01/05 21:29:06 [Local 01/05 22:29:06] Trace: [zone Atelier (Sonos)] Loaded Queue=0 Tracks Swim=Inactive AutoSwim=True Loop=Disabled Shuffle=False 01/05 21:29:06 [Local 01/05 22:29:06] Info: [stats] 6101mb Virtual, 1175mb Physical, 754mb Managed, 421mb estimated Unmanaged, 374 Handles, 73 Threads, 12.35% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [devicemanager/sonos] FOUND Device IP=192.168.1.62 UDN=uuid:RINCON_347E5CF014C201400 Manufacturer=Sonos, Inc. ModelName=SYMFONISK Bookshelf ModelNumber=S21 01/05 21:29:07 [Local 01/05 22:29:07] Warn: [client/sonos] Client created for id: uuid:RINCON_347E5CF014C201400 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [device/sonos] [sonos] device constructor, UDN: uuid:RINCON_347E5CF014C201400 modelname: ISK BOOKSHELF remoteIP: 192.168.1.62 01/05 21:29:07 [Local 01/05 22:29:07] Info: [transport] creating endpoint for sonos device 23:1:cd72dddd-f8b7-291a-01a8-105cbf14dbc0 in Thread[Id=14, Name=Broker:Transport] 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [dspengine] created new dsp config {"version":4,"items":[{"type":"bs2b","enabled":false},{"type":"parametric_equalizer","enabled":false},{"type":"ohd_presets","enabled":false}]} 01/05 21:29:07 [Local 01/05 22:29:07] Debug: [open headphone database] HeadphoneEqItem constructor start 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [devicemanager/sonos] found device UUID: RINCON_347E5CF014C201400 from zone state, searching by ip: 192.168.1.62 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [devicemanager/sonos] found device UUID: RINCON_347E5C33053401400 from zone state, searching by ip: 192.168.1.48 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [devicemanager/sonos] found device UUID: RINCON_347E5C33068E01400 from zone state, searching by ip: 192.168.1.35 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [devicedb] [autodetect] No Match for DeviceAutodetectData[Type=Sonos Vendor=Sonos Model=ISK BOOKSHELF DescriptiveName=Chambre (ISK BOOKSHELF)] 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [zone Chambre (Sonos)] Loading from /roon/data/RoonServer/Database/Core/e0c287dbe5904bf2a9ace64f126fa4bb/transport/zone_1601dddd72cdb7f81a2901a8105cbf14dbc0.db 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [zone Chambre (Sonos)] Suspend 01/05 21:29:07 [Local 01/05 22:29:07] Info: [zone Chambre (Sonos)] Canceling Pending Sleep 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [Chambre (Sonos)] [zoneplayer/sonos] constructor, zonecoordinator: RINCON_347E5CF014C201400 01/05 21:29:07 [Local 01/05 22:29:07] Info: [transport] created zone Chambre (Sonos) 01/05 21:29:07 [Local 01/05 22:29:07] Info: [transport] with endpoint Chambre (ISK BOOKSHELF) (23:1:cd72dddd-f8b7-291a-01a8-105cbf14dbc0) [IsAvailable=True] 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [Chambre (Sonos)] [Inactive] [STOPPED @ 0:00] 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [endpoint/sonos/uuid:RINCON_347E5C33053401400] zone update: 01/05 21:29:07 [Local 01/05 22:29:07] Warn: [endpoint/sonos/uuid:RINCON_347E5C33053401400] unlink check, dev id: uuid:RINCON_347E5C33053401400, devname: uuid:RINCON_347E5C33053401400, zone coordinator: , coordinatorid: RINCON_347E5C33053401400 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [client/sonos] av_status 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [zone Chambre (Sonos)] Loaded Queue=1248 Tracks Swim=Inactive AutoSwim=True Loop=Disabled Shuffle=False 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [Chambre (Sonos)] [Inactive] [PAUSED @ 0:45/4:22] Rêveurs - Alain Souchon 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [mobile] [remoteconnectivity] found new upnp device: Device={ DeviceType=urn:schemas-upnp-org:device:WFADevice Version=1 FriendlyName=RBR350(AP) Manufacturer=NETGEAR,Inc. ModelName=NETGEAR Orbi Dual Band AX1800 Router UDN=uuid:d35c67b7-9c12-430b-a6b3-c899b2d86c71 Description=http://www.netgear.com/home/products/wirelessrouters ModelNumber=RBR350 UPC=RBR350 ManufacturerUri=http://www.netgear.com/ ModelUrl=http://www.netgear.com/orbiDevice={ DeviceType=urn:schemas-upnp-org:device:WANDevice Version=1 FriendlyName=WANDevice Manufacturer=NETGEAR,Inc. ModelName=NETGEAR Orbi Dual Band AX1800 Router UDN=uuid:d35c67b7-9c12-430b-a6b3-c899b2d86c72 Description=WANDevice on NETGEAR RBR350 Orbi Router ModelNumber=RBR350 UPC=606449084528 ManufacturerUri=http://www.netgear.com/ ModelUrl=http://www.netgear.com/orbiDevice={ DeviceType=urn:schemas-upnp-org:device:WANConnectionDevice Version=1 FriendlyName=WANConnectionDevice Manufacturer=NETGEAR,Inc. ModelName=NETGEAR Orbi Dual Band AX1800 Router UDN=uuid:d35c67b7-9c12-430b-a6b3-c899b2d86c73 Description=WANConnectionDevice on NETGEAR RBR350 Orbi Router ModelNumber=RBR350 UPC=606449084528 ManufacturerUri=http://www.netgear.com/ ModelUrl=http://www.netgear.com/orbiService={ ServiceType=urn:schemas-upnp-org:service:WANEthernetLinkConfig ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANEthLinkC1 ControlUri=http://192.168.1.2:56688/ctl/WanEth SCPDUri=http://192.168.1.2:56688/WanEth.xml } Service={ ServiceType=urn:schemas-upnp-org:service:WANIPConnection ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANIPConn1 ControlUri=http://192.168.1.2:56688/ctl/IPConn SCPDUri=http://192.168.1.2:56688/WANIPCn.xml } } Service={ ServiceType=urn:schemas-upnp-org:service:WANCommonInterfaceConfig ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANCommonIFC1 ControlUri=http://192.168.1.2:56688/ctl/CmnIfCfg SCPDUri=http://192.168.1.2:56688/WANCfg.xml } } Service={ ServiceType=urn:schemas-upnp-org:service:Layer3Forwarding ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:L3Forwarding1 ControlUri=http://192.168.1.2:56688/ctl/L3F SCPDUri=http://192.168.1.2:56688/L3F.xml } } 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [mobile] [remoteconnectivity] Port Verification started due to: found UPnP WANConnectiondevice, port verification not in progress, starting a new attempt 01/05 21:29:07 [Local 01/05 22:29:07] Info: [mobile] [multinat] >> Mapping port: 55000... 01/05 21:29:07 [Local 01/05 22:29:07] Info: [mobile] [multinat] Searching for Routers on Local Network... 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [endpoint/sonos/uuid:RINCON_347E5CF014C201400] zone update: 01/05 21:29:07 [Local 01/05 22:29:07] Warn: [endpoint/sonos/uuid:RINCON_347E5CF014C201400] unlink check, dev id: uuid:RINCON_347E5CF014C201400, devname: uuid:RINCON_347E5CF014C201400, zone coordinator: , coordinatorid: RINCON_347E5CF014C201400 01/05 21:29:07 [Local 01/05 22:29:07] Trace: [client/sonos] av_status 01/05 21:29:08 [Local 01/05 22:29:08] Debug: [easyhttp] [55] GET to https://porttest.roonlabs.net/1/myip returned after 515 ms, status code: 200, request body size: 0 B 01/05 21:29:17 [Local 01/05 22:29:17] Debug: [easyhttp] [56] POST to https://api.roonlabs.net/device-map/1/register returned after 178 ms, status code: 200, request body size: 8 KB 01/05 21:29:17 [Local 01/05 22:29:17] Trace: [devicemap] device map updated 01/05 21:29:21 [Local 01/05 22:29:21] Info: [stats] 6135mb Virtual, 1187mb Physical, 756mb Managed, 431mb estimated Unmanaged, 386 Handles, 73 Threads, 10.02% of runtime in GC pauses, 6ms last GC pause duration 01/05 21:29:22 [Local 01/05 22:29:22] Info: [mobile] [multinat] Network Hop 1..Found Router: 192.168.1.1 01/05 21:29:22 [Local 01/05 22:29:22] Info: [mobile] [multinat] Network Hop 2..Found Router: 10.2.0.143 01/05 21:29:22 [Local 01/05 22:29:22] Warn: [mobile] [multinat] Network Hop 3...Request timed out, Stopping trace 01/05 21:29:22 [Local 01/05 22:29:22] Info: [mobile] [multinat] Discovering Primary Router... 01/05 21:29:22 [Local 01/05 22:29:22] Info: [mobile] [multinat] Sending M-SEARCH to 239.255.255.250... 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] M-SEARCH sent. Waiting for response... 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Response received! IP: 192.168.1.1 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Primary Router Found! 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Router 1: 192.168.1.1 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Using cached Control URL for Router: 192.168.1.1 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Port mapping control URL: http://192.168.1.1:5000/ctl/IPConn 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Creating port mapping on service: urn:schemas-upnp-org:service:WANIPConnection:1... 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [storage] [directory] timer delay: 120000, retrycount: 3 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Port mapped successfully! 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Mapped Port: 192.168.1.4:55000 -> 192.168.1.1:55000 (TCP) 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Router External IP: 45.83.230.98 01/05 21:29:23 [Local 01/05 22:29:23] Info: [mobile] [multinat] Reached WAN - Done! 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Multi-NAT Finished. Success: True, Error: None 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 3, Tasks: DiscoverIPv4, DiscoverIPv6, MultiNAT 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: DiscoverIPv4 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity for 45.83.230.98... 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Authorize 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Authorization Complete! 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Port Check 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 3, Tasks: DiscoverIPv6, MultiNAT, VerifyConnectivityIPv4 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: DiscoverIPv6 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 2, Tasks: MultiNAT, VerifyConnectivityIPv4 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: MultiNAT 01/05 21:29:23 [Local 01/05 22:29:23] Trace: [mobile] [remoteconnectivity] Waiting for Connectivity tasks to finish. Pending Tasks Count: 1, Tasks: VerifyConnectivityIPv4 01/05 21:29:24 [Local 01/05 22:29:24] Info: [mobile] GOT HTTP API /portverify/01926e2c-056f-4830-b5ae-fcf684269745 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] Got PortVerify Request from_guid=01926e2c-056f-4830-b5ae-fcf684269745 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] Returning guid for verification: 20ad9276-d82b-4c53-88c6-60b6da2a66ac 01/05 21:29:24 [Local 01/05 22:29:24] Debug: [easyhttp] [57] POST to https://api.roonlabs.net/porttest/1/port/check returned after 770 ms, status code: 200, request body size: 745 B 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Port Check Requested: 200 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Testing IPv4 Connectivity...Result: Success 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Connectivity task finished. Task: VerifyConnectivityIPv4 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] All Connectivity tasks completed! Tasks Pending 0 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Processing results... 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Gathering diagnostics data... 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] New Status: Success 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Status Changed: Ready 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Announcing... 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] OnChanged Event 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Status Change Done! 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Exiting Verification Task: {"ipv4_connectivity":{"status":"Success","status_code":200,"error":""},"external_ip":{"actual_external_ip":"45.aaa.bbb.ccc","actual_external_ipv6":"null","router_external_ip":"45.aaa.bbb.ccc"},"natpmp_autoconfig":{"status":"NotFound"},"upnp_autoconfig":{"status":"NotFound"},"multinat_autoconfig":{"status":"Success","error":"No Error","routers":2,"routers_mapped":1}} 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Verification Task Completed! 01/05 21:29:24 [Local 01/05 22:29:24] Trace: [mobile] [remoteconnectivity] Got Verification Task Result: {"ipv4_connectivity":{"status":"Success","status_code":200,"error":""},"external_ip":{"actual_external_ip":"45.aaa.bbb.ccc","actual_external_ipv6":"null","router_external_ip":"45.aaa.bbb.ccc"},"natpmp_autoconfig":{"status":"NotFound"},"upnp_autoconfig":{"status":"NotFound"},"multinat_autoconfig":{"status":"Success","error":"No Error","routers":2,"routers_mapped":1}} 01/05 21:29:24 [Local 01/05 22:29:24] Debug: [easyhttp] [58] POST to https://api.roonlabs.net/roonmobile/1/cores/announce returned after 313 ms, status code: 200, request body size: 734 B 01/05 21:29:25 [Local 01/05 22:29:25] Info: [mobile] GOT HTTP API /hello 01/05 21:29:25 [Local 01/05 22:29:25] Trace: [mobile] Got Hello Request body={"coreId":"a1f6742e-ae32-4f43-8e8b-a0746048d49d"} 01/05 21:29:36 [Local 01/05 22:29:36] Info: [stats] 6047mb Virtual, 1191mb Physical, 759mb Managed, 432mb estimated Unmanaged, 386 Handles, 66 Threads, 8.79% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:29:41 [Local 01/05 22:29:41] Warn: null SortEnv language. Defaulting to current culture. 01/05 21:29:41 [Local 01/05 22:29:41] Debug: [history] loading history for f8b3989a-d5a1-40d7-a3a9-3f33a5f206bb 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [history] Loading plays 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [history] loaded 1463 plays, 1150 have tracks, 1103 lib plays, 47 non-lib plays 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [history] history loaded in 11ms 01/05 21:29:41 [Local 01/05 22:29:41] Trace: computing profile stats 01/05 21:29:41 [Local 01/05 22:29:41] Trace: done computing profile stats 01/05 21:29:41 [Local 01/05 22:29:41] Debug: [music/profilestats] Computed stats in 32ms, got 6 top albums, 10 top performers, 2 genres 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/query] performing channel query 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/query] query returned 7 Sooloos.Broker.Api.Channel(s) 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/genrerules] loading genre rules from /roon/app/RoonServer/Appliance/genrerules.csv 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [library] starting cleanup with 14 dirty genres , 0 tracks to retain, 0 auxfiles to retain 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [library] finished with 14 dirty genres 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 14 changed objects 01/05 21:29:41 [Local 01/05 22:29:41] Warn: null SortEnv language. Defaulting to current culture. 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/query] performing channel query 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/query] query returned 7 Sooloos.Broker.Api.Channel(s) 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/query] performing channel query 01/05 21:29:41 [Local 01/05 22:29:41] Trace: [radio/query] query returned 7 Sooloos.Broker.Api.Channel(s) 01/05 21:29:41 [Local 01/05 22:29:41] Debug: [easyhttp] [59] GET to https://api.roonlabs.net/internetradio/2/api/stations/all?count=100&sortby=popular&location=auto&maxDistance=500&format=msgpack& returned after 593 ms, status code: 200, request body size: 0 B 01/05 21:29:42 [Local 01/05 22:29:42] Debug: [easyhttp] [61] GET to https://api.roonlabs.net/internetradio/2/api/stations/all?count=100&sortby=popular&location=auto&maxDistance=500&format=msgpack& returned after 563 ms, status code: 200, request body size: 0 B 01/05 21:29:42 [Local 01/05 22:29:42] Trace: GetImageData[Remote](id=40809 spec=1by1_512 key=pjicaaaa) => got from cache overalltime=1ms 01/05 21:29:42 [Local 01/05 22:29:42] Trace: GetImageData[Remote](id=12598 spec=1by1_512 key=oqsaaaaa) => got from cache overalltime=1ms 01/05 21:29:42 [Local 01/05 22:29:42] Trace: GetImageData[Remote](id=12598 spec=1by1_512 key=oqsaaaaa) => got from cache overalltime=2ms 01/05 21:29:42 [Local 01/05 22:29:42] Trace: GetImageData[Remote](id=40809 spec=1by1_512 key=pjicaaaa) => got from cache overalltime=3ms 01/05 21:29:42 [Local 01/05 22:29:42] Trace: GetImageData[Remote](id=12208 spec=1by1_512 key=obsaaaaa) => got from cache overalltime=0ms 01/05 21:29:42 [Local 01/05 22:29:42] Trace: GetImageData[Remote](id=12208 spec=1by1_512 key=obsaaaaa) => got from cache overalltime=1ms 01/05 21:29:42 [Local 01/05 22:29:42] Debug: [easyhttp] [60] GET to https://api.roonlabs.net/internetradio/2/api/stations/all?count=100&sortby=popular&location=auto&maxDistance=500&format=msgpack& returned after 1060 ms, status code: 200, request body size: 0 B 01/05 21:29:43 [Local 01/05 22:29:43] Trace: [library] endmutation in 12ms 01/05 21:29:43 [Local 01/05 22:29:43] Trace: GetImageData[Remote](id=1942 spec=16by7_1024 key=swcaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030353035323635/photo/16by7_1024.jpg) => fetched in 1342ms status=200 size=110260 overalltime=1895ms 01/05 21:29:43 [Local 01/05 22:29:43] Trace: GetImageData[Remote](id=14738 spec=1by1_512 key=wuvaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030363931323339/photo/1by1_512.jpg) => fetched in 1580ms status=304 size=0 overalltime=1582ms 01/05 21:29:46 [Local 01/05 22:29:46] Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates 01/05 21:29:46 [Local 01/05 22:29:46] Info: [library/albumdetails] Created album details screen for LibraryAlbum[3467567, Murray Perahia - Bach: Partitas pour clavier n°1 à 6] 01/05 21:29:46 [Local 01/05 22:29:46] Info: [library/albumdetails] 3e01b34827b4a87d6d418113c6bc945ad9f0 01/05 21:29:46 [Local 01/05 22:29:46] Trace: [music/query] performing album query 01/05 21:29:46 [Local 01/05 22:29:46] Warn: null SortEnv language. Defaulting to current culture. 01/05 21:29:46 [Local 01/05 22:29:46] Trace: [music/query] query returned 4 Sooloos.Broker.Api.AlbumLite(s) 01/05 21:29:46 [Local 01/05 22:29:46] Trace: [music/query] performing album query 01/05 21:29:46 [Local 01/05 22:29:46] Trace: [music/query] query returned 0 Sooloos.Broker.Api.AlbumLite(s) 01/05 21:29:46 [Local 01/05 22:29:46] Trace: GetImageData[Remote](id=115215 spec=512 key=jlogaaaa) => got from cache overalltime=0ms 01/05 21:29:46 [Local 01/05 22:29:46] Trace: GetImageData[Remote](id=115215 spec=512 key=jlogaaaa) => got from cache overalltime=0ms 01/05 21:29:47 [Local 01/05 22:29:47] Debug: [easyhttp] [65] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=62:1:b42748b3-7da8-416d-8113-c6bc945ad9f0&type=review&sourceLangs=Wikipedia:fr,Wikipedia:en,Rovi-compositions:en,Rovi-artists:en,Rovi-albums:en,Wikipedia:en-simple&contentPreferences=preferMqa&tidal=max returned after 218 ms, status code: 200, request body size: 0 B 01/05 21:29:47 [Local 01/05 22:29:47] Trace: GetImageData[Local](id=38613 spec=256 key=ddfcaaaa) => gotfromcache=False missinglocalimage=False didscale=True scaletime=126), overalltime=128ms 01/05 21:29:47 [Local 01/05 22:29:47] Trace: GetImageData[Local](id=38613 spec=256 key=ddfcaaaa) => gotfromcache=False missinglocalimage=False didscale=True scaletime=126), overalltime=129ms 01/05 21:29:47 [Local 01/05 22:29:47] Trace: GetImageData[Local](id=41843 spec=256 key=jxjcaaaa) => gotfromcache=False missinglocalimage=False didscale=True scaletime=127), overalltime=130ms 01/05 21:29:47 [Local 01/05 22:29:47] Trace: GetImageData[Local](id=41843 spec=256 key=jxjcaaaa) => gotfromcache=False missinglocalimage=False didscale=True scaletime=127), overalltime=130ms 01/05 21:29:47 [Local 01/05 22:29:47] Debug: [easyhttp] [64] GET to https://api.roonlabs.net/discover/1/albums/62:1:b42748b3-7da8-416d-8113-c6bc945ad9f0/performers/similar?profileId=f8b3989a-d5a1-40d7-a3a9-3f33a5f206bb&languages=fr,en,%3Efr&tidal=max returned after 320 ms, status code: 200, request body size: 0 B 01/05 21:29:47 [Local 01/05 22:29:47] Trace: GetImageData[Remote](id=110216 spec=256 key=cbhgaaaa uri=https://imagecache.roonlabs.net/im/1/albums/79004d5730303031333932373737/cover/256.jpg) => fetched in 318ms status=304 size=0 overalltime=319ms 01/05 21:29:47 [Local 01/05 22:29:47] Trace: [library] starting cleanup with 1 dirty performers , 0 tracks to retain, 0 auxfiles to retain 01/05 21:29:47 [Local 01/05 22:29:47] Trace: [library] finished with 1 dirty performers 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 1 changed objects 01/05 21:29:47 [Local 01/05 22:29:47] Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 2272152 bytes, 805 ops in 6344 ms) 01/05 21:29:49 [Local 01/05 22:29:49] Info: [broker/httpserver] scaled 600,600 => 64,64 in 1ms 01/05 21:29:49 [Local 01/05 22:29:49] Info: [broker/httpserver] scaled 599,599 => 64,64 in 1ms 01/05 21:29:49 [Local 01/05 22:29:49] Info: [broker/httpserver] scaled 2560,2366 => 64,64 in 9ms 01/05 21:29:49 [Local 01/05 22:29:49] Info: [broker/httpserver] scaled 2212,978 => 64,64 in 11ms 01/05 21:29:49 [Local 01/05 22:29:49] Info: [broker/httpserver] scaled 1069,958 => 64,64 in 129ms 01/05 21:29:49 [Local 01/05 22:29:49] Trace: GetImageData[Remote](id=115215 spec=64 key=jlogaaaa uri=https://imagecache.roonlabs.net/im/1/albums/3e01b34827b4a87d6d418113c6bc945ad9f0/cover/64.jpg) => fetched in 274ms status=304 size=0 overalltime=275ms 01/05 21:29:49 [Local 01/05 22:29:49] Trace: GetImageData[Remote](id=115215 spec=2048 key=jlogaaaa uri=https://imagecache.roonlabs.net/im/1/albums/3e01b34827b4a87d6d418113c6bc945ad9f0/cover/2048.jpg) => fetched in 357ms status=304 size=0 overalltime=364ms 01/05 21:29:51 [Local 01/05 22:29:51] Info: [stats] 6080mb Virtual, 1218mb Physical, 774mb Managed, 444mb estimated Unmanaged, 388 Handles, 68 Threads, 7.3% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:29:52 [Local 01/05 22:29:52] Info: [broker/httpserver] scaled 2560,2366 => 2048,2048 in 192ms 01/05 21:29:52 [Local 01/05 22:29:52] Info: [broker/httpserver] scaled 2212,978 => 2048,2048 in 131ms 01/05 21:29:56 [Local 01/05 22:29:56] Info: [library] saved recent ProfileId=f8b3989a-d5a1-40d7-a3a9-3f33a5f206bb Time=01/05/2026 21:29:56 DataType=album Type=long_nav MetadataId=8282686 ContentId=3467567 LibraryId=3467567 Text= Genre= 01/05 21:30:06 [Local 01/05 22:30:06] Info: [stats] 6128mb Virtual, 1244mb Physical, 590mb Managed, 654mb estimated Unmanaged, 387 Handles, 74 Threads, 6.41% of runtime in GC pauses, 8ms last GC pause duration 01/05 21:30:18 [Local 01/05 22:30:18] Debug: [easyhttp] [69] POST to https://api.roonlabs.net/device-map/1/register returned after 219 ms, status code: 200, request body size: 8 KB 01/05 21:30:18 [Local 01/05 22:30:18] Trace: [devicemap] device map updated 01/05 21:30:21 [Local 01/05 22:30:21] Info: [stats] 6128mb Virtual, 1228mb Physical, 398mb Managed, 830mb estimated Unmanaged, 386 Handles, 74 Threads, 5.9% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:30:36 [Local 01/05 22:30:36] Info: [stats] 6064mb Virtual, 1229mb Physical, 398mb Managed, 831mb estimated Unmanaged, 386 Handles, 65 Threads, 5.25% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:30:51 [Local 01/05 22:30:51] Info: [stats] 6064mb Virtual, 1229mb Physical, 397mb Managed, 832mb estimated Unmanaged, 386 Handles, 63 Threads, 4.79% of runtime in GC pauses, 6ms last GC pause duration 01/05 21:30:55 [Local 01/05 22:30:55] Trace: [storage] [directory] force rescan requested for /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [storage] [directory] extracting /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/9. Test Hifi/[TEST] Yuri Korzunov Through [DSDFLAC HD Format Test]/yuri-korzunov_through_chill_2022_1024fs.dsf 01/05 21:30:56 [Local 01/05 22:30:56] Warn: [storage] [directory] Unsupported stream parameters from '/roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/9. Test Hifi/[TEST] Yuri Korzunov Through [DSDFLAC HD Format Test]/yuri-korzunov_through_chill_2022_1024fs.dsf': StreamParams[SampleRate=45158400, BitsPerSample=1, Channels=2, Layout=Stereo FrameCount=7176524472] 01/05 21:30:56 [Local 01/05 22:30:56] Info: [importstatus] notifying 0 imports completed 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [storage] [directory] initial scan of /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music took: 1116 ms 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [radio/query] performing channel query 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [radio/query] query returned 7 Sooloos.Broker.Api.Channel(s) 01/05 21:30:56 [Local 01/05 22:30:56] Trace: GetImageData[Remote](id=32578 spec=16by7_1024 key=afwbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030323535323130/photo/16by7_1024.jpg) => fetched in 62ms status=304 size=0 overalltime=64ms 01/05 21:30:56 [Local 01/05 22:30:56] Trace: GetImageData[Remote](id=38528 spec=1by1_512 key=wzecaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030373638363039/photo/1by1_512.jpg) => fetched in 73ms status=304 size=0 overalltime=74ms 01/05 21:30:56 [Local 01/05 22:30:56] Debug: [easyhttp] [71] GET to https://api.roonlabs.net/internetradio/2/api/stations/all?count=100&sortby=popular&location=auto&maxDistance=500&format=msgpack& returned after 309 ms, status code: 200, request body size: 0 B 01/05 21:30:56 [Local 01/05 22:30:56] Trace: GetImageData[Remote](id=39541 spec=16by7_1024 key=vmgcaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030373432323835/photo/16by7_1024.jpg) => fetched in 161ms status=200 size=161520 overalltime=197ms 01/05 21:30:56 [Local 01/05 22:30:56] Debug: [music/storage] processing simple delete for auxfile 67:0:0. Rip in Progress/Bach Partitas pour clavier - Murray Perahia (2018) [Apple Lossless]/Bach-Partitas-n-1-a-6-par-Murray-Perahia-notre-Indispensable-de-janvier-est-arrive-scaled.jpg from /Music 01/05 21:30:56 [Local 01/05 22:30:56] Debug: [music/storage] LibraryAuxFile[2594840, 0. Rip in Progress/Bach Partitas pour clavier - Murray Perahia (2018) [Apple Lossless]/Bach-Partitas-n-1-a-6-par-Murray-Perahia-notre-Indispensable-de-janvier-est-arrive-scaled.jpg] 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [library] starting cleanup with , 0 tracks to retain, 0 auxfiles to retain 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [clumping] clumping 40 tracks and 4 auxfiles 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [clumping] finished 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [library] finished with 40 dirty tracks 1 dirty albums 2 dirty performers 6 dirty works 8 dirty performances 1 dirty genres 1 dirty auxfiles 1 dirty folders 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 40 tracks to (re)load, 0 tracks to retain, 1 auxfiles to (re)load, 0 auxfiles to retain, and 59 changed objects 01/05 21:30:56 [Local 01/05 22:30:56] Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [music/searchindex] [search-index] removed in 0ms: 0 album documents, 40 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [music/searchindex] [search-index] added in 10ms: 0 album documents, 40 track documents, 0 work documents, 0 performer documents, 0 genre documents, 0 label documents, 0 tag documents 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [library/playlist] saving playlist folder 10:1:2fbd43db-3328-4514-91b5-3303e447c95c [root] 01/05 21:30:56 [Local 01/05 22:30:56] Trace: finished updating 1 dirty playlists and 1 dirty playlist folders 01/05 21:30:56 [Local 01/05 22:30:56] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:30:56 [Local 01/05 22:30:56] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty (< rebuild threshold of 624.8000000000001). re-sorting item-by-item (internaltype=LibraryAlbum) 01/05 21:30:56 [Local 01/05 22:30:56] Debug: [query] Sooloos.Broker.Music.LibraryAlbum:1 dirty items, no items in query, rebuilding? False 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [dbperf] flush 224954 bytes, 86 ops in 10 ms (cumulative 2497106 bytes, 891 ops in 6354 ms) 01/05 21:30:56 [Local 01/05 22:30:56] Trace: [library] endmutation in 72ms 01/05 21:30:57 [Local 01/05 22:30:57] Trace: GetImageData[Remote](id=7617 spec=1by1_512 key=zglaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030313431353237/photo/1by1_512.jpg) => fetched in 417ms status=304 size=0 overalltime=419ms 01/05 21:30:58 [Local 01/05 22:30:58] Trace: [music/query] performing tag query 01/05 21:30:58 [Local 01/05 22:30:58] Trace: [music/query] query returned 2 Sooloos.Broker.Api.Tag(s) 01/05 21:30:58 [Local 01/05 22:30:58] Trace: [music/query] performing tag query 01/05 21:30:58 [Local 01/05 22:30:58] Trace: [music/query] query returned 2 Sooloos.Broker.Api.Tag(s) 01/05 21:30:58 [Local 01/05 22:30:58] Trace: [music/query] performing tag query 01/05 21:30:58 [Local 01/05 22:30:58] Trace: [music/query] query returned 2 Sooloos.Broker.Api.Tag(s) 01/05 21:31:01 [Local 01/05 22:31:01] Info: [library/albumdetails] found 1 ingroup alternates, 0 other alternates 01/05 21:31:01 [Local 01/05 22:31:01] Info: [library/albumdetails] Created album details screen for LibraryAlbum[3467567, Murray Perahia - Bach: Partitas pour clavier n°1 à 6] 01/05 21:31:01 [Local 01/05 22:31:01] Info: [library/albumdetails] 3e01b34827b4a87d6d418113c6bc945ad9f0 01/05 21:31:01 [Local 01/05 22:31:01] Trace: [music/query] performing album query 01/05 21:31:01 [Local 01/05 22:31:01] Trace: [music/query] query returned 4 Sooloos.Broker.Api.AlbumLite(s) 01/05 21:31:01 [Local 01/05 22:31:01] Trace: [music/query] performing album query 01/05 21:31:01 [Local 01/05 22:31:01] Trace: [music/query] query returned 0 Sooloos.Broker.Api.AlbumLite(s) 01/05 21:31:01 [Local 01/05 22:31:01] Debug: [easyhttp] [77] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=62:1:b42748b3-7da8-416d-8113-c6bc945ad9f0&type=review&sourceLangs=Wikipedia:fr,Wikipedia:en,Rovi-compositions:en,Rovi-artists:en,Rovi-albums:en,Wikipedia:en-simple&contentPreferences=preferMqa&tidal=max returned after 124 ms, status code: 200, request body size: 0 B 01/05 21:31:02 [Local 01/05 22:31:02] Debug: [easyhttp] [76] GET to https://api.roonlabs.net/discover/1/albums/62:1:b42748b3-7da8-416d-8113-c6bc945ad9f0/performers/similar?profileId=f8b3989a-d5a1-40d7-a3a9-3f33a5f206bb&languages=fr,en,%3Efr&tidal=max returned after 839 ms, status code: 200, request body size: 0 B 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=29788 spec=1by1_128 key=sbsbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030383033373532/avatar/1by1_128.jpg) => fetched in 64ms status=200 size=6296 overalltime=66ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=5613 spec=1by1_128 key=xhiaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030313130303333/avatar/1by1_128.jpg) => fetched in 74ms status=304 size=0 overalltime=76ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=32714 spec=1by1_128 key=gkwbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303032333532373838/avatar/1by1_128.jpg) => fetched in 74ms status=304 size=0 overalltime=77ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=22253 spec=1by1_128 key=xxgbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030363830373031/avatar/1by1_128.jpg) => fetched in 77ms status=304 size=0 overalltime=78ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=885 spec=1by1_128 key=bibaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030323339333832/avatar/1by1_128.jpg) => fetched in 77ms status=304 size=0 overalltime=78ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=517 spec=1by1_128 key=xtaaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303031343536383335/avatar/1by1_128.jpg) => fetched in 80ms status=304 size=0 overalltime=83ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=38696 spec=1by1_128 key=igfcaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030393235393833/avatar/1by1_128.jpg) => fetched in 83ms status=304 size=0 overalltime=84ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=29708 spec=1by1_128 key=qyrbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030323339383539/avatar/1by1_128.jpg) => fetched in 85ms status=304 size=0 overalltime=89ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=33775 spec=1by1_128 key=bzxbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030313132353235/avatar/1by1_128.jpg) => fetched in 152ms status=304 size=0 overalltime=154ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=5713 spec=1by1_128 key=tliaaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030383033313238/avatar/1by1_128.jpg) => fetched in 182ms status=304 size=0 overalltime=185ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=26756 spec=1by1_128 key=cpnbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030303331313831/avatar/1by1_128.jpg) => fetched in 184ms status=304 size=0 overalltime=185ms 01/05 21:31:02 [Local 01/05 22:31:02] Trace: GetImageData[Remote](id=22242 spec=1by1_128 key=mxgbaaaa uri=https://imagecache.roonlabs.net/im/1/artists/7a004d4e30303030313634303530/avatar/1by1_128.jpg) => fetched in 191ms status=304 size=0 overalltime=194ms 01/05 21:31:06 [Local 01/05 22:31:06] Debug: [easyhttp] [90] POST to https://api.roonlabs.net/device-map/1/register returned after 187 ms, status code: 200, request body size: 8 KB 01/05 21:31:06 [Local 01/05 22:31:06] Trace: [devicemap] device map updated 01/05 21:31:06 [Local 01/05 22:31:06] Info: [stats] 6146mb Virtual, 1240mb Physical, 408mb Managed, 832mb estimated Unmanaged, 387 Handles, 74 Threads, 4.54% of runtime in GC pauses, 9ms last GC pause duration 01/05 21:31:11 [Local 01/05 22:31:11] Info: [library] saved recent ProfileId=f8b3989a-d5a1-40d7-a3a9-3f33a5f206bb Time=01/05/2026 21:31:11 DataType=album Type=long_nav MetadataId=8282686 ContentId=3467567 LibraryId=3467567 Text= Genre= 01/05 21:31:18 [Local 01/05 22:31:18] Info: [library stats] tracks: 17303 (hidden: 365), albums: 781 (hidden: 21), artists: 931, works: 3537, performances: 5249 01/05 21:31:21 [Local 01/05 22:31:21] Info: [stats] 6146mb Virtual, 1240mb Physical, 404mb Managed, 836mb estimated Unmanaged, 386 Handles, 73 Threads, 4.13% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:31:23 [Local 01/05 22:31:23] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:31:23 [Local 01/05 22:31:23] Trace: [storage] [directory] timer delay: 500, retrycount: 1 01/05 21:31:24 [Local 01/05 22:31:24] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:31:24 [Local 01/05 22:31:24] Trace: [storage] [directory] timer delay: 60000, retrycount: 2 01/05 21:31:26 [Local 01/05 22:31:26] Trace: [music/query] performing tag query 01/05 21:31:26 [Local 01/05 22:31:26] Trace: [music/query] query returned 2 Sooloos.Broker.Api.Tag(s) 01/05 21:31:26 [Local 01/05 22:31:26] Trace: [music/query] performing tag query 01/05 21:31:26 [Local 01/05 22:31:26] Trace: [music/query] query returned 2 Sooloos.Broker.Api.Tag(s) 01/05 21:31:26 [Local 01/05 22:31:26] Trace: [music/query] performing tag query 01/05 21:31:26 [Local 01/05 22:31:26] Trace: [music/query] query returned 2 Sooloos.Broker.Api.Tag(s) 01/05 21:31:36 [Local 01/05 22:31:36] Trace: [dbperf] flush 0 bytes, 0 ops in 44 ms (cumulative 2497106 bytes, 891 ops in 6398 ms) 01/05 21:31:36 [Local 01/05 22:31:36] Info: [stats] 6082mb Virtual, 1243mb Physical, 405mb Managed, 838mb estimated Unmanaged, 386 Handles, 65 Threads, 3.85% of runtime in GC pauses, 1ms last GC pause duration 01/05 21:31:38 [Local 01/05 22:31:38] Trace: [music/librarymaintenance] preparing to delete information about 1 files 01/05 21:31:38 [Local 01/05 22:31:38] Trace: [music/librarymaintenance] done! 01/05 21:31:38 [Local 01/05 22:31:38] Trace: [library] starting cleanup with , 0 tracks to retain, 0 auxfiles to retain 01/05 21:31:38 [Local 01/05 22:31:38] Trace: [library] finished with 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 0 changed objects 01/05 21:31:38 [Local 01/05 22:31:38] Trace: [dbperf] flush 448 bytes, 4 ops in 45 ms (cumulative 2497554 bytes, 895 ops in 6443 ms) 01/05 21:31:51 [Local 01/05 22:31:51] Info: [stats] 6082mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 65 Threads, 3.62% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:32:06 [Local 01/05 22:32:06] Info: [stats] 6138mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 75 Threads, 3.39% of runtime in GC pauses, 6ms last GC pause duration 01/05 21:32:21 [Local 01/05 22:32:21] Info: [stats] 6138mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 73 Threads, 3.26% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:32:24 [Local 01/05 22:32:24] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:32:24 [Local 01/05 22:32:24] Trace: [storage] [directory] timer delay: 120000, retrycount: 3 01/05 21:32:36 [Local 01/05 22:32:36] Info: [stats] 6082mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 66 Threads, 3.08% of runtime in GC pauses, 1ms last GC pause duration 01/05 21:32:51 [Local 01/05 22:32:51] Info: [stats] 6082mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 64 Threads, 2.88% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:33:06 [Local 01/05 22:33:06] Trace: [broker/accounts] [heartbeat] now=01/05/2026 21:33:06 nextauthrefresh=01/05/2026 22:28:14 nextmachineallocate=01/06/2026 01:28:06 01/05 21:33:06 [Local 01/05 22:33:06] Info: [stats] 6130mb Virtual, 1242mb Physical, 382mb Managed, 860mb estimated Unmanaged, 386 Handles, 74 Threads, 2.78% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:33:19 [Local 01/05 22:33:19] Debug: [broker/locations/directorystoragelocation] ev_subdirectory, path: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Test 01/05 21:33:21 [Local 01/05 22:33:21] Info: [stats] 6130mb Virtual, 1242mb Physical, 383mb Managed, 859mb estimated Unmanaged, 386 Handles, 74 Threads, 2.69% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:33:36 [Local 01/05 22:33:36] Info: [stats] 6122mb Virtual, 1242mb Physical, 382mb Managed, 860mb estimated Unmanaged, 386 Handles, 69 Threads, 2.53% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:33:51 [Local 01/05 22:33:51] Info: [stats] 6090mb Virtual, 1242mb Physical, 381mb Managed, 861mb estimated Unmanaged, 386 Handles, 65 Threads, 2.41% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:34:06 [Local 01/05 22:34:06] Info: [stats] 6106mb Virtual, 1242mb Physical, 383mb Managed, 859mb estimated Unmanaged, 386 Handles, 71 Threads, 2.34% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:34:18 [Local 01/05 22:34:18] Info: [library stats] tracks: 17303 (hidden: 365), albums: 781 (hidden: 21), artists: 931, works: 3537, performances: 5249 01/05 21:34:21 [Local 01/05 22:34:21] Info: [stats] 6106mb Virtual, 1242mb Physical, 382mb Managed, 860mb estimated Unmanaged, 386 Handles, 71 Threads, 2.27% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:34:24 [Local 01/05 22:34:24] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:34:24 [Local 01/05 22:34:24] Trace: [storage] [directory] timer delay: 240000, retrycount: 4 01/05 21:34:37 [Local 01/05 22:34:37] Info: [stats] 6082mb Virtual, 1242mb Physical, 381mb Managed, 861mb estimated Unmanaged, 386 Handles, 64 Threads, 2.16% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:34:52 [Local 01/05 22:34:52] Info: [stats] 6074mb Virtual, 1242mb Physical, 383mb Managed, 859mb estimated Unmanaged, 386 Handles, 63 Threads, 2.1% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:35:07 [Local 01/05 22:35:07] Info: [stats] 6138mb Virtual, 1242mb Physical, 383mb Managed, 859mb estimated Unmanaged, 386 Handles, 75 Threads, 2.02% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:35:22 [Local 01/05 22:35:22] Info: [stats] 6146mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 75 Threads, 1.98% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:35:37 [Local 01/05 22:35:37] Info: [stats] 6074mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 67 Threads, 1.89% of runtime in GC pauses, 3ms last GC pause duration 01/05 21:35:52 [Local 01/05 22:35:52] Info: [stats] 6074mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 67 Threads, 1.83% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:36:07 [Local 01/05 22:36:07] Info: [stats] 6122mb Virtual, 1243mb Physical, 383mb Managed, 860mb estimated Unmanaged, 389 Handles, 73 Threads, 1.78% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:36:22 [Local 01/05 22:36:22] Info: [stats] 6130mb Virtual, 1243mb Physical, 383mb Managed, 860mb estimated Unmanaged, 386 Handles, 73 Threads, 1.76% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:36:37 [Local 01/05 22:36:37] Info: [stats] 6082mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 68 Threads, 1.7% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:36:52 [Local 01/05 22:36:52] Info: [stats] 6082mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 65 Threads, 1.65% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:37:07 [Local 01/05 22:37:07] Info: [stats] 6114mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 388 Handles, 72 Threads, 1.61% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:37:18 [Local 01/05 22:37:18] Info: [library stats] tracks: 17303 (hidden: 365), albums: 781 (hidden: 21), artists: 931, works: 3537, performances: 5249 01/05 21:37:22 [Local 01/05 22:37:22] Info: [stats] 6122mb Virtual, 1243mb Physical, 379mb Managed, 864mb estimated Unmanaged, 386 Handles, 72 Threads, 1.57% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:37:37 [Local 01/05 22:37:37] Info: [stats] 6066mb Virtual, 1243mb Physical, 383mb Managed, 860mb estimated Unmanaged, 386 Handles, 66 Threads, 1.54% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:37:52 [Local 01/05 22:37:52] Info: [stats] 6066mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 66 Threads, 1.52% of runtime in GC pauses, 3ms last GC pause duration 01/05 21:38:06 [Local 01/05 22:38:06] Trace: [broker/accounts] [heartbeat] now=01/05/2026 21:38:06 nextauthrefresh=01/05/2026 22:28:14 nextmachineallocate=01/06/2026 01:28:06 01/05 21:38:07 [Local 01/05 22:38:07] Info: [stats] 6122mb Virtual, 1243mb Physical, 380mb Managed, 863mb estimated Unmanaged, 388 Handles, 73 Threads, 1.46% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:38:19 [Local 01/05 22:38:19] Debug: [broker/locations/directorystoragelocation] ev_subdirectory, path: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Test 01/05 21:38:22 [Local 01/05 22:38:22] Info: [stats] 6122mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 73 Threads, 1.45% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:38:24 [Local 01/05 22:38:24] Trace: [storage] [directory] Cannot iterate dir: /roon/sys/storage/mounts/Nucleus_SSD_SABRENT_ABCDEFA74602_6882-9AE7-p2/Music/1. Classical/Savall Le Royaume Oublié - La Tragédie Cathare - Savall (2009) [Apple Lossless] 01/05 21:38:24 [Local 01/05 22:38:24] Trace: [storage] [directory] timer delay: 480000, retrycount: 5 01/05 21:38:37 [Local 01/05 22:38:37] Info: [stats] 6098mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 68 Threads, 1.41% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:38:41 [Local 01/05 22:38:41] Debug: [easyhttp] [91] POST to https://api.roonlabs.net/device-map/1/register returned after 741 ms, status code: 200, request body size: 8 KB 01/05 21:38:41 [Local 01/05 22:38:41] Trace: [devicemap] device map updated 01/05 21:38:52 [Local 01/05 22:38:52] Info: [stats] 6098mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 68 Threads, 1.39% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:39:07 [Local 01/05 22:39:07] Info: [stats] 6106mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 71 Threads, 1.35% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:39:22 [Local 01/05 22:39:22] Info: [stats] 6114mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 71 Threads, 1.33% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:39:37 [Local 01/05 22:39:37] Info: [stats] 6058mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 63 Threads, 1.3% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:39:52 [Local 01/05 22:39:52] Info: [stats] 6058mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 61 Threads, 1.28% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:40:07 [Local 01/05 22:40:07] Info: [stats] 6114mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 387 Handles, 72 Threads, 1.25% of runtime in GC pauses, 6ms last GC pause duration 01/05 21:40:18 [Local 01/05 22:40:18] Info: [library stats] tracks: 17303 (hidden: 365), albums: 781 (hidden: 21), artists: 931, works: 3537, performances: 5249 01/05 21:40:22 [Local 01/05 22:40:22] Info: [stats] 6114mb Virtual, 1243mb Physical, 382mb Managed, 861mb estimated Unmanaged, 386 Handles, 72 Threads, 1.24% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:40:37 [Local 01/05 22:40:37] Info: [stats] 6082mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 65 Threads, 1.21% of runtime in GC pauses, 7ms last GC pause duration 01/05 21:40:52 [Local 01/05 22:40:52] Info: [stats] 6050mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 60 Threads, 1.2% of runtime in GC pauses, 4ms last GC pause duration 01/05 21:41:07 [Local 01/05 22:41:07] Info: [stats] 6106mb Virtual, 1243mb Physical, 381mb Managed, 862mb estimated Unmanaged, 386 Handles, 71 Threads, 1.16% of runtime in GC pauses, 5ms last GC pause duration 01/05 21:41:22 [Local 01/05 22:41:22] Info: [stats] 6114mb Virtual, 1243mb Physical, 379mb Managed, 864mb estimated Unmanaged, 386 Handles, 72 Threads, 1.14% of runtime in GC pauses, 4ms last GC pause duration