Apr 11 16:46:02 volumio wpa_supplicant[3915]: wlan0: CTRL-EVENT-BEACON-LOSS Apr 11 16:46:15 volumio volumio5-onboarding[1770]: time=2026-04-11T16:46:15.312+07:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.23:57535 @ 0xc0002e6d20" latency=274.218136ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 11 16:46:15 volumio ntpd[1110]: PROTO: 159.223.60.208 unlink local addr 192.168.1.24 -> Apr 11 16:46:15 volumio sudo[7246]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 16:46:15 volumio sudo[7246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:46:15 volumio sudo[7246]: pam_unix(sudo:session): session closed for user root Apr 11 16:46:15 volumio sudo[7248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 16:46:15 volumio sudo[7248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:46:15 volumio sudo[7248]: pam_unix(sudo:session): session closed for user root Apr 11 16:46:15 volumio volumio[1388]: verbose: New Socket.io Connection to 192.168.1.24 from 192.168.1.23 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Apr 11 16:46:15 volumio sudo[7253]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 16:46:15 volumio sudo[7253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:46:15 volumio sudo[7253]: pam_unix(sudo:session): session closed for user root Apr 11 16:46:15 volumio sudo[7255]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 16:46:15 volumio sudo[7255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:46:15 volumio sudo[7255]: pam_unix(sudo:session): session closed for user root Apr 11 16:46:15 volumio volumio[1388]: verbose: New Socket.io Connection to 192.168.1.24 from 192.168.1.23 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Apr 11 16:46:15 volumio volumio[1388]: info: CoreCommandRouter::volumioGetState Apr 11 16:46:15 volumio volumio[1388]: info: CorePlayQueue::getTrack 0 Apr 11 16:46:15 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 16:46:15 volumio volumio[1388]: info: Listing playlists Apr 11 16:46:15 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 11 16:46:15 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 16:46:15 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 16:46:15 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 16:46:16 volumio bluealsa[1057]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci1/dev_DC_04_67_9D_A9_4F, ...) Apr 11 16:46:16 volumio volumio5-onboarding[1770]: time=2026-04-11T16:46:16.740+07:00 level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=DC:04:67:9D:A9:4F error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" Apr 11 16:46:17 volumio volumio[1388]: info: CoreCommandRouter::volumioPlay Apr 11 16:46:17 volumio volumio[1388]: info: CoreStateMachine::play index undefined Apr 11 16:46:17 volumio volumio[1388]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 16:46:17 volumio volumio[1388]: info: CorePlayQueue::getTrack 0 Apr 11 16:46:17 volumio volumio[1388]: info: CoreStateMachine::startPlaybackTimer Apr 11 16:46:17 volumio volumio[1388]: info: CorePlayQueue::getTrack 0 Apr 11 16:46:17 volumio volumio[1388]: info: [ytmusic-play] clearAddPlayTrack: ytmusic/video@explodeTrackData:o=%7B%22type%22%3A%22video%22%2C%22title%22%3A%22logical%20(Official%20Lyric%20Video)%22%2C%22artist%22%3A%22Olivia%20Rodrigo%22%2C%22album%22%3A%22%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FI6OeAufKDBg%2Fhq720.jpg%3Fsqp%3D-oaymwEXCNUGEOADIAQqCwjVARCqCBh4INgESFo%26rs%3DAMzJL3lCYkfUAkVPeIE46BFu9vlwRcHJrA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22I6OeAufKDBg%22%2C%22playlistId%22%3A%22RDCLAK5uy_nRFKmL13urbE-A89oJfnt1-u1hfiCLriA%22%2C%22params%22%3A%22OAHyAQQIARgD%22%2C%22index%22%3A0%2C%22playlistSetVideoId%22%3A%2256B44F6D10557CC6%22%7D%2C%22musicVideoType%22%3A%22MUSIC_VIDEO_TYPE_OMV%22%7D%2C%22autoplayContext%22%3A%7B%22fetchEndpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22playlistId%22%3A%22RDCLAK5uy_nRFKmL13urbE-A89oJfnt1-u1hfiCLriA%22%2C%22params%22%3A%22OAHyAQQIARgD%22%2C%22videoId%22%3A%22nCkpzqqog4k%22%7D%7D%7D%7D Apr 11 16:46:17 volumio volumio[1388]: info: [ytmusic] Obtained PO token for video #I6OeAufKDBg: MlVfxQlDUVuyJF_7cLja1QggpCigCg4IAy14EG5L2UTNgTC0RYCeSmj1Ib26KMP1Ie9vMA0CqKXWTzf6jk-TF00wpCqX_YLPEDlm3Nl6nBv7HDpA_Gr4 Apr 11 16:46:18 volumio volumio[1388]: error: [ytmusic] Innertube support service: TypeError: exportedVars.nFunction is not a function Apr 11 16:46:18 volumio volumio[1388]: at eval (eval at evalFnImpl (file:///data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Service.js:29:12), :16:26) Apr 11 16:46:18 volumio volumio[1388]: at evalFnImpl (file:///data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Service.js:29:26) Apr 11 16:46:18 volumio volumio[1388]: at Object.evalFn (file:///data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Service.js:65:48) Apr 11 16:46:18 volumio volumio[1388]: at file:///data/plugins/music_service/ytmusic/node_modules/volumio-yt-support/dist/lib/innertube/Server.js:96:96 Apr 11 16:46:18 volumio volumio[1388]: at Layer.handleRequest (file:///data/plugins/music_service/ytmusic/node_modules/router/lib/layer.js:152:17) Apr 11 16:46:18 volumio volumio[1388]: at next (file:///data/plugins/music_service/ytmusic/node_modules/router/lib/route.js:157:13) Apr 11 16:46:18 volumio volumio[1388]: at Route.dispatch (file:///data/plugins/music_service/ytmusic/node_modules/router/lib/route.js:117:3) Apr 11 16:46:18 volumio volumio[1388]: at handle (file:///data/plugins/music_service/ytmusic/node_modules/router/index.js:435:11) Apr 11 16:46:18 volumio volumio[1388]: at Layer.handleRequest (file:///data/plugins/music_service/ytmusic/node_modules/router/lib/layer.js:152:17) Apr 11 16:46:18 volumio volumio[1388]: at file:///data/plugins/music_service/ytmusic/node_modules/router/index.js:295:15 Apr 11 16:46:20 volumio wpa_supplicant[3915]: wlan0: CTRL-EVENT-BEACON-LOSS Apr 11 16:46:21 volumio ntpd[1110]: PROTO: 122.248.201.177 unlink local addr 192.168.1.24 -> Apr 11 16:46:21 volumio ntpd[1110]: PROTO: 129.150.55.241 unlink local addr 192.168.1.24 -> Apr 11 16:46:21 volumio volumio[1388]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 16:46:21 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 16:46:21 volumio volumio[1388]: info: CoreCommandRouter::volumioGetQueue Apr 11 16:46:21 volumio volumio[1388]: info: CoreStateMachine::getQueue Apr 11 16:46:21 volumio volumio[1388]: info: CorePlayQueue::getQueue Apr 11 16:46:22 volumio ntpd[1110]: PROTO: 103.221.223.143 unlink local addr 192.168.1.24 -> Apr 11 16:46:24 volumio bluealsa[1057]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci1/dev_56_A4_39_47_DA_C8, ...) Apr 11 16:46:25 volumio ntpd[1110]: PROTO: 203.123.48.1 unlink local addr 192.168.1.24 -> Apr 11 16:46:27 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 16:46:27 volumio volumio[1388]: info: Received Get System Info Apr 11 16:46:27 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 16:46:27 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 16:46:27 volumio volumio[1388]: info: Discovery: Getting this device information Apr 11 16:46:27 volumio volumio[1388]: info: CoreCommandRouter::volumioGetState Apr 11 16:46:27 volumio volumio[1388]: info: CorePlayQueue::getTrack 0 Apr 11 16:46:27 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 16:46:28 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 16:46:28 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 16:46:33 volumio volumio[1388]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 11 16:46:33 volumio volumio[1388]: info: Received Get System Version Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 16:46:33 volumio volumio[1388]: info: Received Get System Info Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 16:46:33 volumio volumio[1388]: info: Discovery: Getting this device information Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::volumioGetState Apr 11 16:46:33 volumio volumio[1388]: info: CorePlayQueue::getTrack 0 Apr 11 16:46:33 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 16:46:38 volumio bluealsa[1057]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci1/dev_F0_2B_D7_1A_91_9C, ...) Apr 11 16:46:38 volumio volumio5-onboarding[1770]: time=2026-04-11T16:46:38.088+07:00 level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=F0:2B:D7:1A:91:9C error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" Apr 11 16:46:39 volumio bluealsa[1057]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci1/dev_5C_8D_1C_74_BD_A0, ...) Apr 11 16:46:39 volumio volumio5-onboarding[1770]: time=2026-04-11T16:46:39.475+07:00 level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=5C:8D:1C:74:BD:A0 error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" Apr 11 16:46:49 volumio bluealsa[1057]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci1/dev_DC_04_67_9D_A9_4F, ...) Apr 11 16:46:50 volumio bluealsa[1057]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci1/dev_E5_98_EC_F9_B9_A9, ...) Apr 11 16:46:58 volumio volumio[1388]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 16:47:09 volumio bluealsa[1057]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci1/dev_5C_8D_1C_74_BD_A0, ...) Apr 11 16:47:18 volumio bluealsa[1057]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci1/dev_DC_04_67_9D_A9_4F, ...) Apr 11 16:47:18 volumio volumio5-onboarding[1770]: time=2026-04-11T16:47:18.597+07:00 level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=DC:04:67:9D:A9:4F error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" Apr 11 16:47:22 volumio bluealsa[1057]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci1/dev_6A_D6_BA_00_61_94, ...) Apr 11 16:47:22 volumio volumio5-onboarding[1770]: time=2026-04-11T16:47:22.199+07:00 level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=6A:D6:BA:00:61:94 error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" Apr 11 16:47:22 volumio volumio[1388]: info: Received OAUTH Data Apr 11 16:47:22 volumio volumio[1388]: info: Executing Spotify Oauth Login Apr 11 16:47:22 volumio volumio[1388]: info: Saving Spotify Refresh Token Apr 11 16:47:23 volumio sudo[7435]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 16:47:23 volumio sudo[7435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:47:23 volumio sudo[7435]: pam_unix(sudo:session): session closed for user root Apr 11 16:47:23 volumio sudo[7437]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 16:47:23 volumio sudo[7437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:47:23 volumio sudo[7437]: pam_unix(sudo:session): session closed for user root Apr 11 16:47:23 volumio volumio[1388]: verbose: New Socket.io Connection to 192.168.1.24 from 192.168.1.23 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::volumioGetState Apr 11 16:47:23 volumio volumio[1388]: info: CorePlayQueue::getTrack 0 Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 16:47:23 volumio volumio[1388]: info: New Spotify access tokenBQDf1PkdNg... Apr 11 16:47:23 volumio volumio[1388]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 11 16:47:23 volumio volumio[1388]: SPOTIFY: User informations: {"country":"IN","display_name":"Tân Tit","email":"tannh81.bvsc@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/315qee2w2i26yi4mzflhupgvlcc4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/315qee2w2i26yi4mzflhupgvlcc4","id":"315qee2w2i26yi4mzflhupgvlcc4","images":[],"product":"free","type":"user","uri":"spotify:user:315qee2w2i26yi4mzflhupgvlcc4"} Apr 11 16:47:23 volumio volumio[1388]: info: Creating Spotify config file Apr 11 16:47:23 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 16:47:23 volumio volumio[1388]: info: Spotify config file written Apr 11 16:47:23 volumio sudo[7442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 11 16:47:23 volumio sudo[7442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 16:47:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Apr 11 16:47:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Apr 11 16:47:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 11 16:47:23 volumio volumio[1388]: info: Connection to go-librespot Websocket closed Apr 11 16:47:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 16:47:23 volumio sudo[7442]: pam_unix(sudo:session): session closed for user root Apr 11 16:47:23 volumio go-librespot[7444]: go-librespot daemon starting... Apr 11 16:47:23 volumio go-librespot[7445]: time="2026-04-11T16:47:23+07:00" level=info msg="running go-librespot 0.7.1" Apr 11 16:47:23 volumio go-librespot[7445]: time="2026-04-11T16:47:23+07:00" level=debug msg="app state loaded" Apr 11 16:47:23 volumio go-librespot[7445]: time="2026-04-11T16:47:23+07:00" level=debug msg="stored credentials not found" Apr 11 16:47:23 volumio go-librespot[7445]: time="2026-04-11T16:47:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=info msg="zeroconf server listening on port 43227" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="obtained new client token: AAAlxZGOIRi9SSYRkukXhh+zZM4vYp9twP/yYL9ABt4PnYqp6TXN+NkdsPT1JBYuenJDvxUbJVwbIyryvSrE44/NReTfr2JZB28RZOlL2XkysoDdQY/1ainZhkHTu42Iabwx/a7guE7XQ7VuEUrcIq5BJe8DCW6f1bWjprE7uEd6KOx90JBVLk8Q+ItNRI1A/tQF1wR5jLqquhsnlOMQkm+lBfRPTbcCs6DSo9xeOnfCajN+mjpsTxw=" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="completed keyexchange" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=debug msg="completed challenge" Apr 11 16:47:24 volumio go-librespot[7445]: time="2026-04-11T16:47:24+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 11 16:47:24 volumio volumio[1388]: info: New Spotify access tokenBQAePMG7Wo... Apr 11 16:47:24 volumio volumio[1388]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 11 16:47:24 volumio volumio[1388]: SPOTIFY: User informations: {"country":"IN","display_name":"Tân Tit","email":"tannh81.bvsc@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/315qee2w2i26yi4mzflhupgvlcc4"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/315qee2w2i26yi4mzflhupgvlcc4","id":"315qee2w2i26yi4mzflhupgvlcc4","images":[],"product":"free","type":"user","uri":"spotify:user:315qee2w2i26yi4mzflhupgvlcc4"} Apr 11 16:47:24 volumio volumio[1388]: info: Spotify Successfully logged in Apr 11 16:47:24 volumio volumio[1388]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 16:47:24 volumio volumio[1388]: info: [1775900844823] CoreMusicLibrary::Adding element Spotify Apr 11 16:47:24 volumio volumio[1388]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 16:47:24 volumio volumio[1388]: Cannot find translation for source YouTube2 Apr 11 16:47:24 volumio volumio[1388]: Cannot find translation for source YouTube Music Apr 11 16:47:24 volumio volumio[1388]: Cannot find translation for source Spotify Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=debug msg="completed keyexchange" Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=debug msg="completed challenge" Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=debug msg="completed keyexchange" Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=debug msg="completed challenge" Apr 11 16:47:25 volumio go-librespot[7445]: time="2026-04-11T16:47:25+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 11 16:47:26 volumio go-librespot[7445]: time="2026-04-11T16:47:26+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 11 16:47:26 volumio go-librespot[7445]: time="2026-04-11T16:47:26+07:00" level=debug msg="completed keyexchange" Apr 11 16:47:26 volumio go-librespot[7445]: time="2026-04-11T16:47:26+07:00" level=debug msg="completed challenge" Apr 11 16:47:26 volumio volumio[1388]: info: Initializing connection to go-librespot Websocket Apr 11 16:47:26 volumio go-librespot[7445]: time="2026-04-11T16:47:26+07:00" level=debug msg="new websocket client" Apr 11 16:47:26 volumio volumio[1388]: info: Connection to go-librespot Websocket established Apr 11 16:47:26 volumio volumio[1388]: info: go-librespot daemon successfully initialized Apr 11 16:47:27 volumio go-librespot[7445]: time="2026-04-11T16:47:27+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 11 16:47:27 volumio go-librespot[7445]: time="2026-04-11T16:47:27+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 11 16:47:28 volumio bluealsa[1057]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci1/dev_5C_8D_1C_74_BD_A0, ...) Apr 11 16:47:28 volumio volumio5-onboarding[1770]: time=2026-04-11T16:47:28.151+07:00 level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=5C:8D:1C:74:BD:A0 error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" Apr 11 16:47:28 volumio go-librespot[7445]: time="2026-04-11T16:47:28+07:00" level=debug msg="completed keyexchange" Apr 11 16:47:28 volumio go-librespot[7445]: time="2026-04-11T16:47:28+07:00" level=debug msg="completed challenge" Apr 11 16:47:28 volumio go-librespot[7445]: time="2026-04-11T16:47:28+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 11 16:47:29 volumio go-librespot[7445]: time="2026-04-11T16:47:29+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 11 16:47:29 volumio go-librespot[7445]: time="2026-04-11T16:47:29+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Apr 11 16:47:29 volumio go-librespot[7445]: time="2026-04-11T16:47:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Apr 11 16:47:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 11 16:47:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 11 16:47:29 volumio volumio[1388]: info: Connection to go-librespot Websocket closed Apr 11 16:47:29 volumio volumio[1388]: info: Getting Spotify volume Apr 11 16:47:29 volumio volumio[1388]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 16:47:29 volumio volumio[1388]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 11 16:47:29 volumio volumio[1388]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 11 16:47:29 volumio volumio[1388]: errno: -111, Apr 11 16:47:29 volumio volumio[1388]: code: 'ECONNREFUSED', Apr 11 16:47:29 volumio volumio[1388]: syscall: 'connect', Apr 11 16:47:29 volumio volumio[1388]: address: '127.0.0.1', Apr 11 16:47:29 volumio volumio[1388]: port: 9879, Apr 11 16:47:29 volumio volumio[1388]: response: undefined Apr 11 16:47:29 volumio volumio[1388]: } Apr 11 16:47:29 volumio volumio[1388]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 16:47:30 volumio sudo[7475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 16:46' Apr 11 16:47:30 volumio sudo[7475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"