Oct 11 14:05:04 volumio go-librespot[11974]: time="2026-10-11T14:05:04+02:00" level=trace msg="sent dealer ping" Oct 11 14:05:04 volumio go-librespot[11974]: time="2026-10-11T14:05:04+02:00" level=trace msg="received dealer pong" Oct 11 14:05:05 volumio volumio[1244]: info: [1791720305220] [RadioParadise] getMetadata started with url https://api.radioparadise.com/api/now_playing?chan=1 Oct 11 14:05:05 volumio volumio[1244]: info: [1791720305803] [RadioParadise] received new metadata: {"time":273,"artist":"Arcade Fire","title":"Neighborhood #4 (7 Kettles)","album":"Funeral","year":"2004","cover":"https://img.radioparadise.com/covers/l/11288.jpg","cover_med":"https://img.radioparadise.com/covers/m/11288.jpg","cover_small":"https://img.radioparadise.com/covers/s/11288.jpg"} Oct 11 14:05:05 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:05 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:05 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:05 volumio volumio[1244]: verbose: STATE SERVICE {"status":"play","service":"radio_paradise","type":"webradio","trackType":"flac","radioType":"","albumart":"https://img.radioparadise.com/covers/l/11288.jpg","uri":"https://stream.radioparadise.com/mellow-flacm","name":"Neighborhood #4 (7 Kettles)","title":"Neighborhood #4 (7 Kettles)","artist":"Arcade Fire","album":"Funeral","streaming":true,"disableUiControls":true,"duration":278,"seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 11 14:05:05 volumio volumio[1244]: verbose: CURRENT POSITION 0 Oct 11 14:05:05 volumio volumio[1244]: info: CoreStateMachine::syncState stateService play Oct 11 14:05:05 volumio volumio[1244]: info: CoreStateMachine::syncState currentStatus play Oct 11 14:05:05 volumio volumio[1244]: info: Received an update from plugin. extracting info from payload Oct 11 14:05:05 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:05 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:05 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:05:05 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:05 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:05 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:05 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:05 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:05.811+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_PLAYING positionMs=0 volume=51 Oct 11 14:05:05 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:05.811+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=https://stream.radioparadise.com/mellow-flacm title="Neighborhood #4 (7 Kettles)" Oct 11 14:05:05 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:05.812+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_PLAYING positionMs=0 volume=51 Oct 11 14:05:05 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:05.812+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=https://stream.radioparadise.com/mellow-flacm title="Neighborhood #4 (7 Kettles)" Oct 11 14:05:05 volumio volumio[1244]: info: [1791720305815] [RadioParadise] setting new timer with duration of 278000 seconds. Oct 11 14:05:05 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:05 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:06 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:06 volumio volumio[1244]: info: CorePlayQueue::getTrack 1 Oct 11 14:05:11 volumio volumio[1244]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 14:05:11 volumio volumio[1244]: info: CoreCommandRouter::Close All Modals sent Oct 11 14:05:11 volumio volumio[1244]: info: Received OAUTH Data Oct 11 14:05:11 volumio volumio[1244]: info: Executing Spotify Oauth Login Oct 11 14:05:11 volumio volumio[1244]: info: Saving Spotify Refresh Token Oct 11 14:05:11 volumio sudo[13319]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 11 14:05:11 volumio sudo[13319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:05:11 volumio sudo[13319]: pam_unix(sudo:session): session closed for user root Oct 11 14:05:11 volumio sudo[13321]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 11 14:05:11 volumio sudo[13321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:05:11 volumio sudo[13321]: pam_unix(sudo:session): session closed for user root Oct 11 14:05:11 volumio volumio[1244]: verbose: New Socket.io Connection to 192.168.178.127 from 192.168.178.131 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 11 14:05:12 volumio volumio[1244]: info: New Spotify access tokenBQDGrcKZW-... Oct 11 14:05:12 volumio volumio[1244]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::volumioGetVisibleSources Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:12 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 11 14:05:12 volumio volumio[1244]: info: Received Get System Info Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:05:12 volumio volumio[1244]: info: Discovery: Getting this device information Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:12 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:12 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:12 volumio volumio[1244]: info: Listing playlists Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 11 14:05:12 volumio volumio[1244]: SPOTIFY: User informations: {"account_id":"5xz6ErtDrm","country":"DE","display_name":"Michel von Löneberger","email":"michel.lorenzen@googlemail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/12142543431"},"followers":{"href":null,"total":32},"href":"https://api.spotify.com/v1/users/12142543431","id":"12142543431","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464724316_10211255384655752_7383952624731997116_n.jpg?stp=c897.0.1151.1151a_dst-jpg_s320x320_tt6&_nc_cat=105&ccb=1-7&_nc_sid=08baa4&_nc_ohc=GFTUXPx1t3IQ7kNvwHjE8Qz&_nc_oc=AdrKiFZfTBaYMYm7VqNrapUBIl4-PAXSTUyuvqC3mEAduM7PowIcQ2bkj2SKV6CQbKbFEDv43KeUAd36TzmCtFiW&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=arIP8TgaJzRVUMQrKVuq3Q&_nc_tpa=Q5bMBQKjQUCF_URj4fiZIMqv-HXiZ2c4ukWX4qehs8QGBJOEf0w4HrcTY-2L2QSuZIkt-cC1_kG1&oh=00_AQNvNiXA_9UmnfAwVRM7xXNPGcyFdV3q7xxp2cbZ1nEtSg&oe=6AD1226D","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464724316_10211255384655752_7383952624731997116_n.jpg?stp=c897.0.1151.1151a_cp0_dst-jpg_s50x50_tt6&_nc_cat=105&ccb=1-7&_nc_sid=28885b&_nc_ohc=GFTUXPx1t3IQ7kNvwHjE8Qz&_nc_oc=AdrKiFZfTBaYMYm7VqNrapUBIl4-PAXSTUyuvqC3mEAduM7PowIcQ2bkj2SKV6CQbKbFEDv43KeUAd36TzmCtFiW&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=arIP8TgaJzRVUMQrKVuq3Q&_nc_tpa=Q5bMBQIsOhzs88xCYo8rEzqzvEhJWPJpy-JWM8CQdcvbGs7K3-vUMvyEFhm44Qjy4VORWBlsXbVR&oh=00_AQNAqAIBnty3AucCOSaa_H6l2tqR3B0FDwAIoiDyUOuXcw&oe=6AD1226D","width":64}],"product":"premium","type":"user","uri":"spotify:user:12142543431"} Oct 11 14:05:12 volumio volumio[1244]: info: Creating Spotify config file Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 14:05:12 volumio volumio[1244]: info: Spotify config file written Oct 11 14:05:12 volumio sudo[13328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 11 14:05:12 volumio sudo[13328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:05:12 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Oct 11 14:05:12 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Oct 11 14:05:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:12 volumio volumio[1244]: info: Connection to go-librespot Websocket closed Oct 11 14:05:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:12 volumio sudo[13328]: pam_unix(sudo:session): session closed for user root Oct 11 14:05:12 volumio go-librespot[13330]: go-librespot daemon starting... Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="app state loaded" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:12 volumio volumio[1244]: info: New Spotify access tokenBQBHvOoaIW... Oct 11 14:05:12 volumio volumio[1244]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 11 14:05:12 volumio volumio[1244]: SPOTIFY: User informations: {"account_id":"5xz6ErtDrm","country":"DE","display_name":"Michel von Löneberger","email":"michel.lorenzen@googlemail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/12142543431"},"followers":{"href":null,"total":32},"href":"https://api.spotify.com/v1/users/12142543431","id":"12142543431","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464724316_10211255384655752_7383952624731997116_n.jpg?stp=c897.0.1151.1151a_dst-jpg_s320x320_tt6&_nc_cat=105&ccb=1-7&_nc_sid=08baa4&_nc_ohc=GFTUXPx1t3IQ7kNvwHjE8Qz&_nc_oc=AdrKiFZfTBaYMYm7VqNrapUBIl4-PAXSTUyuvqC3mEAduM7PowIcQ2bkj2SKV6CQbKbFEDv43KeUAd36TzmCtFiW&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=arIP8TgaJzRVUMQrKVuq3Q&_nc_tpa=Q5bMBQKjQUCF_URj4fiZIMqv-HXiZ2c4ukWX4qehs8QGBJOEf0w4HrcTY-2L2QSuZIkt-cC1_kG1&oh=00_AQNvNiXA_9UmnfAwVRM7xXNPGcyFdV3q7xxp2cbZ1nEtSg&oe=6AD1226D","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/464724316_10211255384655752_7383952624731997116_n.jpg?stp=c897.0.1151.1151a_cp0_dst-jpg_s50x50_tt6&_nc_cat=105&ccb=1-7&_nc_sid=28885b&_nc_ohc=GFTUXPx1t3IQ7kNvwHjE8Qz&_nc_oc=AdrKiFZfTBaYMYm7VqNrapUBIl4-PAXSTUyuvqC3mEAduM7PowIcQ2bkj2SKV6CQbKbFEDv43KeUAd36TzmCtFiW&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=arIP8TgaJzRVUMQrKVuq3Q&_nc_tpa=Q5bMBQIsOhzs88xCYo8rEzqzvEhJWPJpy-JWM8CQdcvbGs7K3-vUMvyEFhm44Qjy4VORWBlsXbVR&oh=00_AQNAqAIBnty3AucCOSaa_H6l2tqR3B0FDwAIoiDyUOuXcw&oe=6AD1226D","width":64}],"product":"premium","type":"user","uri":"spotify:user:12142543431"} Oct 11 14:05:12 volumio volumio[1244]: info: Spotify Successfully logged in Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 11 14:05:12 volumio volumio[1244]: info: [1791720312536] CoreMusicLibrary::Adding element Spotify Oct 11 14:05:12 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 14:05:12 volumio volumio[1244]: Cannot find translation for source Radio Paradise Oct 11 14:05:12 volumio volumio[1244]: Cannot find translation for source Spotify Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=info msg="zeroconf server listening on port 36981" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="obtained new client token: AAHqXuCzYsxaUD5uG+qR5vw60oDGOm8jd6+uB1MY6nnJt2GjB3aZ1i720IfDmwJiMTaaxAV/z8rdETw7cZlx58nkbOvTuMunrw5jCbidYlnTPiPbssZ5Xwh4KV9wVFOSKMQ8UlFHEtAHBEK5zDgfdUOm1hFiJEADsJ9zuyborWQLv64JUqKQ3KElz/eo1oBz8TnSNrT/OOFdLkOJBGM7pdv1NIRJoKF3w2NvkMP1xs5trnKDpPLNIA==" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=debug msg="completed challenge" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:12 volumio go-librespot[13331]: time="2026-10-11T14:05:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:13 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 11 14:05:13 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 14:05:13 volumio volumio[1244]: info: Received Get System Info Oct 11 14:05:13 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:05:13 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:05:13 volumio volumio[1244]: info: Discovery: Getting this device information Oct 11 14:05:13 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:13 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:13 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:05:14 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 14:05:14 volumio volumio[1244]: info: Received Get System Info Oct 11 14:05:14 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:05:14 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:05:14 volumio volumio[1244]: info: Discovery: Getting this device information Oct 11 14:05:14 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:14 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:14 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:05:15 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:15 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:15 volumio volumio[1244]: info: go-librespot daemon successfully initialized Oct 11 14:05:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Oct 11 14:05:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:16 volumio go-librespot[13348]: go-librespot daemon starting... Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="app state loaded" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=info msg="zeroconf server listening on port 46297" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="obtained new client token: AAHT5lfBdaMWn5CMKq1AdELEt9QIP34w0ohc3pDxeVN4E19qOZp6BAw+KKlmCETXr2tPH2QL33pnBxWwc0LNALQE/d7oJrR+MGAo3eQZhcJsy5XpUG0Flh9696K1fZOvUMX+KBYjw9OgOAwrKa+8CtmcrUExYNGWtxYDDM5KUDhBKAhIRtUmnWxT+4XIsN6HE1eDfVSanOL1ilcbAIL64jOuHoC6X3+k/MAfsXTm9gEtu9ZY9nhXSg==" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=debug msg="completed challenge" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:16 volumio go-librespot[13349]: time="2026-10-11T14:05:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:18 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:18 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:18 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:18 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Oct 11 14:05:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:19 volumio go-librespot[13379]: go-librespot daemon starting... Oct 11 14:05:19 volumio go-librespot[13380]: time="2026-10-11T14:05:19+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:19 volumio go-librespot[13380]: time="2026-10-11T14:05:19+02:00" level=debug msg="app state loaded" Oct 11 14:05:19 volumio go-librespot[13380]: time="2026-10-11T14:05:19+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:19 volumio go-librespot[13380]: time="2026-10-11T14:05:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=info msg="zeroconf server listening on port 40045" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="obtained new client token: AAHOE/XbZXt2FQnYNFMiuUVOekbKLCXQW+WzXyp0ovdJJtgCTvatdIh2KF5xNkQ3sAH3Ei67tlpalIJQwilWRGGv60ZBXnz3nlhyJTXd6dFHi4C+9Im84Sf/lfIrt+El5zGExCfJVCJmIzvPCVw1p0Zldp2wIOyp56Xbi9DOGqsI5agHBsK9a6troh+LEluBhf+Zh0Pt7KDDugbkWLgPpfM7wc3FL0ZJxLkwXB/WpvBtH9irKU4=" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=debug msg="completed challenge" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:20 volumio go-librespot[13380]: time="2026-10-11T14:05:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:21 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:21 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Oct 11 14:05:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:23 volumio go-librespot[13399]: go-librespot daemon starting... Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="app state loaded" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=info msg="zeroconf server listening on port 35603" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="obtained new client token: AAHC20KPqJhPqAm0GX2DqRvnW1AXDwnSlw6TdCKJz3/I235IqRs3/8bJEiK9XLbgA/MEOb/ywemo1Y9FOyHfeVVAanJPqaAb5fVAiD8enHmGVoUGWKu9AYfyybM1u19FPaCzScc97yKY/jAEzZ//b99QIqxMPYVL31SlXhvfYtfRcAERxKWavSc43+DAgpuoA6lXtSht3k6E01ykMo+yg3mW53oUToWLSsEkOxWF5A7pQ1S6tfYsMw==" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:23 volumio go-librespot[13400]: time="2026-10-11T14:05:23+02:00" level=debug msg="completed challenge" Oct 11 14:05:24 volumio go-librespot[13400]: time="2026-10-11T14:05:24+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:24 volumio go-librespot[13400]: time="2026-10-11T14:05:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:24 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:24 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:24 volumio volumio[1244]: info: Oct 11 14:05:24 volumio volumio[1244]: ---------------------------- MPD announces system playlist update Oct 11 14:05:24 volumio volumio[1244]: info: Ignoring MPD Status Update Oct 11 14:05:24 volumio volumio[1244]: info: Oct 11 14:05:24 volumio volumio[1244]: ---------------------------- MPD announces state update: player Oct 11 14:05:24 volumio volumio[1244]: info: ControllerMpd::getState Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:05:24 volumio volumio[1244]: info: Oct 11 14:05:24 volumio volumio[1244]: ---------------------------- MPD announces system playlist update Oct 11 14:05:24 volumio volumio[1244]: info: Ignoring MPD Status Update Oct 11 14:05:24 volumio volumio[1244]: info: Oct 11 14:05:24 volumio volumio[1244]: ---------------------------- MPD announces state update: player Oct 11 14:05:24 volumio volumio[1244]: info: ControllerMpd::getState Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:05:24 volumio volumio[1244]: info: Oct 11 14:05:24 volumio volumio[1244]: ---------------------------- MPD announces system playlist update Oct 11 14:05:24 volumio volumio[1244]: info: Ignoring MPD Status Update Oct 11 14:05:24 volumio volumio[1244]: info: Oct 11 14:05:24 volumio volumio[1244]: ---------------------------- MPD announces state update: player Oct 11 14:05:24 volumio volumio[1244]: info: ControllerMpd::getState Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:05:24 volumio volumio[1244]: info: ------------------------------ 3ms Oct 11 14:05:24 volumio volumio[1244]: info: sendMpdCommand status took 2 milliseconds Oct 11 14:05:24 volumio volumio[1244]: info: ------------------------------ 2ms Oct 11 14:05:24 volumio volumio[1244]: info: sendMpdCommand status took 2 milliseconds Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::parseState Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::parseState Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:05:24 volumio volumio[1244]: info: ------------------------------ 3ms Oct 11 14:05:24 volumio volumio[1244]: info: sendMpdCommand status took 3 milliseconds Oct 11 14:05:24 volumio volumio[1244]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 14:05:24 volumio volumio[1244]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::parseState Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:05:24 volumio volumio[1244]: info: ControllerMpd::pushState Oct 11 14:05:24 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:24 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:24 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 11 14:05:24 volumio volumio[1244]: info: ControllerMpd::pushState Oct 11 14:05:24 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:24 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:24 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 11 14:05:24 volumio volumio[1244]: info: ------------------------------ 7ms Oct 11 14:05:24 volumio volumio[1244]: info: ------------------------------ 5ms Oct 11 14:05:24 volumio volumio[1244]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 14:05:24 volumio volumio[1244]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:05:24 volumio volumio[1244]: info: ControllerMpd::pushState Oct 11 14:05:24 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:24 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:24 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Oct 11 14:05:24 volumio volumio[1244]: info: ------------------------------ 5ms Oct 11 14:05:27 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 11 14:05:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Oct 11 14:05:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:27 volumio go-librespot[13419]: go-librespot daemon starting... Oct 11 14:05:27 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:27 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="app state loaded" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=info msg="zeroconf server listening on port 46157" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.568+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.591+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=http://pushupdates.volumio.org duration=22.630427ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.591+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=22.274927ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.591+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=23.255592ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.600+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=31.66459ms Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="obtained new client token: AAGE/2eddwsuEaM9NH7n3rK4gQzZieGvJ58xXKqHm3jCcwsv38//7ph35MMIzplCF7ZjWWchS4LQpTCbHUnxGQhALnbpSL9I2IPsV7AXMxrR+m68IsaY8rz/XevnoTxOvTCc4LcJtl+b9OjEXrNQ8BhP1VXozxADTL54MD1lraHuIW5ycLLbcaBCANKpBwK6//iCCENU7Eh+dyB5v4DGOpFs8DVW1BR7R5+KwvGx1iLwbKyfbuh3Yw==" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.697+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://www.googleapis.com duration=128.977279ms Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=debug msg="completed challenge" Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.724+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=156.356619ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.725+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://securetoken.googleapis.com duration=157.338358ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.732+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://functions.volumio.cloud duration=163.434732ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.735+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://functions.volumio.cloud duration=166.816112ms Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.747+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://database.volumio.cloud duration=177.530883ms Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.771+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=https://google.com duration=203.469079ms Oct 11 14:05:27 volumio go-librespot[13420]: time="2026-10-11T14:05:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:27 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:27.995+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=http://cddb.volumio.org duration=426.427869ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 11 14:05:28 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:28.073+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=30.138845ms timeout=10s endpoint=http://plugins.volumio.org duration=504.230032ms Oct 11 14:05:29 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:05:29 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:05:29 volumio volumio[1244]: info: Discovery: Getting this device information Oct 11 14:05:29 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:29 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:29 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:05:29 volumio volumio[1244]: verbose: New Socket.io Connection to 192.168.178.127:3000 from 192.168.178.131 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 11 14:05:29 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 11 14:05:29 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 11 14:05:30 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:30 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Oct 11 14:05:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:31 volumio go-librespot[13450]: go-librespot daemon starting... Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="app state loaded" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=info msg="zeroconf server listening on port 34763" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="obtained new client token: AAEJgaXhReHT2VCWu111j3P36PrYoXH+z4Hps8OvnKjDO3kUH3/iLVYIt/4bo7sotGz1B0Qz4MlIfD4aJn2xheXXWbMcq997x4t2lDssOoN2qf+wPYXQ/DJ73/yXyItu1uQ6qVaXvp3B8mnuezRw2N3V9IUUTJlufqbMWwm5ZnAW6OSGqdeIa/ZQ0KuRoO083paB1QNwrjEKMLvT9X0KeAml/ZjPrDlBhEgtAnCXoqo5cHDJY31dYA==" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=debug msg="completed challenge" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:31 volumio go-librespot[13451]: time="2026-10-11T14:05:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:33 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:33 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:33 volumio volumio[1244]: info: CoreCommandRouter::volumioGetQueue Oct 11 14:05:33 volumio volumio[1244]: info: CoreStateMachine::getQueue Oct 11 14:05:33 volumio volumio[1244]: info: CorePlayQueue::getQueue Oct 11 14:05:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Oct 11 14:05:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:34 volumio go-librespot[13468]: go-librespot daemon starting... Oct 11 14:05:34 volumio go-librespot[13469]: time="2026-10-11T14:05:34+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:34 volumio go-librespot[13469]: time="2026-10-11T14:05:34+02:00" level=debug msg="app state loaded" Oct 11 14:05:34 volumio go-librespot[13469]: time="2026-10-11T14:05:34+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:34 volumio go-librespot[13469]: time="2026-10-11T14:05:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=info msg="zeroconf server listening on port 37083" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="obtained new client token: AAE6bgmXQpnFNU4CqGlVglTW672RrN+eHhKYdPql9RLA0oINiAqi3/Ennup+TicENlbBudOn3YsWElv0OqpXzca1tIeG3RfBY4OVQOgEacuqi6qiorHoAtFPNsUWJ5ImFxbKvEVGs1y2RxtPxtZQebbfJWVQeYPxS7aV3sA4NtH1MvueQV9XcnmaR9f9mQkm5Zn5X2FLksKZnbSTH2d84CL7dVKIV/A+ly8mLVNIAD/0hR6jwD0=" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=debug msg="completed challenge" Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 11 14:05:35 volumio volumio[1244]: info: In handleBrowseUri, curUri=spotify Oct 11 14:05:35 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:35 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:35 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:35 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:35 volumio go-librespot[13469]: time="2026-10-11T14:05:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 14:05:35 volumio volumio[1244]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 11 14:05:35 volumio volumio[1244]: info: Received Get System Version Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 11 14:05:35 volumio volumio[1244]: info: Received Get System Info Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:05:35 volumio volumio[1244]: info: Discovery: Getting this device information Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:35 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:35 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:05:36 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:36 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:37 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 11 14:05:37 volumio volumio[1244]: info: In handleBrowseUri, curUri=spotify/playlists Oct 11 14:05:38 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Oct 11 14:05:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:38 volumio go-librespot[13489]: go-librespot daemon starting... Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="app state loaded" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=info msg="zeroconf server listening on port 45027" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="obtained new client token: AAH3NYqjb7ZO3+a5VO4Sjaq641qWkFCvXf/t9rVrb0IZgKmPa44g0MMB1Me9jx5ABECsdjzVglJ1OvTTsy4hh5mNuUFRGiqaKcx9buMu8D1p9b2oqfHvUQNHpBTtVPWkGEiwsliPjTIiK/0bMmX6p3uQLz/tvVUSBwicZPfGGXfB7kQ/U7U4Kfww/c4L1TN/Qh/mRxnOq+wl/FaXu0I8FG2enkEEfNcXlpUelDD1UyUxD6I4I86pSw==" Oct 11 14:05:38 volumio go-librespot[13504]: time="2026-10-11T14:05:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:39 volumio go-librespot[13504]: time="2026-10-11T14:05:39+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:39 volumio go-librespot[13504]: time="2026-10-11T14:05:39+02:00" level=debug msg="completed challenge" Oct 11 14:05:39 volumio go-librespot[13504]: time="2026-10-11T14:05:39+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:39 volumio go-librespot[13504]: time="2026-10-11T14:05:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:39 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:39 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:40 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 11 14:05:40 volumio volumio[1244]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:7hj6zYmbaaiq3XOvrANYAI Oct 11 14:05:41 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:0wY9rA9fJkuESyYm9uzVK5 Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:5PhThXEC5fVIbjwUhFc0Z3 Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:5T1Oj9YoaAgQYdlCQjATav Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:4J2s7nWDdA7i92sojYX8RJ Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:42F7AY5a40owYmUeq0QQTl Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:2jrXrZdn5PoPsMw9W0T5sn Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:37xM5UFUHSVBISEJWTYwvn Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:4Gasn91fsCefnN8zM5GjA8 Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:34FhndFs4d8ltOVj8JqN4s Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:6CtyKz8Dz6npeS572G1WAx Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:4OLpvmygTruvZfH1uyj6sS Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:7v3rmoy5jcn4h5UqwQyCM3 Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:2Xw8NBvHp3LkVZGcHE6Kyy Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:2t3Q3A7h742THd9u1TIUSz Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:7Iq8EO0pcLdEo4tJHcv6FL Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:5Yu1hJpkMPMiNn3Ymh4a3c Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:2TiY3wXiawy2tHnx8JZuwG Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:21Db0GDOcCezPtvibmeDCe Oct 11 14:05:41 volumio volumio[1244]: info: Preloading song: spotify:track:1lbNgoJ5iMrMluCyhI4OQP Oct 11 14:05:41 volumio volumio[1244]: info: Exploding uri spotify:track:0wY9rA9fJkuESyYm9uzVK5 in service spop Oct 11 14:05:41 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:0wY9rA9fJkuESyYm9uzVK5 Oct 11 14:05:41 volumio volumio[1244]: info: Exploding uri spotify:track:5PhThXEC5fVIbjwUhFc0Z3 in service spop Oct 11 14:05:41 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:5PhThXEC5fVIbjwUhFc0Z3 Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:5T1Oj9YoaAgQYdlCQjATav in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:5T1Oj9YoaAgQYdlCQjATav Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:4J2s7nWDdA7i92sojYX8RJ in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:4J2s7nWDdA7i92sojYX8RJ Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0wY9rA9fJkuESyYm9uzVK5","service":"spop","name":"D'Evils","artist":"SiR","album":"November","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b2736892023452c99d13a58c7647","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:42F7AY5a40owYmUeq0QQTl in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:42F7AY5a40owYmUeq0QQTl Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5PhThXEC5fVIbjwUhFc0Z3","service":"spop","name":"Common Person","artist":"Burna Boy","album":"Love, Damini","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b2730ff78f4bff0f63d66db22ba3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5T1Oj9YoaAgQYdlCQjATav","service":"spop","name":"Chain Smoker","artist":"Chance the Rapper","album":"Acid Rap (10th Anniversary - Complete Edition)","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf2c85c09079470c6662eccf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:2jrXrZdn5PoPsMw9W0T5sn in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:2jrXrZdn5PoPsMw9W0T5sn Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4J2s7nWDdA7i92sojYX8RJ","service":"spop","name":"Juice","artist":"Chance the Rapper","album":"Acid Rap (10th Anniversary - Complete Edition)","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf2c85c09079470c6662eccf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:37xM5UFUHSVBISEJWTYwvn in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:37xM5UFUHSVBISEJWTYwvn Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:42F7AY5a40owYmUeq0QQTl","service":"spop","name":"The Thrill","artist":"Wiz Khalifa","album":"The Thrill","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b27302b0327e0d514a5ba0f8ae14","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:4Gasn91fsCefnN8zM5GjA8 in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:4Gasn91fsCefnN8zM5GjA8 Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:34FhndFs4d8ltOVj8JqN4s in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:34FhndFs4d8ltOVj8JqN4s Oct 11 14:05:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Oct 11 14:05:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2jrXrZdn5PoPsMw9W0T5sn","service":"spop","name":"Hair Down","artist":"SiR","album":"Chasing Summer","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b2730087823a0797f3e1adce3333","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:6CtyKz8Dz6npeS572G1WAx in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:6CtyKz8Dz6npeS572G1WAx Oct 11 14:05:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:42 volumio go-librespot[13519]: go-librespot daemon starting... Oct 11 14:05:42 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:4OLpvmygTruvZfH1uyj6sS in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:4OLpvmygTruvZfH1uyj6sS Oct 11 14:05:42 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="app state loaded" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:7v3rmoy5jcn4h5UqwQyCM3 in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:7v3rmoy5jcn4h5UqwQyCM3 Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:37xM5UFUHSVBISEJWTYwvn","service":"spop","name":"Dreams","artist":"RUBII","album":"Dreams","type":"song","duration":141,"albumart":"https://i.scdn.co/image/ab67616d0000b273e9211a624b3f1105af1aaaee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:2Xw8NBvHp3LkVZGcHE6Kyy in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:2Xw8NBvHp3LkVZGcHE6Kyy Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:34FhndFs4d8ltOVj8JqN4s","service":"spop","name":"Jammin","artist":"RUBII","album":"Olive Green","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b27386aaccc3412f0143c2ca70b0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4Gasn91fsCefnN8zM5GjA8","service":"spop","name":"Finesse","artist":"Pheelz","album":"Finesse","type":"song","duration":155,"albumart":"https://i.scdn.co/image/ab67616d0000b27347fb5646baaff836507c4775","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6CtyKz8Dz6npeS572G1WAx","service":"spop","name":"Night Moves","artist":"M41NFR4M3","album":"The Dub Files Vol.II","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b27315d8bedeb523f8101a6a1dd3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4OLpvmygTruvZfH1uyj6sS","service":"spop","name":"Workin On Me","artist":"Russ","album":"Workin On Me","type":"song","duration":300,"albumart":"https://i.scdn.co/image/ab67616d0000b273b09996c031ef740f1fe27e70","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:2t3Q3A7h742THd9u1TIUSz in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:2t3Q3A7h742THd9u1TIUSz Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:7Iq8EO0pcLdEo4tJHcv6FL in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:7Iq8EO0pcLdEo4tJHcv6FL Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=info msg="zeroconf server listening on port 42591" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7v3rmoy5jcn4h5UqwQyCM3","service":"spop","name":"Ginseng Strip 2002","artist":"Yung Lean","album":"Lavender","type":"song","duration":153,"albumart":"https://i.scdn.co/image/ab67616d0000b273581915272a4ffd12551c0202","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2Xw8NBvHp3LkVZGcHE6Kyy","service":"spop","name":"Drop Out","artist":"Boogie Belgique","album":"Blueberry Hill","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b273c76e8f25b6c14cfa6454702e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:5Yu1hJpkMPMiNn3Ymh4a3c in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:5Yu1hJpkMPMiNn3Ymh4a3c Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="obtained new client token: AAEvxHlS0f0L0xQ7TZ6oicZttaD/eTRkm/HVuzmHhcLLTe115ALoZxCwDIjdkslrZOZWLpPh+VgJNfREuTjOtTZUrJlEdfg2m6DjbbrmxYDZcmS+n/MgHHXnjdMhbisOlaXCbMLMu1UVZQ2xZXFYv9iEfu7LdlTg2t6CpRetoYL1TjNVrlYIrJ87A+5RZgcR9Ij5vk9yZqK4f+tTWZ01NDZUiFmbPa7sIs+mMx15lx4vCc4Dl/ujuA==" Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:2TiY3wXiawy2tHnx8JZuwG in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:2TiY3wXiawy2tHnx8JZuwG Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:21Db0GDOcCezPtvibmeDCe in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:21Db0GDOcCezPtvibmeDCe Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=debug msg="completed challenge" Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7Iq8EO0pcLdEo4tJHcv6FL","service":"spop","name":"Booyaya","artist":"EquallyOpposite","album":"Booyaya","type":"song","duration":176,"albumart":"https://i.scdn.co/image/ab67616d0000b2739aede58d7315f3c1f801620b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Yu1hJpkMPMiNn3Ymh4a3c","service":"spop","name":"oh no i hope i don't fall","artist":"HIGHCELL","album":"oh no i hope i don't fall","type":"song","duration":158,"albumart":"https://i.scdn.co/image/ab67616d0000b2730e76848a406e622c5d639d47","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: info: Exploding uri spotify:track:1lbNgoJ5iMrMluCyhI4OQP in service spop Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: EXPLODING URI:spotify:track:1lbNgoJ5iMrMluCyhI4OQP Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2TiY3wXiawy2tHnx8JZuwG","service":"spop","name":"Let's Go!","artist":"Alumni Cloud","album":"Let's Go!","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b2732123ab0a862e728fb797c7f5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2t3Q3A7h742THd9u1TIUSz","service":"spop","name":"Lejanía","artist":"Rozhes","album":"Lejanía","type":"song","duration":143,"albumart":"https://i.scdn.co/image/ab67616d0000b273882f5f13a0b46e8138567ede","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:42 volumio go-librespot[13522]: time="2026-10-11T14:05:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:43 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:21Db0GDOcCezPtvibmeDCe","service":"spop","name":"8:55 - Jend Remix","artist":"Jend","album":"8:55 (Jend Remix)","type":"song","duration":194,"albumart":"https://i.scdn.co/image/ab67616d0000b27363184fde0f0f660debead388","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:43 volumio volumio[1244]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1lbNgoJ5iMrMluCyhI4OQP","service":"spop","name":"Victory Lap","artist":"Fred again..","album":"Victory Lap","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b273bf705b821b031cefe91d7b90","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 11 14:05:44 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::ClearQueue Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::stop Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::stPlaybackTimer Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::updateTrackBlock Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrackBlock Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::serviceStop Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 0 Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::serviceStop Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::stop Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand stop Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::clearPlayQueue Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::saveQueue Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushQueue Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::addQueueItems Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::addQueueItems Oct 11 14:05:44 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:0wY9rA9fJkuESyYm9uzVK5 Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:0wY9rA9fJkuESyYm9uzVK5 Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:5PhThXEC5fVIbjwUhFc0Z3 Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:5PhThXEC5fVIbjwUhFc0Z3 Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:5T1Oj9YoaAgQYdlCQjATav Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:5T1Oj9YoaAgQYdlCQjATav Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:4J2s7nWDdA7i92sojYX8RJ Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:4J2s7nWDdA7i92sojYX8RJ Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:42F7AY5a40owYmUeq0QQTl Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:42F7AY5a40owYmUeq0QQTl Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:2jrXrZdn5PoPsMw9W0T5sn Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:2jrXrZdn5PoPsMw9W0T5sn Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:37xM5UFUHSVBISEJWTYwvn Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:37xM5UFUHSVBISEJWTYwvn Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:4Gasn91fsCefnN8zM5GjA8 Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:4Gasn91fsCefnN8zM5GjA8 Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:34FhndFs4d8ltOVj8JqN4s Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:34FhndFs4d8ltOVj8JqN4s Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:6CtyKz8Dz6npeS572G1WAx Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:6CtyKz8Dz6npeS572G1WAx Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:4OLpvmygTruvZfH1uyj6sS Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:4OLpvmygTruvZfH1uyj6sS Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:7v3rmoy5jcn4h5UqwQyCM3 Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:7v3rmoy5jcn4h5UqwQyCM3 Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:2Xw8NBvHp3LkVZGcHE6Kyy Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:2Xw8NBvHp3LkVZGcHE6Kyy Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:2t3Q3A7h742THd9u1TIUSz Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:2t3Q3A7h742THd9u1TIUSz Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:7Iq8EO0pcLdEo4tJHcv6FL Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:7Iq8EO0pcLdEo4tJHcv6FL Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:5Yu1hJpkMPMiNn3Ymh4a3c Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:5Yu1hJpkMPMiNn3Ymh4a3c Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:2TiY3wXiawy2tHnx8JZuwG Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:2TiY3wXiawy2tHnx8JZuwG Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:21Db0GDOcCezPtvibmeDCe Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:21Db0GDOcCezPtvibmeDCe Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.931+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=0 volume=51 Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.932+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=https://stream.radioparadise.com/mellow-flacm title="Neighborhood #4 (7 Kettles)" Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushQueue Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::saveQueue Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::updateTrackBlock Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrackBlock Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPlay Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::play index 17 Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::addQueueItems Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::addQueueItems Oct 11 14:05:44 volumio volumio[1244]: info: Preload queue cleared Oct 11 14:05:44 volumio volumio[1244]: info: Adding Item to queue: spotify:track:1lbNgoJ5iMrMluCyhI4OQP Oct 11 14:05:44 volumio volumio[1244]: info: Using cached record of: spotify:track:1lbNgoJ5iMrMluCyhI4OQP Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::stop Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushQueue Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::saveQueue Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::play index undefined Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::updateTrackBlock Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrackBlock Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::startPlaybackTimer Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: [1791720344953] ControllerSpotify::clearAddPlayTrack Oct 11 14:05:44 volumio volumio[1244]: info: Sending Spotify command with payload to local API: /player/play Oct 11 14:05:44 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:44 volumio volumio[1244]: info: Oct 11 14:05:44 volumio volumio[1244]: ---------------------------- MPD announces state update: player Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand stop took 42 milliseconds Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::getState Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received radio_paradise Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.970+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=0 volume=51 Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.971+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:44 volumio volumio[1244]: info: Oct 11 14:05:44 volumio volumio[1244]: ---------------------------- MPD announces state update: player Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::getState Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:05:44 volumio volumio[1244]: info: Oct 11 14:05:44 volumio volumio[1244]: ---------------------------- MPD announces state update: player Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::getState Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:05:44 volumio volumio[1244]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:44 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand status took 16 milliseconds Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand status took 7 milliseconds Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand status took 6 milliseconds Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::parseState Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::parseState Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::parseState Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 11 14:05:44 volumio volumio[1244]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:05:44 volumio volumio[1244]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Oct 11 14:05:44 volumio volumio[1244]: info: ControllerMpd::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::servicePushState Oct 11 14:05:44 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:44 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:44 volumio volumio[1244]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.998+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=0 volume=51 Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.998+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:44 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:44.999+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=0 volume=51 Oct 11 14:05:45 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:45.000+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:45 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:45.001+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=0 volume=51 Oct 11 14:05:45 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:45.001+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:45 volumio volumio[1244]: info: ------------------------------ 47ms Oct 11 14:05:45 volumio volumio[1244]: info: ------------------------------ 38ms Oct 11 14:05:45 volumio volumio[1244]: info: ------------------------------ 37ms Oct 11 14:05:45 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:45 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:45 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Oct 11 14:05:45 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:45 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Oct 11 14:05:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:46 volumio go-librespot[13539]: go-librespot daemon starting... Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="app state loaded" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=info msg="zeroconf server listening on port 36853" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="obtained new client token: AAEFq9inFsbjjyWxmmF1uqY3TRluJ/Mb5lMYpmkRNE3rANAvjXjNojAWwkJk9cbHgMNsAyQUD6fOAB/K8p7gS7fV0dR40OPu50IReBc8HZX8aiAyJSlftcaWIc1++lvprPYtgqdJoBzZ/Ip3ISy19mde8AN0EC46rNOgbLcNeRG0TeJPYRJ7cjp3hwaOxKtvvURuez4kKtG0AngZcqWaHKTvcgVookEPIc3IXR6hTSBfeC8Tae43dQ==" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=debug msg="completed challenge" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:46 volumio go-librespot[13540]: time="2026-10-11T14:05:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:47 volumio volumio[1244]: info: CoreCommandRouter::volumioPlay Oct 11 14:05:47 volumio volumio[1244]: info: CoreStateMachine::play index undefined Oct 11 14:05:47 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:47 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:47 volumio volumio[1244]: info: CoreStateMachine::startPlaybackTimer Oct 11 14:05:47 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:47 volumio volumio[1244]: info: [1791720347228] ControllerSpotify::clearAddPlayTrack Oct 11 14:05:47 volumio volumio[1244]: info: Sending Spotify command with payload to local API: /player/play Oct 11 14:05:47 volumio volumio[1244]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:48 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:48 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:49 volumio volumio[1244]: info: CoreCommandRouter::volumioPlay Oct 11 14:05:49 volumio volumio[1244]: info: CoreStateMachine::play index undefined Oct 11 14:05:49 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:49 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:49 volumio volumio[1244]: info: CoreStateMachine::startPlaybackTimer Oct 11 14:05:49 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:49 volumio volumio[1244]: info: [1791720349536] ControllerSpotify::clearAddPlayTrack Oct 11 14:05:49 volumio volumio[1244]: info: Sending Spotify command with payload to local API: /player/play Oct 11 14:05:49 volumio volumio[1244]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Oct 11 14:05:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:49 volumio go-librespot[13563]: go-librespot daemon starting... Oct 11 14:05:49 volumio go-librespot[13564]: time="2026-10-11T14:05:49+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:49 volumio go-librespot[13564]: time="2026-10-11T14:05:49+02:00" level=debug msg="app state loaded" Oct 11 14:05:49 volumio go-librespot[13564]: time="2026-10-11T14:05:49+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:49 volumio go-librespot[13564]: time="2026-10-11T14:05:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=info msg="zeroconf server listening on port 45023" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="obtained new client token: AAFdTdunnLzGw5J1BJbUmUY9RSjkhAexpd+bmM9l3rHhNCZ//8AdHieF0fN6NLszuxx5M3RDZjf64emEMNaNJvopmfR5xazCOvzBP50zVx0uey9ycRknmDvIW7PUo5OXXiQIpt56s/B3soFUcAmHXBEfl8AOCqJJayUkAzM8Ekxa6cBSvVPDXX1I6zpFyE219CWsvMN9u/K6VQujhJjTsjLCLwHvrIP87Xlnq2hPNs25DvSLjQo=" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=debug msg="completed challenge" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:50 volumio go-librespot[13564]: time="2026-10-11T14:05:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:51 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:51 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:52 volumio volumio[1244]: info: CoreCommandRouter::volumioPlay Oct 11 14:05:52 volumio volumio[1244]: info: CoreStateMachine::play index undefined Oct 11 14:05:52 volumio volumio[1244]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:05:52 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:52 volumio volumio[1244]: info: CoreStateMachine::startPlaybackTimer Oct 11 14:05:52 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:52 volumio volumio[1244]: info: [1791720352425] ControllerSpotify::clearAddPlayTrack Oct 11 14:05:52 volumio volumio[1244]: info: Sending Spotify command with payload to local API: /player/play Oct 11 14:05:52 volumio volumio[1244]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Oct 11 14:05:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:53 volumio go-librespot[13574]: go-librespot daemon starting... Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="app state loaded" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=info msg="zeroconf server listening on port 45809" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="obtained new client token: AAGrkeywhuvlpVuhlhW8CQzcKbv/AgtRrWH0/e+RCHwlPY+0kJq4KFloD2T9DX4e08Ss8nYq7QJZIfc4HhSDFQVkK4H3kCn7UDysU8jynKCPBbvyHzTPWlD1kLktlTj8ItXxqvT3B6K6C4Thlcxigge1u5LmC4tCjeOn8unHfdpQx8Ld7oDHXEZooCRKcBP9APutPSMo88GjixOv7uL7IUtzwqnhSHcXmBRFqcas5yz1EWOKzyDNWw==" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:53 volumio go-librespot[13575]: time="2026-10-11T14:05:53+02:00" level=debug msg="completed challenge" Oct 11 14:05:54 volumio go-librespot[13575]: time="2026-10-11T14:05:54+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:54 volumio go-librespot[13575]: time="2026-10-11T14:05:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:54 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:54 volumio volumio[1244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.535+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=31.750735ms timeout=3s volume=44 Oct 11 14:05:55 volumio volumio[1244]: info: VolumeController::SetAlsaVolume44 Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:55 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:55 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:55 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.554+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=3057 volume=44 Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.554+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: SPOTIFY VOLUME 51 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: VOLUMIO VOLUME 44 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 11 14:05:55 volumio volumio[1244]: info: Setting Spotify Volume from Volumio: 44 Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.638+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=32.773596ms timeout=3s volume=43 Oct 11 14:05:55 volumio volumio[1244]: info: VolumeController::SetAlsaVolume43 Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:55 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:55 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:55 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.651+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=3153 volume=43 Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.651+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: SPOTIFY VOLUME 44 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: VOLUMIO VOLUME 43 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.739+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=32.492444ms timeout=3s volume=41 Oct 11 14:05:55 volumio volumio[1244]: info: VolumeController::SetAlsaVolume41 Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:05:55 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:55 volumio volumio[1244]: info: CoreStateMachine::pushState Oct 11 14:05:55 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:05:55 volumio volumio[1244]: info: CoreCommandRouter::volumioPushState Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.754+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" state=STATUS_STOPPED positionMs=3307 volume=41 Oct 11 14:05:55 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:55.754+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" id=spotify:track:21Db0GDOcCezPtvibmeDCe title="8:55 - Jend Remix" Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: SPOTIFY VOLUME 44 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: VOLUMIO VOLUME 41 Oct 11 14:05:55 volumio volumio[1244]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 11 14:05:55 volumio volumio[1244]: info: Setting Spotify Volume from Volumio: 41 Oct 11 14:05:57 volumio volumio[1244]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Oct 11 14:05:57 volumio volumio[1244]: info: Sending Spotify command with payload to local API: /player/volume Oct 11 14:05:57 volumio volumio[1244]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:05:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Oct 11 14:05:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:05:57 volumio go-librespot[13587]: go-librespot daemon starting... Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=info msg="running go-librespot 0.7.1" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="app state loaded" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="stored credentials not found" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:05:57 volumio volumio[1244]: info: Initializing connection to go-librespot Websocket Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="new websocket client" Oct 11 14:05:57 volumio volumio[1244]: info: Connection to go-librespot Websocket established Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=info msg="zeroconf server listening on port 40683" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="obtained new client token: AAFiqb7zQQUy+Fu7QI+l9pypgp1oaYO0QM+CUV2c43lOGV8tS8jdtZgUCi/hh05vb/zHYzoZZ/RpZijrArkYUB6AA4MTIsgLvcFTkA/BK6d5A1ko5tSHieAChJ6SR98MFXMiUhAP8y2CKQTPFQsGnOoLDa5qMEnD4JmZuICkOiEXBzCc1d1KuF7+IkVZktcZAIOtL4405d0IbIdii4HZa3OIsSNW9VJnJx9RhNsdzU5iSS3q346naQ==" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="completed keyexchange" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=debug msg="completed challenge" Oct 11 14:05:57 volumio go-librespot[13588]: time="2026-10-11T14:05:57+02:00" level=info msg="authenticated AP" username="12*******31" Oct 11 14:05:58 volumio go-librespot[13588]: time="2026-10-11T14:05:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:05:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:05:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:05:58 volumio volumio[1244]: info: Connection to go-librespot Websocket closed Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.574+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=38.052627ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.585+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.605+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=19.638768ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.609+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=http://pushupdates.volumio.org duration=23.515257ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.609+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=22.257446ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.621+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=34.000417ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.657+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://google.com duration=71.234809ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.707+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://www.googleapis.com duration=121.460724ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.727+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://securetoken.googleapis.com duration=140.965028ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.743+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=156.084622ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.747+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://functions.volumio.cloud duration=161.365053ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.760+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://functions.volumio.cloud duration=173.740227ms Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.763+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=https://database.volumio.cloud duration=176.585756ms Oct 11 14:05:59 volumio sudo[13613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 11 14:05:59 volumio sudo[13613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:05:59 volumio sudo[13613]: pam_unix(sudo:session): session closed for user root Oct 11 14:05:59 volumio sudo[13615]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 11 14:05:59 volumio sudo[13615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:05:59 volumio sudo[13615]: pam_unix(sudo:session): session closed for user root Oct 11 14:05:59 volumio volumio[1244]: verbose: New Socket.io Connection to 192.168.178.127 from 192.168.178.131 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 11 14:05:59 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 11 14:05:59 volumio volumio5-onboarding[1957]: time=2026-10-11T14:05:59.997+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=http://cddb.volumio.org duration=411.47776ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 11 14:06:00 volumio sudo[13619]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 11 14:06:00 volumio sudo[13619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:06:00 volumio sudo[13619]: pam_unix(sudo:session): session closed for user root Oct 11 14:06:00 volumio sudo[13621]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 11 14:06:00 volumio sudo[13621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:06:00 volumio sudo[13621]: pam_unix(sudo:session): session closed for user root Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 11 14:06:00 volumio volumio[1244]: verbose: New Socket.io Connection to 192.168.178.127 from 192.168.178.131 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 11 14:06:00 volumio volumio5-onboarding[1957]: time=2026-10-11T14:06:00.136+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.131:60061,00:00:00:00:00:00%08 @ 0x28009f0" latency=28.747162ms timeout=10s endpoint=http://plugins.volumio.org duration=550.517405ms Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::volumioGetVisibleSources Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:06:00 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 11 14:06:00 volumio volumio[1244]: info: Received Get System Info Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:06:00 volumio volumio[1244]: info: Discovery: Getting this device information Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:06:00 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::volumioGetState Oct 11 14:06:00 volumio volumio[1244]: info: CorePlayQueue::getTrack 17 Oct 11 14:06:00 volumio volumio[1244]: info: Listing playlists Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 14:06:00 volumio volumio[1244]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 11 14:06:00 volumio volumio[1244]: info: Getting Spotify volume Oct 11 14:06:00 volumio volumio[1244]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 14:06:00 volumio volumio[1244]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:06:00 volumio volumio[1244]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 11 14:06:00 volumio volumio[1244]: errno: -111, Oct 11 14:06:00 volumio volumio[1244]: code: 'ECONNREFUSED', Oct 11 14:06:00 volumio volumio[1244]: syscall: 'connect', Oct 11 14:06:00 volumio volumio[1244]: address: '127.0.0.1', Oct 11 14:06:00 volumio volumio[1244]: port: 9879, Oct 11 14:06:00 volumio volumio[1244]: response: undefined Oct 11 14:06:00 volumio volumio[1244]: } Oct 11 14:06:00 volumio volumio[1244]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 14:06:00 volumio sudo[13639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-11 14:05' Oct 11 14:06:00 volumio sudo[13639]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"