Jan 25 16:08:00 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:08 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:09 volumio-100 go-librespot[1560]: time="2026-01-25T16:08:09+01:00" level=trace msg="sent dealer ping" Jan 25 16:08:09 volumio-100 go-librespot[1560]: time="2026-01-25T16:08:09+01:00" level=trace msg="received dealer pong" Jan 25 16:08:14 volumio-100 volumio[1140]: info: MRS: Found cast device: Google-Nest-Mini-c8b0c286b0709e8e6c66278d061f87e6 Jan 25 16:08:17 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:7I66kvXHHKIBmEnkdLOF6K Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:2M9ro2krNb7nr7HSprkEgo Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:1he20mKw1eq2OVp1BKBlpt Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:2cGxRwrMyEAp8dEbuZaVv6 Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:2GaAWaIazp02G4PZJV0gxX Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:7uv632EkfwYhXoqf8rhYrg Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:4QIo4oxwzzafcBWkKjDpXY Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:67Hna13dNDkZvBpTXRIaOJ Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:2MYPFXScWdR3PQihBQxu7x Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:5uPEIOuFLD7Awf8dB2XZGM Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:6HVfPPQzNb4kqr7o9S0mIx Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:6sQq4zoBTBvdbcmiIcS9Yl Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:29I1vHRrSE9okn7sr0MtYR Jan 25 16:08:22 volumio-100 volumio[1140]: info: Preloading song: spotify:track:4r950qGPziJw0PLre2TXP2 Jan 25 16:08:22 volumio-100 volumio[1140]: info: Exploding uri spotify:track:7I66kvXHHKIBmEnkdLOF6K in service spop Jan 25 16:08:22 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:7I66kvXHHKIBmEnkdLOF6K Jan 25 16:08:22 volumio-100 volumio[1140]: info: Exploding uri mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac in service mpd Jan 25 16:08:22 volumio-100 volumio[1140]: error: scanFolder - failure to stat '/mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac' Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2M9ro2krNb7nr7HSprkEgo in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2M9ro2krNb7nr7HSprkEgo Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:1he20mKw1eq2OVp1BKBlpt in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:1he20mKw1eq2OVp1BKBlpt Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2cGxRwrMyEAp8dEbuZaVv6 in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2cGxRwrMyEAp8dEbuZaVv6 Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2GaAWaIazp02G4PZJV0gxX in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2GaAWaIazp02G4PZJV0gxX Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:7uv632EkfwYhXoqf8rhYrg in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:7uv632EkfwYhXoqf8rhYrg Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:4QIo4oxwzzafcBWkKjDpXY in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:4QIo4oxwzzafcBWkKjDpXY Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:67Hna13dNDkZvBpTXRIaOJ in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:67Hna13dNDkZvBpTXRIaOJ Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2MYPFXScWdR3PQihBQxu7x in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2MYPFXScWdR3PQihBQxu7x Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:5uPEIOuFLD7Awf8dB2XZGM in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:5uPEIOuFLD7Awf8dB2XZGM Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:6HVfPPQzNb4kqr7o9S0mIx in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:6HVfPPQzNb4kqr7o9S0mIx Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:6sQq4zoBTBvdbcmiIcS9Yl in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:6sQq4zoBTBvdbcmiIcS9Yl Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:29I1vHRrSE9okn7sr0MtYR in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:29I1vHRrSE9okn7sr0MtYR Jan 25 16:08:23 volumio-100 volumio[1140]: info: Exploding uri spotify:track:4r950qGPziJw0PLre2TXP2 in service spop Jan 25 16:08:23 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:4r950qGPziJw0PLre2TXP2 Jan 25 16:08:25 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:26 volumio-100 volumio[1140]: info: New access token = BQBh58i7zcv0oMwgEpwk2cY4SA79W3XgZIbvUwwx9xhkpD8aAadE2XqusyUdKOqA7QZ0IwUz8nmkGufKBJRUBPZC8xQuSw7c45I4TIPWsz2htu6HoDF31C30iUtkRmcTJ8Y59jXXmQhdIfqNStBbhe-ng3is4gRQ6OccUiZBkK4rcWR-Xq120sxdhDSFfK8vzm7FXUiqjs-jeWZObSfDyeF7UWO1Ked9WuPG-V2PD_HrBjFumRA4HyYwwPQ06e3WVUlbYXvp-eZT9R8tU0mWp_e8ujUIgOJXfhopD_3DIcMozqLkWyPy4cmn Jan 25 16:08:26 volumio-100 volumio[1140]: info: New access token = BQAdPJKL9ga-18k01YQCYQxlQv8f4kAocmF_WELtP4xBGcMUPOBOtVecz96uEaETOHPMmPLXPlzxUq7XSixJkqnTn1KOW9t3MCdfvUs1OQCDo0GLIVbB_lNr9IE8jce_ygu1_sMjf0V1UcxuQgd2gkDDai2d6vdFYLIE-YBMcx4TXLSLVET2lsEBpQkuaO4eDL78GjjHoynqv3B3lK7_NUxZd9HXv_BAFmXK-7fPHWlPj8RuKwJECVjYU6A0RH7O9R8dKdQFze3l8qxe0IDWEMD-jD52nAANm9p3aRO4Ibru62c8tZROunke Jan 25 16:08:28 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::ClearQueue Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::stop Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::stPlaybackTimer Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::updateTrackBlock Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::getTrackBlock Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::pushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 1 Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output update for this device Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioGetState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 1 Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::serviceStop Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 1 Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::serviceStop Jan 25 16:08:28 volumio-100 volumio[1140]: info: [1769353708418] ControllerTidal::stop Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 25 16:08:28 volumio-100 volumio[1140]: info: ControllerMpd::stop Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: ControllerMpd::sendMpdCommand stop Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::clearPlayQueue Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::saveQueue Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushQueue Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::addQueueItems Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::addQueueItems Jan 25 16:08:28 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:08:28 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:7I66kvXHHKIBmEnkdLOF6K Jan 25 16:08:28 volumio-100 volumio[1140]: info: Exploding uri spotify:track:7I66kvXHHKIBmEnkdLOF6K in service spop Jan 25 16:08:28 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:7I66kvXHHKIBmEnkdLOF6K Jan 25 16:08:28 volumio-100 volumio[1140]: info: Adding Item to queue: mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac Jan 25 16:08:28 volumio-100 volumio[1140]: info: Using cached record of: mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac Jan 25 16:08:28 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2M9ro2krNb7nr7HSprkEgo Jan 25 16:08:28 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2M9ro2krNb7nr7HSprkEgo in service spop Jan 25 16:08:28 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2M9ro2krNb7nr7HSprkEgo Jan 25 16:08:28 volumio-100 volumio[1140]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jan 25 16:08:28 volumio-100 volumio[1140]: info: Jan 25 16:08:28 volumio-100 volumio[1140]: ---------------------------- MPD announces state update: player Jan 25 16:08:28 volumio-100 volumio[1140]: info: sendMpdCommand stop took 45 milliseconds Jan 25 16:08:28 volumio-100 volumio[1140]: info: ControllerMpd::getState Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: ControllerMpd::sendMpdCommand status Jan 25 16:08:28 volumio-100 volumio[1140]: info: sendMpdCommand status took 3 milliseconds Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: ControllerMpd::parseState Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 16:08:28 volumio-100 volumio[1140]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: ControllerMpd::parseTrackInfo Jan 25 16:08:28 volumio-100 volumio[1140]: info: ControllerMpd::pushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::servicePushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::pushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output update for this device Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioGetState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 1 Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1769357090~NGRkYjgwZjE5YmVkZjJmYmIzNjEyMDFlZjIyZmNhYjMwNjNiNzMxMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicwMWNkYjMwY2NlZGI5NzEwNjRhN2Y1NmIyMjAzZWQ5MV82MS5tcDQ/0.flac?token=1769357090~NGRkYjgwZjE5YmVkZjJmYmIzNjEyMDFlZjIyZmNhYjMwNjNiNzMxMg==","trackType":"tidal"} Jan 25 16:08:28 volumio-100 volumio[1140]: verbose: CURRENT POSITION 1 Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::syncState stateService stop Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::syncState currentStatus stop Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::pushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output update for this device Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioGetState Jan 25 16:08:28 volumio-100 volumio[1140]: info: No code Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreStateMachine::pushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushState Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output update for this device Jan 25 16:08:28 volumio-100 volumio[1140]: info: MRS: Pushing multiroomSync output Jan 25 16:08:28 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioGetState Jan 25 16:08:28 volumio-100 volumio[1140]: info: ------------------------------ 50ms Jan 25 16:08:28 volumio-100 volumio[1140]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jan 25 16:08:28 volumio-100 volumio[1140]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jan 25 16:08:28 volumio-100 volumio[1140]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Jan 25 16:08:29 volumio-100 volumio[1140]: info: New access token = BQC45XNpgC2AqyYUVEuHb7SVwHYMz8OdFGV8doPli_utHjLpuJOGonoAgGiqHRz3EvslwazADv-d3gxNoPfJjBvMo7asBQVMhylVwddQKIrDuIDfVXVF0TpTaFiPwMclqpw47O2y3ycgASOedGcmr8kLniTbRO_r2mr7CAOQpOx35FaUyY_GNup3ZXsEMROa4wG-NLKtcuFTtEuts5Oq3Ch6TpuhGu4BIPRZAAgtJmyumFVyyxHpEnt-DeEWh3YrfGGQk4oNXUyLdmnVFnUl3hn0v8XRScXCYqqnrqcTMW9lmDk1Hz-iar-w Jan 25 16:08:29 volumio-100 volumio[1140]: info: New access token = BQBLC9cWaAFSOnMmn0scI-QE9YHYRcsdGYWnr9U2rIWv4SKFdvpCUicYTS2fhLHpWu46XDHw4MHNOq3zke71Rcvpl8fpnLsM-NyUb8uLfYA9lBrbQ3jQmFVslJ8wdT-lXVWOcD_NJNbgvn6Cxa0lAMON2vUPcIEr5uXut6bKFAtsjSSh_xVFK2SReSzOE68MQSOFK2qb98ENMI6r-7Zu8SGGUXog_SCeX2InUrGaiX4jk45i6rd0AIl3snWbjOlk6UbE_Rkg-2fGFxgh_a0W1xp1GKA_q7WyLG4HL5vPsgHSURMV-eq-ASKH Jan 25 16:08:32 volumio-100 volumio[1140]: info: New access token = BQDY-YbhOmoOYZjMFPtnoTAJ3_nc7vPU-Wil0bSB0HDElv_6PGv2h2UioDOYLs_9msdP5uuBEV80eEM5KpGfSRODhNNWCY1MFs7OitPFe-zsrOrYTLr3AjX2y3YOP_Tcz3cPwQ9_WzZf9Jy38Gy8EycKIfzl0H0Le5GDoh0gT7y35KdX2Q1jLUGQDDGWKXLazxOJiKz063WXbPW56qvNEF8pYG6HAbVWufbsfRvaRhyXGxl8r8RKZ9xSmx2BYNNtgsAljLJz2gZYvq_iz_xmOgPQyu2pB8ZvWbLaKq0CdnBoCz-Heom3c7_I Jan 25 16:08:32 volumio-100 volumio[1140]: info: New access token = BQCAhgFFKcytQBcoe13VoLiI8fqG26eMRog26eI2oWErXCKmDsMGyJdUtTGj2EsCQAeRwzG79ZmTmRmr-3gm7qFVeuVkRySmq-DHiJz1W_uhXqZuPoom2y1Ufpp6N_LIEJ9tOLBOQMK6io8GWxGZsz_QRqWmO3VklYrre8s8dJsxODmgf0OKA415AKKYe2j140HpjJQtQIWTsEye37NwEdWAByN8nfNNb5A_hEx_ziWdiqzELlBQ_8pSiPlLHrIb2864e1LfShkJNIfERWCj-ZE-fjc1CoLiyEzYQBfeqjtt9jOev4SP3zOd Jan 25 16:08:33 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:35 volumio-100 volumio[1140]: info: New access token = BQBYSFOX1u6_Jz0KYJP-mz6FmrwGSz4rjnEi_1Kpt16NcCEH9gVOSix4SeLJGwvQ-phVca2Jg4XMoId9fr9hwUqCYYyNRzDNgco9s8lxiU3iy3DJiOtMCYZq4QoE-wivlr0rCOlkeTSSrt1nwB8iylaOSBh_g60CFyTry1yJ2ET3hRFe0MaAmn7NZE8k849FAAXH-5E-YRtKzgrfzJto7R3FE8AseRuOIhtQpd6LFEY0U14aZom7ZwoiCLBR0KrxoCI-0Ni4xlmV_S9H0Lgh6UiBvfh51zOQtV0penvVLA-JxiPNIjkvdT5g Jan 25 16:08:35 volumio-100 volumio[1140]: info: New access token = BQAI4LBXU28AYNjYjF9veiZJgb4HJgXdm4Mn9N2DMXz3UpwOZ86ZrsnnpxOhltzVQHPTAWLb5vsJ8rmGw_20Vn9FrkoOeBM8XclBph84DZMXnlprVAL8yagU3NId_ngjvhH8HIQ51edNLfcCyE1eqIFAvjuAFpCQ_GIzXvKQP_FoTsSRzxHFLSR8JQTta23h6MA-RKTUeQcmp9xGmhgLQ2jpfdb8OoW72mxYPRjDy6YMHdwA0nZxmUNBMr80qHb44crwMwe10nJukk2J3OXSrT5s8N42trJCsR6R3NqLaPdo27SwyZIn7Tnt Jan 25 16:08:38 volumio-100 volumio[1140]: info: New access token = BQA6g9sF1vxi3NBIuJObPJVMFRDcFxoIu6F6e1g_2Fu052IUoldeM_kmEs-zF56CKYB9i2BmbImtwlsZcaSKGB3Y3VeMR22FfAEoaqUft0m3bq8NoiW7Kc3GPZCcfokAN_tmIRNOcaZAn4HT6nApvpmNQaS68pX_j7dYx1Xj94lGAh02cxZBv6I3P9kKFG1nrCj_qmoDBiyHPvIHh_QpOO_kOkUCvhoW0KQ5nrL3hvh3GrDy78PTpfaWsLfjBu4THXWIqc9coEkGGbATksu-8p8I7eYyIcKKB8BhRqSn6jPUNbpUnSBPRI9m Jan 25 16:08:38 volumio-100 volumio[1140]: info: New access token = BQC_rAyS7Ld_L2eRPiFowMZZjJqnJjFRVWL8Y3z8UDifd_vt0Kmf6fMqibsizCBnC2Mfq3us5NBSkvt6XlWge5stOUEZSe9zFnVvdyw66rppeLqveNwe397glG8bjeVbOcQWUxWRCNBDddUm2gN9wGeHQtzaPRcOvigBCWaWyCHzNHE5PPpiXhmDYse9sFCWbAf6AH2uCJPz8xiJO9lz-V-Kqcmi7-S509Bt6raKzyRUi_Hz4mgqc9sprGkAAVewYl8ab5B7t_6i6PcGhCokhoXjvfSgrbs_wUPd7D_GYP4GaBQChFYaJ799 Jan 25 16:08:39 volumio-100 go-librespot[1560]: time="2026-01-25T16:08:39+01:00" level=trace msg="sent dealer ping" Jan 25 16:08:39 volumio-100 go-librespot[1560]: time="2026-01-25T16:08:39+01:00" level=trace msg="received dealer pong" Jan 25 16:08:41 volumio-100 volumio[1140]: info: New access token = BQDfCrt3GG2e-UIvQoAXde4KkFX0uVdN_0RtGCdqIkzNrgDJvKdmh5MWrFv84IJ2R9bfUS9rnfZhKsL-N7h2u6SvP_LZNgWDfDTHDdI_n3rdvD9aUt5_WjpKFiUyX-Qrjfa1TQwVtT9SNaV07Qza881uWHLE1GpYxn7fQmbPsKXAEHnXLmGVxUERdLz73IQ30WgVYSXovlTFds8J0oYRxea2iJEHXX3Llw3QPzdnuRFFM6apIvpykNQQPq3YxumUSU295Fm-gcgZuiN4UQECIj0KyX6dbvyZ-_xydOZE6lxWArAB7fNkps2A Jan 25 16:08:41 volumio-100 volumio[1140]: info: New access token = BQAuT07476EfrT5Zx4bQjv3gBarAImTDlnbqET06uvhJaUpfnAzLcrMBZPu0DyrQWJB51gLfQZxfBxwb-VHPfHyPQ7TmugRFM9SnupTrQZxkpEv5c_QVs4DygjkZ-mVSoYfvWU0IJy4_-eHKZkRDCVgzs7CQApskMp43cfnHTM3WwnNzADSOv_szbRB1HeVVYwBqkXGNW21ZRLWHvbuPimgEopesqLbtwnPQhEN_QjbXRVci5GQ9Nc6VAZxOTlo7hrk6k3WJOHRvv5ORTStiTwqdeC2zrdhoOZKf4TkJ1eCURZdnxoEoI6gs Jan 25 16:08:41 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:44 volumio-100 volumio[1140]: info: New access token = BQA5qRxiHdaGzjWLMYVnF5x5M7aOXQO0s3NEYiVTQKwuYUfpdDJ_WAMUUKPi6oeidXErwVmkDtimwWAthDow2jetGVI5WbXWtT2E73QFk4-Ymp_1O78-BI8kKFcj6fcIwclFSIaauBM_YjXklicRndbhtgFLS_0Fw4JUrh0nOFxj7NoqUiUZIrGv0QXsktI3_WiOx2VmfVD9tBevmRS78y185MtzfiNDMvxZlMcuqjLKHJoQ2XQRxrfpHHdO5ULugISYNpDnPwiEjNzV_BpTxIxF9mSVR7TCzVRs4mE-3aejck-wd9swGdDc Jan 25 16:08:44 volumio-100 volumio[1140]: info: New access token = BQDhiAv-pPdDnNhTN9KN6Y6DNNRDmlvjGiCHVb5BHH1NR83m0S8-zRgve_JCgW1156uLcDVMovE5xTi79nog0ROrnixK0G6hk-vJJ2FGFHRyxad59K8LCVeOyDSdufccEtLP1uSlk4lkyANh7sExf3Zjurhp5Q7dA-VBVEjN6QOagHGenkw_kN6XDoK14iKGr8FVcA7NdCqIbvLfypUTE7mjnleTAgkk1uVuL1tOEgXP8fD2yVXApET_b-1vQGfWkl2LztEUIaZDAWULIMkH1qACg5m3KwF9ZNq_K8oepDywTGz75EiNpspS Jan 25 16:08:47 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2M9ro2krNb7nr7HSprkEgo","service":"spop","name":"Fast Car","artist":"Tracy Chapman","album":"Tracy Chapman","type":"song","duration":296,"albumart":"https://i.scdn.co/image/ab67616d0000b27390b8a540137ee2a718a369f9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:47 volumio-100 volumio[1140]: info: New access token = BQAUvbSMlKqqwfY9nnURlAW8IQaV42329yOY7v4BUYJQvCXCWPRHLqDk0QNw_sexlnQaN9ObDEz4D-BZWdkhD9vNxfq08bn8zuRnP2wm91lAShbjvLoZ91EnmZRLm0pKUVK_JlM6Ilg-WS26svzhMIzv5nK8UrwYW_8bD-hIjmwZkBc6VKthnfdyZpxqHRoJxtD0lBaRA-NX7j5sDBtCDQD1U4fJ7AT-6zR9Q_TA4l6tMr4luDLLdNCRT-k8vGz56QKpGZIDJpxtQ4VWga9VnaxHhKmx3LXlx1x4roNBoKQoFbQQRQ3qxjGT Jan 25 16:08:49 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:50 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7I66kvXHHKIBmEnkdLOF6K","service":"spop","name":"Furia Taurina - Live","artist":"Jordan Rudess","album":"An Evening With John Petrucci & Jordan Rudess (Live)","type":"song","duration":610,"albumart":"https://i.scdn.co/image/ab67616d0000b2739bb5e390ef2bd2c4247caa9a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:50 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7I66kvXHHKIBmEnkdLOF6K","service":"spop","name":"Furia Taurina - Live","artist":"Jordan Rudess","album":"An Evening With John Petrucci & Jordan Rudess (Live)","type":"song","duration":610,"albumart":"https://i.scdn.co/image/ab67616d0000b2739bb5e390ef2bd2c4247caa9a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2M9ro2krNb7nr7HSprkEgo","service":"spop","name":"Fast Car","artist":"Tracy Chapman","album":"Tracy Chapman","type":"song","duration":296,"albumart":"https://i.scdn.co/image/ab67616d0000b27390b8a540137ee2a718a369f9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushQueue Jan 25 16:08:53 volumio-100 volumio[1140]: info: CorePlayQueue::saveQueue Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::updateTrackBlock Jan 25 16:08:53 volumio-100 volumio[1140]: info: CorePlayQueue::getTrackBlock Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioGetState Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPlay Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::play index 2 Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::addQueueItems Jan 25 16:08:53 volumio-100 volumio[1140]: info: CorePlayQueue::addQueueItems Jan 25 16:08:53 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:1he20mKw1eq2OVp1BKBlpt Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:1he20mKw1eq2OVp1BKBlpt in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:1he20mKw1eq2OVp1BKBlpt Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2cGxRwrMyEAp8dEbuZaVv6 Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2cGxRwrMyEAp8dEbuZaVv6 in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2cGxRwrMyEAp8dEbuZaVv6 Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2GaAWaIazp02G4PZJV0gxX Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2GaAWaIazp02G4PZJV0gxX in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2GaAWaIazp02G4PZJV0gxX Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:7uv632EkfwYhXoqf8rhYrg Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:7uv632EkfwYhXoqf8rhYrg in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:7uv632EkfwYhXoqf8rhYrg Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:4QIo4oxwzzafcBWkKjDpXY Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:4QIo4oxwzzafcBWkKjDpXY in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:4QIo4oxwzzafcBWkKjDpXY Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:67Hna13dNDkZvBpTXRIaOJ Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:67Hna13dNDkZvBpTXRIaOJ in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:67Hna13dNDkZvBpTXRIaOJ Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2MYPFXScWdR3PQihBQxu7x Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:2MYPFXScWdR3PQihBQxu7x in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:2MYPFXScWdR3PQihBQxu7x Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:5uPEIOuFLD7Awf8dB2XZGM Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:5uPEIOuFLD7Awf8dB2XZGM in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:5uPEIOuFLD7Awf8dB2XZGM Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:6HVfPPQzNb4kqr7o9S0mIx Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:6HVfPPQzNb4kqr7o9S0mIx in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:6HVfPPQzNb4kqr7o9S0mIx Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:6sQq4zoBTBvdbcmiIcS9Yl Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:6sQq4zoBTBvdbcmiIcS9Yl in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:6sQq4zoBTBvdbcmiIcS9Yl Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:29I1vHRrSE9okn7sr0MtYR Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:29I1vHRrSE9okn7sr0MtYR in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:29I1vHRrSE9okn7sr0MtYR Jan 25 16:08:53 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:4r950qGPziJw0PLre2TXP2 Jan 25 16:08:53 volumio-100 volumio[1140]: info: Exploding uri spotify:track:4r950qGPziJw0PLre2TXP2 in service spop Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: EXPLODING URI:spotify:track:4r950qGPziJw0PLre2TXP2 Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::stop Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::play index undefined Jan 25 16:08:53 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:08:53 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 2 Jan 25 16:08:53 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1he20mKw1eq2OVp1BKBlpt","service":"spop","name":"Black Cow","artist":"Steely Dan","album":"Aja","type":"song","duration":310,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf39e4261576717ff4737bb6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:56 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2GaAWaIazp02G4PZJV0gxX","service":"spop","name":"Limit To Your Love","artist":"James Blake","album":"James Blake","type":"song","duration":276,"albumart":"https://i.scdn.co/image/ab67616d0000b27307237d7403e8e70cc35f88ad","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:56 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2cGxRwrMyEAp8dEbuZaVv6","service":"spop","name":"Instant Crush (feat. Julian Casablancas)","artist":"Daft Punk","album":"Random Access Memories","type":"song","duration":337,"albumart":"https://i.scdn.co/image/ab67616d0000b2739b9b36b0e22870b9f542d937","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:57 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:08:59 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4QIo4oxwzzafcBWkKjDpXY","service":"spop","name":"xanny","artist":"Billie Eilish","album":"WHEN WE ALL FALL ASLEEP, WHERE DO WE GO?","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b27350a3147b4edd7701a876c6ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:08:59 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2dLLR6qlu5UJ5gk0dKz0h3","service":"spop","name":"Royals","artist":"Lorde","album":"Pure Heroine","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b273187331e276c898d39764cc98","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:02 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2MYPFXScWdR3PQihBQxu7x","service":"spop","name":"Bubbles","artist":"Yosi Horikawa","album":"Wandering","type":"song","duration":347,"albumart":"https://i.scdn.co/image/ab67616d0000b2737d09a384de0438a4ad206d13","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:02 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7uv632EkfwYhXoqf8rhYrg","service":"spop","name":"Angel","artist":"Massive Attack","album":"Mezzanine","type":"song","duration":379,"albumart":"https://i.scdn.co/image/ab67616d0000b2732fcb0a3c7a66e516b11cd26e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:05 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5uPEIOuFLD7Awf8dB2XZGM","service":"spop","name":"Am I Losing You","artist":"Jan Akkerman","album":"Focus in Time","type":"song","duration":384,"albumart":"https://i.scdn.co/image/ab67616d0000b2730b7157a1a6d488420d6421a5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:05 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:67Hna13dNDkZvBpTXRIaOJ","service":"spop","name":"Teardrop","artist":"Massive Attack","album":"Mezzanine","type":"song","duration":330,"albumart":"https://i.scdn.co/image/ab67616d0000b2732fcb0a3c7a66e516b11cd26e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:05 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:09:08 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:29I1vHRrSE9okn7sr0MtYR","service":"spop","name":"Pretend","artist":"Brandt Brauer Frick","album":"Mr. Machine","type":"song","duration":449,"albumart":"https://i.scdn.co/image/ab67616d0000b27368014e93ea7ca9556d24e59c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:08 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6HVfPPQzNb4kqr7o9S0mIx","service":"spop","name":"Comme un tango","artist":"Vincent Belanger","album":"Conversations (XLO 25th Anniversary Edition)","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b2734590d2d7c950b2dd58231966","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:09 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:09+01:00" level=trace msg="sent dealer ping" Jan 25 16:09:09 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:09+01:00" level=trace msg="received dealer pong" Jan 25 16:09:11 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4r950qGPziJw0PLre2TXP2","service":"spop","name":"Patti Cake","artist":"Thom Rotella Band","album":"Thom Rotella Band","type":"song","duration":269,"albumart":"https://i.scdn.co/image/ab67616d0000b273524994fddc19042d7e7a33c5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:11 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6sQq4zoBTBvdbcmiIcS9Yl","service":"spop","name":"Hanuman","artist":"Rodrigo y Gabriela","album":"11:11","type":"song","duration":223,"albumart":"https://i.scdn.co/image/ab67616d0000b273d9805e261028fa4ac705dee0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:13 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::ClearQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::stop Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::clearPlayQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::saveQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::addQueueItems Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::addQueueItems Jan 25 16:09:13 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:7I66kvXHHKIBmEnkdLOF6K Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:7I66kvXHHKIBmEnkdLOF6K Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: mnt/NAS/NAS/Dire Straits - Brothers In Arms (1985)/01.-So Far Away.flac Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2M9ro2krNb7nr7HSprkEgo Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:2M9ro2krNb7nr7HSprkEgo Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::saveQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::updateTrackBlock Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::getTrackBlock Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioGetState Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 0 Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPlay Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::play index 2 Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::addQueueItems Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::addQueueItems Jan 25 16:09:13 volumio-100 volumio[1140]: info: Preload queue cleared Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:1he20mKw1eq2OVp1BKBlpt Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:1he20mKw1eq2OVp1BKBlpt Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2cGxRwrMyEAp8dEbuZaVv6 Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:2cGxRwrMyEAp8dEbuZaVv6 Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2GaAWaIazp02G4PZJV0gxX Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:2GaAWaIazp02G4PZJV0gxX Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:2dLLR6qlu5UJ5gk0dKz0h3 Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:7uv632EkfwYhXoqf8rhYrg Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:7uv632EkfwYhXoqf8rhYrg Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:4QIo4oxwzzafcBWkKjDpXY Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:4QIo4oxwzzafcBWkKjDpXY Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:67Hna13dNDkZvBpTXRIaOJ Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:67Hna13dNDkZvBpTXRIaOJ Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:2MYPFXScWdR3PQihBQxu7x Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:2MYPFXScWdR3PQihBQxu7x Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:5uPEIOuFLD7Awf8dB2XZGM Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:5uPEIOuFLD7Awf8dB2XZGM Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:6HVfPPQzNb4kqr7o9S0mIx Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:6HVfPPQzNb4kqr7o9S0mIx Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:6sQq4zoBTBvdbcmiIcS9Yl Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:6sQq4zoBTBvdbcmiIcS9Yl Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:29I1vHRrSE9okn7sr0MtYR Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:29I1vHRrSE9okn7sr0MtYR Jan 25 16:09:13 volumio-100 volumio[1140]: info: Adding Item to queue: spotify:track:4r950qGPziJw0PLre2TXP2 Jan 25 16:09:13 volumio-100 volumio[1140]: info: Using cached record of: spotify:track:4r950qGPziJw0PLre2TXP2 Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::stop Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreCommandRouter::volumioPushQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::saveQueue Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::play index undefined Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::updateTrackBlock Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::getTrackBlock Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 2 Jan 25 16:09:13 volumio-100 volumio[1140]: info: CoreStateMachine::startPlaybackTimer Jan 25 16:09:13 volumio-100 volumio[1140]: info: CorePlayQueue::getTrack 2 Jan 25 16:09:13 volumio-100 volumio[1140]: info: [1769353753936] ControllerSpotify::clearAddPlayTrack Jan 25 16:09:13 volumio-100 volumio[1140]: info: Sending Spotify command with payload to local API: /player/play Jan 25 16:09:14 volumio-100 volumio[1140]: info: Discovery: Remote connection error: 192.168.31.41 Jan 25 16:09:14 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:14+01:00" level=debug msg="resolved context of track" uri="spotify:track:1he20mKw1eq2OVp1BKBlpt" Jan 25 16:09:14 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:14+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1he20mKw1eq2OVp1BKBlpt" Jan 25 16:09:14 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:14+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1he20mKw1eq2OVp1BKBlpt" Jan 25 16:09:14 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2cGxRwrMyEAp8dEbuZaVv6","service":"spop","name":"Instant Crush (feat. Julian Casablancas)","artist":"Daft Punk","album":"Random Access Memories","type":"song","duration":337,"albumart":"https://i.scdn.co/image/ab67616d0000b2739b9b36b0e22870b9f542d937","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:14 volumio-100 volumio[1140]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1he20mKw1eq2OVp1BKBlpt","service":"spop","name":"Black Cow","artist":"Steely Dan","album":"Aja","type":"song","duration":310,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf39e4261576717ff4737bb6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=trace msg="emitting websocket event: will_play" Jan 25 16:09:15 volumio-100 volumio[1140]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1he20mKw1eq2OVp1BKBlpt","uri":"spotify:track:1he20mKw1eq2OVp1BKBlpt","play_origin":"go-librespot"}} Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="selected format OGG_VORBIS_320 (9b0eb07213949e2335b4bb8b2decec7cbed25646)" uri="spotify:track:1he20mKw1eq2OVp1BKBlpt" Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="requested aes key for file 9b0eb07213949e2335b4bb8b2decec7cbed25646, gid: 1he20mKw1eq2OVp1BKBlpt" Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1376" Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1he20mKw1eq2OVp1BKBlpt" Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 25 16:09:15 volumio-100 go-librespot[1560]: time="2026-01-25T16:09:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1134" Jan 25 16:09:16 volumio-100 volumio[1140]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 16:09:16 volumio-100 volumio[1140]: ConnectionError: Connection error in fetching pairing code Jan 25 16:09:16 volumio-100 volumio[1140]: at PairingCodeRequestService._PairingCodeRequestService_getCodeAndEmit (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/PairingCodeRequestService.js:126:17) Jan 25 16:09:16 volumio-100 volumio[1140]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) { Jan 25 16:09:16 volumio-100 volumio[1140]: cause: TypeError: fetch failed Jan 25 16:09:16 volumio-100 volumio[1140]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jan 25 16:09:16 volumio-100 volumio[1140]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jan 25 16:09:16 volumio-100 volumio[1140]: at async PairingCodeRequestService._PairingCodeRequestService_getCodeAndEmit (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/PairingCodeRequestService.js:120:20) { Jan 25 16:09:16 volumio-100 volumio[1140]: cause: ConnectTimeoutError: Connect Timeout Error Jan 25 16:09:16 volumio-100 volumio[1140]: at onConnectTimeout (node:internal/deps/undici/undici:8522:28) Jan 25 16:09:16 volumio-100 volumio[1140]: at node:internal/deps/undici/undici:8480:50 Jan 25 16:09:16 volumio-100 volumio[1140]: at Immediate._onImmediate (node:internal/deps/undici/undici:8511:13) Jan 25 16:09:16 volumio-100 volumio[1140]: at process.processImmediate (node:internal/timers:478:21) { Jan 25 16:09:16 volumio-100 volumio[1140]: code: 'UND_ERR_CONNECT_TIMEOUT' Jan 25 16:09:16 volumio-100 volumio[1140]: } Jan 25 16:09:16 volumio-100 volumio[1140]: }, Jan 25 16:09:16 volumio-100 volumio[1140]: info: { Jan 25 16:09:16 volumio-100 volumio[1140]: url: 'https://www.youtube.com/api/lounge/pairing/get_pairing_code?ctx=pair' Jan 25 16:09:16 volumio-100 volumio[1140]: } Jan 25 16:09:16 volumio-100 volumio[1140]: } Jan 25 16:09:16 volumio-100 volumio[1140]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 16:09:17 volumio-100 sudo[2149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 16:08' Jan 25 16:09:17 volumio-100 sudo[2149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"