Aug 31 12:32:03 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 31 12:32:03 musica-casa volumio[1403]: info: In handleBrowseUri, curUri=spotify Aug 31 12:32:03 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:03 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:03 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:03 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:04 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 31 12:32:04 musica-casa volumio[1403]: info: In handleBrowseUri, curUri=spotify/playlists Aug 31 12:32:04 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:05 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::ClearQueue Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::stop Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::stPlaybackTimer Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::updateTrackBlock Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::getTrackBlock Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::serviceStop Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::serviceStop Aug 31 12:32:05 musica-casa volumio[1403]: info: [ytmusic] (AutoplayManager) Removed mpdStateListener Aug 31 12:32:05 musica-casa volumio[1403]: info: [ytmusic] (AutoplayManager) Removed volumioStateListener Aug 31 12:32:05 musica-casa volumio[1403]: info: [ytmusic] (AutoplayManager) Disabled Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 12:32:05 musica-casa volumio[1403]: info: ControllerMpd::stop Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::clearPlayQueue Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::saveQueue Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushQueue Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::addQueueItems Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::addQueueItems Aug 31 12:32:05 musica-casa volumio[1403]: info: Preload queue cleared Aug 31 12:32:05 musica-casa volumio[1403]: info: Adding Item to queue: spotify:user:spotify:playlist:1ni5sdmrCsdss1d9oNPB4i Aug 31 12:32:05 musica-casa volumio[1403]: info: Exploding uri spotify:user:spotify:playlist:1ni5sdmrCsdss1d9oNPB4i in service spop Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=stop timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Aug 31 12:32:05 musica-casa volumio[1403]: ---------------------------- MPD announces state update: player Aug 31 12:32:05 musica-casa volumio[1403]: info: sendMpdCommand stop took 7 milliseconds Aug 31 12:32:05 musica-casa volumio[1403]: info: ControllerMpd::getState Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::sendMpdCommand status Aug 31 12:32:05 musica-casa volumio[1403]: info: Aug 31 12:32:05 musica-casa volumio[1403]: ---------------------------- MPD announces state update: player Aug 31 12:32:05 musica-casa volumio[1403]: info: ControllerMpd::getState Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::sendMpdCommand status Aug 31 12:32:05 musica-casa volumio[1403]: info: sendMpdCommand status took 1 milliseconds Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::parseState Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 12:32:05 musica-casa volumio[1403]: info: sendMpdCommand status took 1 milliseconds Aug 31 12:32:05 musica-casa volumio[1403]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::parseState Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::parseTrackInfo Aug 31 12:32:05 musica-casa volumio[1403]: info: ControllerMpd::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::servicePushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:05 musica-casa volumio[1403]: 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":"We Don't Talk Anymore (feat. Selena Gomez)","artist":"Charlie Puth","album":null,"uri":"https://rr16---sn-42u-i5olr.googlevideo.com/videoplayback?expire=1788175824&ei=cBGVarnIDciNpt8PzODP2QE&ip=42.114.43.41&id=o-ALF5ta13fbw0SnVt41wYvyt7PyLxES6cggtvizMMDCD3&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=1202&met=1788154224%2C&mh=Gc&mm=18%2C26&mn=sn-42u-i5olr%2Csn-oguelnl7&ms=aub%2Conr&mv=m&mvi=16&pl=23&rms=aub%2Caub&initcwndbps=3186250&bui=AR3QkAliU5dTEnyxx2iyrjm_FhMkBqLpj10Beq62r1jqrvuj7Iq7OUmIx0dD1ffxAwYcmp8RuIWw5EUw&spc=KBGBcnNMYW0p2IRmpJ2aolgUeg3efZePGwxz99nwqIKlw-ZPR_ACLSxxVTZ9gVHQBXA&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=sV0NXw3grPX1ig-DvFor4IoY&rqh=1&gir=yes&clen=3768018&dur=230.461&lmt=1787585408342559&mt=1788153901&fvip=1&keepalive=yes&fexp=51565115%2C52135441&c=WEB_REMIX&sefc=1&txp=5532234&n=sdHz3Ofe9jBXag&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=cps%2Cmet%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhALfEDWexFmrLQf6DIftxdm1qj8X2Tz2GkFnM9i0AUzmLAiBDFfd4PFPuHWHOc_QAtlkOO99wvZ_j2ijno234Vbgzeg%3D%3D&sig=AE0s2JYwRgIhANotDQ141xUc4OhDtmpslgQ9IJoDDv5MnP-Qf_8whwKWAiEAjgM4nJj_F_8UmakH6_iSGNGXHxg0-SY77ytrJhsNKWw%3D&cver=1.20250219.01.00&pot=MltI8NI9OFe05Ui0GGRSScXTSQfNowLTGbk5d2Vf6kTXoe0g6K8WhzobE8gekcEyDTiCpVuyRRHz5Sa68qW4SQN1lrnkqLDQd773b1Mnuok6qAJ6_2HLOQSeSEqZ&t.YouTube","trackType":"YouTube"} Aug 31 12:32:05 musica-casa volumio[1403]: verbose: CURRENT POSITION 0 Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::syncState stateService stop Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::syncState currentStatus stop Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: No code Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: ------------------------------ 10ms Aug 31 12:32:05 musica-casa volumio[1403]: info: sendMpdCommand playlistinfo took 10 milliseconds Aug 31 12:32:05 musica-casa volumio[1403]: verbose: ControllerMpd::parseTrackInfo Aug 31 12:32:05 musica-casa volumio[1403]: info: ControllerMpd::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::servicePushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:05 musica-casa volumio[1403]: 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":"We Don't Talk Anymore (feat. Selena Gomez)","artist":"Charlie Puth","album":null,"uri":"https://rr16---sn-42u-i5olr.googlevideo.com/videoplayback?expire=1788175824&ei=cBGVarnIDciNpt8PzODP2QE&ip=42.114.43.41&id=o-ALF5ta13fbw0SnVt41wYvyt7PyLxES6cggtvizMMDCD3&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=1202&met=1788154224%2C&mh=Gc&mm=18%2C26&mn=sn-42u-i5olr%2Csn-oguelnl7&ms=aub%2Conr&mv=m&mvi=16&pl=23&rms=aub%2Caub&initcwndbps=3186250&bui=AR3QkAliU5dTEnyxx2iyrjm_FhMkBqLpj10Beq62r1jqrvuj7Iq7OUmIx0dD1ffxAwYcmp8RuIWw5EUw&spc=KBGBcnNMYW0p2IRmpJ2aolgUeg3efZePGwxz99nwqIKlw-ZPR_ACLSxxVTZ9gVHQBXA&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=sV0NXw3grPX1ig-DvFor4IoY&rqh=1&gir=yes&clen=3768018&dur=230.461&lmt=1787585408342559&mt=1788153901&fvip=1&keepalive=yes&fexp=51565115%2C52135441&c=WEB_REMIX&sefc=1&txp=5532234&n=sdHz3Ofe9jBXag&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=cps%2Cmet%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIhALfEDWexFmrLQf6DIftxdm1qj8X2Tz2GkFnM9i0AUzmLAiBDFfd4PFPuHWHOc_QAtlkOO99wvZ_j2ijno234Vbgzeg%3D%3D&sig=AE0s2JYwRgIhANotDQ141xUc4OhDtmpslgQ9IJoDDv5MnP-Qf_8whwKWAiEAjgM4nJj_F_8UmakH6_iSGNGXHxg0-SY77ytrJhsNKWw%3D&cver=1.20250219.01.00&pot=MltI8NI9OFe05Ui0GGRSScXTSQfNowLTGbk5d2Vf6kTXoe0g6K8WhzobE8gekcEyDTiCpVuyRRHz5Sa68qW4SQN1lrnkqLDQd773b1Mnuok6qAJ6_2HLOQSeSEqZ&t.YouTube","trackType":"YouTube"} Aug 31 12:32:05 musica-casa volumio[1403]: verbose: CURRENT POSITION 0 Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::syncState stateService stop Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::syncState currentStatus stop Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: No code Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:05 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:05 musica-casa volumio[1403]: info: ------------------------------ 18ms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:32:05 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushQueue Aug 31 12:32:06 musica-casa volumio[1403]: info: CorePlayQueue::saveQueue Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::updateTrackBlock Aug 31 12:32:06 musica-casa volumio[1403]: info: CorePlayQueue::getTrackBlock Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPlay Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::play index 0 Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::stop Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::play index undefined Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 12:32:06 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:06 musica-casa volumio[1403]: info: CoreStateMachine::startPlaybackTimer Aug 31 12:32:06 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:06 musica-casa volumio[1403]: info: [1788154326105] ControllerSpotify::clearAddPlayTrack Aug 31 12:32:06 musica-casa volumio[1403]: info: Sending Spotify command with payload to local API: /player/play Aug 31 12:32:14 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetState Aug 31 12:32:14 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:51 musica-casa volumio[1403]: verbose: New Socket.io Connection to 192.168.10.248 from 192.168.10.67 UA: Mozilla/5.0 (Linux; Android 16; CPH2791 Build/BP2A.250605.015; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetState Aug 31 12:32:51 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 31 12:32:51 musica-casa volumio[1403]: info: Received Get System Info Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 12:32:51 musica-casa volumio[1403]: info: Discovery: Getting this device information Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetState Aug 31 12:32:51 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetState Aug 31 12:32:51 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:51 musica-casa volumio[1403]: info: Listing playlists Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetQueue Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreStateMachine::getQueue Aug 31 12:32:51 musica-casa volumio[1403]: info: CorePlayQueue::getQueue Aug 31 12:32:51 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 12:32:56 musica-casa go-librespot[2180]: time="2026-08-31T12:32:56+07:00" level=debug msg="obtained new client token: AAFP0TZkN/Kft2E4gwRHtg6BMlesmxpAIXj2abr9f6LW+WCcXxyyxSDgRapk83pveFT3kbTsbMX8pD9Mw+z/rk2YigLUSZ3Nqh98y3nMgRIDNQk0mDjuBqA3NpGdxjdTdhyndeN5ALOfe+3MNI0LayGvja+btSSSY3mGgXo+7M4vN7+knN6qPlgaLgL9kwKt6IPSRPsdTHENOfXZTR3ecSuK38QLWgqvleLC9PBy/R3feC9m0h+07/M=" Aug 31 12:32:56 musica-casa go-librespot[2180]: time="2026-08-31T12:32:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Aug 31 12:32:56 musica-casa go-librespot[2180]: time="2026-08-31T12:32:56+07:00" level=debug msg="completed keyexchange" Aug 31 12:32:56 musica-casa go-librespot[2180]: time="2026-08-31T12:32:56+07:00" level=debug msg="completed challenge" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=info msg="authenticated AP" username="56*********************op" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=info msg="authenticated Login5" username="56*********************op" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=info msg="accepted zeroconf from OPPO Find X9 Pro" username="56*********************op" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="dealer connection opened" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=trace msg="starting accesspoint recv loop" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=trace msg="starting dealer recv loop" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=trace msg="received accesspoint ping" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="received connection id: ZTM1MmYzMDMtNDU0...RDNDNDQ1OEJGNw==" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=trace msg="received accesspoint pong ack" Aug 31 12:32:57 musica-casa go-librespot[2180]: time="2026-08-31T12:32:57+07:00" level=debug msg="put connect state because NEW_DEVICE" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="handling transfer player command from 5e06495da75d8c46c3146d82daa4a520237ee50d" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="resolved context of track" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="shuffled context with seed 17886798677881969654 (len: 1, keep: -1)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="loading track (paused: true, position: 66495ms)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=trace msg="emitting websocket event: will_play" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 439" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="selected format OGG_VORBIS_320 (80b3162742da8af12d24a6056ae0d2dcdae7835e)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="requested aes key for file 80b3162742da8af12d24a6056ae0d2dcdae7835e, gid: 5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1498" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 439" Aug 31 12:32:58 musica-casa go-librespot[2180]: time="2026-08-31T12:32:58+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1253" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched first chunk of 19, total size is 9812503 bytes" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="vorbis: corrupt or missing data in bitstream" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=trace msg="seek to 66495ms (diff: 76ms, samples: 2932429, bytes: 1899884)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="created new output device" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=info msg="loaded track \"Hoa Nở Không Màu\" (paused: true, position: 66495ms, duration: 328106ms, prefetched: false)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=trace msg="emitting websocket event: metadata" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=trace msg="emitting websocket event: active" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="sending successful reply for dealer request" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 31 12:32:59 musica-casa volumio[1403]: info: Aligning Spotify Volume to Volumio Volume Aug 31 12:32:59 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetState Aug 31 12:32:59 musica-casa volumio[1403]: info: CorePlayQueue::getTrack 0 Aug 31 12:32:59 musica-casa volumio[1403]: info: Setting Spotify Volume from Volumio: 100 Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:32:59 musica-casa go-librespot[2180]: time="2026-08-31T12:32:59+07:00" level=trace msg="emitting websocket event: paused" Aug 31 12:32:59 musica-casa volumio[1403]: info: Spotify is playing in volatile mode Aug 31 12:32:59 musica-casa volumio[1403]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 12:32:59 musica-casa volumio[1403]: info: Setting Spotify stop after unset volatile call Aug 31 12:32:59 musica-casa volumio[1403]: info: CoreCommandRouter::servicePushState Aug 31 12:32:59 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:32:59 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:32:59 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:32:59 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=pause timeout=90 noifplay=true screensavertype=dpms Aug 31 12:32:59 musica-casa volumio[1403]: info: Spotify Stop Aug 31 12:33:00 musica-casa volumio[1403]: info: Sending Spotify command with payload to local API: /player/volume Aug 31 12:33:00 musica-casa go-librespot[2180]: time="2026-08-31T12:33:00+07:00" level=debug msg="update volume requested to 65535/65535" Aug 31 12:33:01 musica-casa go-librespot[2180]: time="2026-08-31T12:33:01+07:00" level=debug msg="put connect state because VOLUME_CHANGED" Aug 31 12:33:01 musica-casa go-librespot[2180]: time="2026-08-31T12:33:01+07:00" level=trace msg="emitting websocket event: volume" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=debug msg="handling resume player command from 5e06495da75d8c46c3146d82daa4a520237ee50d" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=trace msg="seek to 66495ms (diff: 76ms, samples: 2932429, bytes: 1899884)" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=debug msg="resume track at 66419ms" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=trace msg="scheduling prefetch in 232s" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=debug msg="sending successful reply for dealer request" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:33:08 musica-casa go-librespot[2180]: time="2026-08-31T12:33:08+07:00" level=trace msg="emitting websocket event: playing" Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreCommandRouter::servicePushState Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:33:08 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:33:08 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:33:08 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:33:08 musica-casa systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreCommandRouter::servicePushState Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreStateMachine::pushState Aug 31 12:33:08 musica-casa volumio[1403]: info: CoreCommandRouter::volumioPushState Aug 31 12:33:08 musica-casa volumio[1403]: info: Display-configuration --- Volumio status=play timeout=90 noifplay=true screensavertype=dpms Aug 31 12:33:08 musica-casa volumio[1403]: info: Display-configuration --- → Wakeup triggered Aug 31 12:33:08 musica-casa volumio[1403]: info: Display-configuration --- wakeupScreen: DPMS - screen on Aug 31 12:33:11 musica-casa systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 12:33:11 musica-casa systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 12:33:14 musica-casa go-librespot[2180]: time="2026-08-31T12:33:14+07:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:33:22 musica-casa go-librespot[2180]: time="2026-08-31T12:33:22+07:00" level=debug msg="update volume requested to 65535/65535" Aug 31 12:33:22 musica-casa go-librespot[2180]: time="2026-08-31T12:33:22+07:00" level=debug msg="put connect state because VOLUME_CHANGED" Aug 31 12:33:22 musica-casa go-librespot[2180]: time="2026-08-31T12:33:22+07:00" level=trace msg="emitting websocket event: volume" Aug 31 12:33:27 musica-casa go-librespot[2180]: time="2026-08-31T12:33:27+07:00" level=trace msg="sent dealer ping" Aug 31 12:33:27 musica-casa go-librespot[2180]: time="2026-08-31T12:33:27+07:00" level=trace msg="received dealer pong" Aug 31 12:33:32 musica-casa go-librespot[2180]: time="2026-08-31T12:33:32+07:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:5rVRjE3K44dbMAVtjvLdQh" Aug 31 12:33:35 musica-casa volumio[1403]: info: Display-configuration --- → Sleep (DPMS) triggered after 90s Aug 31 12:33:35 musica-casa volumio[1403]: info: Display-configuration --- sleepScreen: DPMS - screen off in 90s Aug 31 12:33:40 musica-casa volumio[1403]: info: CoreCommandRouter::volumioGetState Aug 31 12:33:41 musica-casa volumio[1403]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 31 12:33:41 musica-casa volumio[1403]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:17gp7BcMLN0IZ0k3g9Yx47 Aug 31 12:33:42 musica-casa volumio[1403]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 12:33:42 musica-casa volumio[1403]: TypeError: Cannot read properties of null (reading '0') Aug 31 12:33:42 musica-casa volumio[1403]: at /data/plugins/music_service/spop/index.js:2468:56 Aug 31 12:33:42 musica-casa volumio[1403]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 31 12:33:42 musica-casa volumio[1403]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 12:33:42 musica-casa sudo[5124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 12:32' Aug 31 12:33:42 musica-casa sudo[5124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"