Oct 30 23:21:00 volumio mpd[12633]: 2025-10-30T23:21:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Oct 30 23:21:00 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Oct 30 23:21:00 volumio sudo[12603]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:00 volumio sudo[12593]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:00 volumio go-librespot[12669]: time="2025-10-30T23:21:00Z" level=debug msg="obtained new client token: AAAOKMmcBx1c7cEWNFUmfu9ps58U5//cLfEvPZC5WdFTHO4K1YZkkb2DxNGqUeeWXNiDx9pAzG4ntWDXx/4vu9xjbkVHYB+8nqRnIcoB6ypgr8zzDQuoAdLr4bjIogbSPRLeQb4HLrXLmNcAXo6eSxe4rYGZIluSZoL/8Mlb4ur4HaF7q1Kr78xNQ7ch8pxhJK697t/0bewUM03lQQJ8+uqIbDMxrOUJNfuaSA+ya4TumjfOGwqM"
Oct 30 23:21:00 volumio volumio[12466]: error: MPD error: The expression evaluated to a falsy value:
Oct 30 23:21:00 volumio volumio[12466]: assert.ok(self.idling)
Oct 30 23:21:00 volumio volumio[12466]: error: The expression evaluated to a falsy value:
Oct 30 23:21:00 volumio volumio[12466]: assert.ok(self.idling)
Oct 30 23:21:00 volumio volumio[12466]: info: MPD running with PID12633
Oct 30 23:21:00 volumio volumio[12466]: ,establishing connection
Oct 30 23:21:00 volumio volumio[12466]: error: updateQueue error: null
Oct 30 23:21:00 volumio volumio[12466]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Oct 30 23:21:00 volumio volumio[12466]: SPOTIFY: BQAZhPUxW4fzuBMg6fspJAPoyCPOx7rMHySZUlZ9lGmDYIF1vZ34XWk6hddIgeEP6jZocJjpRTw_Rt_w4zgqx-upey4BcUi6FbbIqg88pOXROU2Nn4tzHCba3TG4Xi18VaRdrW9lGGX8hkki2X-HatRruRddBLjyRe6HULthLF8mmcfLdjj5wihEc5lzVOGFGmzAdbzNCOp2N9eeOjkLtxOBxD5oMiOTNTRhll76MGyGJZH5gltXjWJLWwAqEOZOWq3HT8L-vaFNvWnhZNL_2e20WVJBqGfNoQ_9ZuHxzQc039qhoaI
Oct 30 23:21:00 volumio volumio[12466]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Oct 30 23:21:00 volumio volumio[12466]: info: New Spotify access token = BQAZhPUxW4fzuBMg6fspJAPoyCPOx7rMHySZUlZ9lGmDYIF1vZ34XWk6hddIgeEP6jZocJjpRTw_Rt_w4zgqx-upey4BcUi6FbbIqg88pOXROU2Nn4tzHCba3TG4Xi18VaRdrW9lGGX8hkki2X-HatRruRddBLjyRe6HULthLF8mmcfLdjj5wihEc5lzVOGFGmzAdbzNCOp2N9eeOjkLtxOBxD5oMiOTNTRhll76MGyGJZH5gltXjWJLWwAqEOZOWq3HT8L-vaFNvWnhZNL_2e20WVJBqGfNoQ_9ZuHxzQc039qhoaI
Oct 30 23:21:00 volumio volumio[12466]: info: Spotify credentials grant success - running version from March 24, 2019
Oct 30 23:21:00 volumio volumio[12466]: error: updateQueue error: null
Oct 30 23:21:00 volumio volumio[12466]: info: [yt-cast-receiver] DIAL server listening on port 8098
Oct 30 23:21:00 volumio volumio[12466]: info: CoreCommandRouter::volumioRetrievevolume
Oct 30 23:21:00 volumio go-librespot[12669]: time="2025-10-30T23:21:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:00 volumio volumio[12466]: info: VolumeController:: Volume=33 Mute =false
Oct 30 23:21:00 volumio volumio[12466]: info: CoreCommandRouter::volumioGetState
Oct 30 23:21:00 volumio volumio[12466]: info: CorePlayQueue::getTrack 0
Oct 30 23:21:00 volumio volumio[12466]: info: CoreStateMachine::pushState
Oct 30 23:21:00 volumio volumio[12466]: info: CorePlayQueue::getTrack 0
Oct 30 23:21:00 volumio volumio[12466]: info: CoreCommandRouter::volumioPushState
Oct 30 23:21:00 volumio go-librespot[12669]: time="2025-10-30T23:21:00Z" level=debug msg="completed keyexchange"
Oct 30 23:21:00 volumio go-librespot[12669]: time="2025-10-30T23:21:00Z" level=debug msg="completed challenge"
Oct 30 23:21:00 volumio go-librespot[12669]: time="2025-10-30T23:21:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:00 volumio volumio[12466]: SPOTIFY: User informations: {"country":"DE","display_name":"lapman","email":"ylm19961214@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31hyzsop5elyyfayaiyk5tmkxmky"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31hyzsop5elyyfayaiyk5tmkxmky","id":"31hyzsop5elyyfayaiyk5tmkxmky","images":[],"product":"free","type":"user","uri":"spotify:user:31hyzsop5elyyfayaiyk5tmkxmky"}
Oct 30 23:21:00 volumio volumio[12466]: info: Spotify Successfully logged in
Oct 30 23:21:00 volumio volumio[12466]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Oct 30 23:21:00 volumio volumio[12466]: info: [1761866460536] CoreMusicLibrary::Adding element Spotify
Oct 30 23:21:00 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 30 23:21:00 volumio volumio[12466]: Cannot find translation for source Spotify
Oct 30 23:21:00 volumio volumio[12466]: info: Completed starting Core Plugins
Oct 30 23:21:00 volumio volumio[12466]: info: -------------------------------------------
Oct 30 23:21:00 volumio volumio[12466]: info: ----- MyVolumio plugins startup ----
Oct 30 23:21:00 volumio volumio[12466]: info: -------------------------------------------
Oct 30 23:21:00 volumio volumio[12466]: info: [MyVolumio PluginManager] Fetching plans data....
Oct 30 23:21:01 volumio volumio-remote-updater[874]: [2025-10-30 23:21:01] [connect] Successful connection
Oct 30 23:21:01 volumio volumio-remote-updater[874]: [2025-10-30 23:21:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1761866461 101
Oct 30 23:21:01 volumio volumio[12466]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2
Oct 30 23:21:02 volumio volumio[12466]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds
Oct 30 23:21:02 volumio volumio[12466]: info: go-librespot daemon successfully initialized
Oct 30 23:21:03 volumio sudo[12722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Oct 30 23:21:03 volumio sudo[12722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:03 volumio sudo[12724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Oct 30 23:21:03 volumio sudo[12724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:03 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Oct 30 23:21:03 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Oct 30 23:21:03 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Oct 30 23:21:03 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Oct 30 23:21:03 volumio mpd_monitor.sh[12727]: MPD Monitor Service: Starting MPD Monitor Service
Oct 30 23:21:03 volumio sudo[12722]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:03 volumio sudo[12724]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:03 volumio volumio[12466]: info: Successfully started MPD Monitor
Oct 30 23:21:03 volumio volumio[12466]: info: Successfully started MPD Monitor
Oct 30 23:21:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 287.
Oct 30 23:21:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:03 volumio go-librespot[12731]: go-librespot daemon starting...
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="app state loaded"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=info msg="zeroconf server listening on port 45967"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="obtained new client token: AAD76fySiQ+pJz1DKyeSaHNJ7Rs+Fk++S6OefjZoss1Iiu70WitAgfapGhtZfU0OZrdBK81VY+zrLJ+q4maUn9Sc88dCqsHwENFQcALRasVut5kJmP5XR4p6bPvrUWsJnd9VkUuR+vCcN7miMDpn+V0ZL/5bBMEczRmekDS5fFDg4PO7+TTJ7V0dIDFN57tCE4VgZ63BMTfreU7QOI+WT27wBAixD6KxAU37CO4TSJevSHR1ZHmuQpQ="
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="completed keyexchange"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=debug msg="completed challenge"
Oct 30 23:21:03 volumio go-librespot[12732]: time="2025-10-30T23:21:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:05 volumio volumio[12466]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Oct 30 23:21:05 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:05 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 288.
Oct 30 23:21:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:07 volumio go-librespot[12739]: go-librespot daemon starting...
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="app state loaded"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=info msg="zeroconf server listening on port 38697"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="obtained new client token: AADDjvmlldSRSgUTRQB9J2DABQALJ9tJS7vPQV5BTAMYrt26Gz00wAMh/YX4ye/kmBFfNxEhzygH2vN3cJdu3WIgZnvp0/iOtJ3WJ6vSeqlRvMRjTpzIPuwN8NyOaNCWjYFOApzIP/9NYpNm7KYtxPLDykAT6yrI+SSZhgfWYziDiAxZqVGgCtblu7vp9sI5wsIWYEh0zVyNi8NOiEdNvsEn4RTUvJi3AdpMAQGZZ/DG4gFpnJIz"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="completed keyexchange"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=debug msg="completed challenge"
Oct 30 23:21:07 volumio go-librespot[12740]: time="2025-10-30T23:21:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:07 volumio volumio[12466]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds
Oct 30 23:21:07 volumio sudo[12762]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Oct 30 23:21:07 volumio sudo[12762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:07 volumio sudo[12764]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Oct 30 23:21:07 volumio sudo[12764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:07 volumio sudo[12762]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:07 volumio sudo[12764]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:07 volumio sudo[12768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Oct 30 23:21:07 volumio sudo[12768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:07 volumio sudo[12768]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:07 volumio volumio[12466]: info: Upmpdcli Daemon Started
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin bluetooth to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin multiroom to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin metavolumio to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin cd_controller to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin qobuzconnect to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin smart_inputs to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: Adding plugin tidalconnect to MyMusic Plugins
Oct 30 23:21:08 volumio volumio[12466]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Oct 30 23:21:09 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:09 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:09 volumio volumio[12466]: info: Starting MyVolumio Remote Streaming Endpoints
Oct 30 23:21:09 volumio volumio[12466]: info: MyVolumio login type: Token
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Oct 30 23:21:09 volumio volumio[12466]: info: Streaming services startup
Oct 30 23:21:09 volumio volumio[12466]: info: Starting Streaming Daemon
Oct 30 23:21:09 volumio sudo[12771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Oct 30 23:21:09 volumio sudo[12771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:09 volumio volumio[12466]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Oct 30 23:21:09 volumio sudo[12771]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:09 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:09 volumio volumio[12466]: error: Cannot start Volumio Streaming Daemon
Oct 30 23:21:09 volumio volumio[12466]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Oct 30 23:21:09 volumio volumio[12466]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Oct 30 23:21:09 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:09 volumio volumio[12466]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Oct 30 23:21:10 volumio volumio[12466]: info: MyVolumio token set successfully
Oct 30 23:21:10 volumio volumio[12466]: info: MYVOLUMIO: Adding device
Oct 30 23:21:10 volumio volumio[12466]: info: MYVOLUMIO: Evaluating Server
Oct 30 23:21:10 volumio volumio[12466]: info: MyVolumio status changed
Oct 30 23:21:10 volumio volumio[12466]: info: Streaming services startup
Oct 30 23:21:10 volumio volumio[12466]: info: Starting Streaming Daemon
Oct 30 23:21:10 volumio volumio[12466]: info: Removing browser output: myVolumio user plan is not superstar
Oct 30 23:21:10 volumio volumio[12466]: info: Removing audio output:
Oct 30 23:21:10 volumio volumio[12466]: info: Stoppping Tunnel 1
Oct 30 23:21:10 volumio sudo[12795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Oct 30 23:21:10 volumio sudo[12795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:10 volumio sudo[12797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Oct 30 23:21:10 volumio sudo[12797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio sudo[12795]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:10 volumio volumio[12466]: error: Cannot start Volumio Streaming Daemon
Oct 30 23:21:10 volumio volumio[12466]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Oct 30 23:21:10 volumio volumio[12466]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Oct 30 23:21:10 volumio sudo[12797]: pam_unix(sudo:session): session closed for user root
Oct 30 23:21:10 volumio volumio[12466]: info: Remote SSH Stopped
Oct 30 23:21:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 289.
Oct 30 23:21:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:10 volumio volumio[12466]: info: Setting Geolocation for MyVolumio to eu3
Oct 30 23:21:10 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:10 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:10 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:10 volumio go-librespot[12800]: go-librespot daemon starting...
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="app state loaded"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=info msg="zeroconf server listening on port 43307"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="obtained new client token: AACQe1lVqfQ1s7DhHuGfMgQEQZw9cGvpGwPlnmf+t8ZQTjZJx+RTY/9jZvfXiQ2dIqUEYtWF/HWHaS6/i3iWwKmt4tApaw1+wp73noIw+CDbDs15S3HWQJNPS5vWWcPjQAxFwxJ+IiPk8TkQcYtg15/Go4B4yngdGTNqz5VwrElhfAS35AfV9eaA/KfUYf5WKGy/j6PMlGfSGkLRTD8R/hYGLYyEqeHm7Gx6kmusRZ0G34VR5QpBb8M="
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="completed keyexchange"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=debug msg="completed challenge"
Oct 30 23:21:10 volumio go-librespot[12801]: time="2025-10-30T23:21:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:11 volumio volumio[12466]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Oct 30 23:21:11 volumio volumio[12466]: info: Updating MyVolumio device info
Oct 30 23:21:11 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:11 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:11 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:11 volumio volumio[12466]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Oct 30 23:21:12 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:12 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:12 volumio volumio[12466]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds
Oct 30 23:21:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 290.
Oct 30 23:21:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:14 volumio go-librespot[12809]: go-librespot daemon starting...
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="app state loaded"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=info msg="zeroconf server listening on port 33339"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="obtained new client token: AABwCCwbva2YCh/bC0+4/4QmXAxACOQSiJIxFg3a2FIfsV/tu06onJ8TqJ7a831n0l8ima7Zu3Qk5HsbYQr3wNMlIZ0oTzPc7sAckXgUvn11y8ofDxTBXP0MGPH6ibXhMv0MEVATwbAnqjBQcl2aSDQo5Ao1B4IxSFRUzMHJUv0F8Tg0lNQYBDtfj9SFc0lVZf3nnGRLcUpHfCVwqwE9jXQcFYhdozBKrHNP7Q2FyA3tBz6/bt4E"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="completed keyexchange"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=debug msg="completed challenge"
Oct 30 23:21:14 volumio go-librespot[12810]: time="2025-10-30T23:21:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:15 volumio volumio[12466]: info: MYVOLUMIO: Adding device
Oct 30 23:21:15 volumio volumio[12466]: info: MYVOLUMIO: Evaluating Server
Oct 30 23:21:15 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:15 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:15 volumio volumio[12466]: info: Setting Geolocation for MyVolumio to eu3
Oct 30 23:21:15 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:15 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:15 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:16 volumio volumio[12466]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Oct 30 23:21:16 volumio volumio[12466]: info: Updating MyVolumio device info
Oct 30 23:21:16 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:16 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:16 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:17 volumio volumio[12466]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Oct 30 23:21:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 291.
Oct 30 23:21:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:17 volumio go-librespot[12832]: go-librespot daemon starting...
Oct 30 23:21:17 volumio volumio[12466]: info: Cannot mount NAS at system boot, trial number 4 ,stopping
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="app state loaded"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=info msg="zeroconf server listening on port 42111"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="obtained new client token: AAAIGbKHTLM3JrJw+XPB8xAp2PgLQvtmGMytRv0YGaTYZFE5CEdmkyreWwH7YKY0uIS1s0nyFCHOiGmZWqVbQ8W8C3xZqurgm2ZFJnrLDoyfkGoAy4M2psGx4BBg61tYWo4YS8hm4u1y09UQ+4Hf4iL2zT9hftljbHaUyKhhHh+/+0qkOh0aD2DwwHPw/DvhgwvoLvJ0WyH+JxwY8vl3xvm3t4tyHy9q5EmilVyc/F7dwM/fwngnOMk="
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="completed keyexchange"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=debug msg="completed challenge"
Oct 30 23:21:17 volumio go-librespot[12847]: time="2025-10-30T23:21:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:18 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:18 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 292.
Oct 30 23:21:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:21 volumio go-librespot[12854]: go-librespot daemon starting...
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="app state loaded"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=info msg="zeroconf server listening on port 37437"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="obtained new client token: AACn4uo3BpD8MM/OBmq4JS0UF+NVSdRSHuzZ1PaFp3aeurIMDPcvnv0JPIIWDadPa1GBpjnsLOHvAnrV9CMbbSMMj2nLntSEzPt9KnOf2XBktL/1M7ZiLl2iixcHv7x/4DMAczeB0UDNzUI0cN+7Poudbu7nRvJypdEqfKpkZf0cq+2IivrM71tn3i7G4H8WLtkhj1DYIgfGTV/c9HUSzkJY7MqpoTP+/qCn/KTgh9Lgg6NokgNm"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="completed keyexchange"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=debug msg="completed challenge"
Oct 30 23:21:21 volumio go-librespot[12855]: time="2025-10-30T23:21:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:21 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:21 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:24 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Oct 30 23:21:24 volumio volumio[12466]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Oct 30 23:21:24 volumio volumio[12466]: info: CoreCommandRouter::volumioGetState
Oct 30 23:21:24 volumio volumio[12466]: info: CorePlayQueue::getTrack 0
Oct 30 23:21:24 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:24 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 293.
Oct 30 23:21:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:24 volumio go-librespot[12866]: go-librespot daemon starting...
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="app state loaded"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=info msg="zeroconf server listening on port 38343"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="obtained new client token: AADS41CYFfdB7sNp851ReX5pAF+U/wtG/mIrF7oBayUI9IlUdG5XQtMW/8LqRqzoNQlFHYIKNY0b5S/T49IMJcp7L1km6oyehK7ICl44CFK7cv1SwleWqjXJnO+89FVpfg9lEqEB2Vkty0/J3UiwcWyEXrK5i8z4Zx15Kw/vSRtBihrZwoHoPtHT5WETVBmuMuqcmwJs18F399tYVy/2ZbtD106jd+Hz5eXcINTY25TUi9f8qsu0xEA="
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="completed keyexchange"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=debug msg="completed challenge"
Oct 30 23:21:24 volumio go-librespot[12867]: time="2025-10-30T23:21:24Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:27 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:27 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 294.
Oct 30 23:21:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:28 volumio go-librespot[12888]: go-librespot daemon starting...
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="app state loaded"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=info msg="zeroconf server listening on port 36669"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="obtained new client token: AAC8srXUgRvdUz9BeslJ920rZQ4d5U/DzdsfhAKAkdzCMFsc3sqw+nIe/Unkyvf+wMJlI6P4hIsioPm8XGUnVe3T5x5pFjckktae6Ig/lhfuuzsexiIQyIntSYyB6qkfOO5l5WuVcboNxh1rBAXUxqIo0kK8pOkaySIAjTwvMMrT+/4fYAjB+DwBvaZlhQl2stucSwnvOypwLc4izAGSoKZANwpHQAPMI8FxMsVzG3hPBMcVP0x/"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="completed keyexchange"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=debug msg="completed challenge"
Oct 30 23:21:28 volumio go-librespot[12889]: time="2025-10-30T23:21:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::volumioGetBrowseSources
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 30 23:21:29 volumio volumio[12466]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Oct 30 23:21:29 volumio volumio[12466]: info: Completed starting MyVolumio Plugin
Oct 30 23:21:29 volumio volumio[12466]: [Metrics] CommandRouter: 32s 142.53ms
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::volumiosetStartupVolume
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::Close All Modals sent
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::Close All Modals sent
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Oct 30 23:21:29 volumio volumio-remote-updater[874]: Test mode disabled
Oct 30 23:21:29 volumio volumio-remote-updater[874]: Alpha mode disabled
Oct 30 23:21:29 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Oct 30 23:21:29 volumio volumio[12466]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Oct 30 23:21:29 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Oct 30 23:21:30 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Oct 30 23:21:30 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Oct 30 23:21:30 volumio volumio[12466]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Oct 30 23:21:30 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:30 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 295.
Oct 30 23:21:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:31 volumio go-librespot[12906]: go-librespot daemon starting...
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="app state loaded"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=info msg="zeroconf server listening on port 37335"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="obtained new client token: AAB8/wxuFXFoU75f3Qoh4a28iYvkHY0mgRRzocrD/U7LHujCmdoUvI3seTIIyC5MXVvBo35Lllbm1AP66yPH3ircM1ObQe5L5bJC8/8mUQjERvxllzpCosM6ULZahCJayaOm/cm/7cCfkRsD+IcXWtaDySy5KBca0SqYbabkQOMfH4gTdy/NI0hRF2bVDKnXl7qIIvIk1pBq6w7EmqDETBtiWiNO43SdwV+EarcaW6fbyifARatnipY="
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="completed keyexchange"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=debug msg="completed challenge"
Oct 30 23:21:31 volumio go-librespot[12907]: time="2025-10-30T23:21:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:33 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:33 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 296.
Oct 30 23:21:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:35 volumio go-librespot[12915]: go-librespot daemon starting...
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="app state loaded"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=info msg="zeroconf server listening on port 38419"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="obtained new client token: AADPTZc4P77cIrgRqpV6hvcyC3styJbY4yHTSgM/IgyVuEf//XMmCXhwykI/ESNYjnF5fNoSLAx5mJlbe+iUSMrdKdHxeQNrOjYIqC4G7zM5mxHQBQI5RepJsUoVWWl02n/JEQZUQalY5+Xs6TRMRosy94NgF7gZj8uY8Y0+ioZ3RIrksSG+fLzZ28BHhbg5fVMouGN0hJD1wHo7C3a/B9L5QKt49v7pGRY13IIMsOo6iY5HtnhT"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="completed keyexchange"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=debug msg="completed challenge"
Oct 30 23:21:35 volumio go-librespot[12916]: time="2025-10-30T23:21:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:36 volumio volumio[12466]: info: BOOT COMPLETED
Oct 30 23:21:36 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:36 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 297.
Oct 30 23:21:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:38 volumio go-librespot[12938]: go-librespot daemon starting...
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="app state loaded"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=info msg="zeroconf server listening on port 45249"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="obtained new client token: AAAl/fqxWyq3lLbGXYWTnDfGFUzAE1r2zaotpCFrVv5NcQJVvHlNBAQigK26gNcfYjPqSk24Cr2YmR6NE3AS/jGNAiIIwJK5iSEqcaJl9uwZP1AP+F4u9vcuW31S7UxtztlVmtL2sOFLBRvXcUNWuFiMpoMMTQcJkAdpIORFxQCkIlzejwERbRPMNeTaMVME9scNw45JJJCauEFZbO7idc4AcwV/RSdCw7Dkc01o2aHxejaZVOcO1Nk="
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="completed keyexchange"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=debug msg="completed challenge"
Oct 30 23:21:38 volumio go-librespot[12939]: time="2025-10-30T23:21:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:39 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:39 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 298.
Oct 30 23:21:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:42 volumio go-librespot[12947]: go-librespot daemon starting...
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="app state loaded"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=info msg="zeroconf server listening on port 42907"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="obtained new client token: AADQgADxdZtV+dEdDKK8SaySWv7QFNvDt/QDzD6T6rACx9Lf1qTkKdG/SbGbVsjO5N0YPbUGEFW0xak9Api4K1RdsWA5EqYOMDlP2lz9hD1lxa/LFQOWQSBfoYD6RJ1ikrZY17mDp1RUF+FheR1z9Zds6tCOg2lxuVqEH0uUWTJKUTzxv2asL/AdpmLI93f22jst00UbxpbfpN9AhElvXG8rrmatNW+Gz93epNthSacTy0yuSQz9"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="completed keyexchange"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=debug msg="completed challenge"
Oct 30 23:21:42 volumio go-librespot[12948]: time="2025-10-30T23:21:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:42 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:42 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:45 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:45 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 299.
Oct 30 23:21:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:45 volumio go-librespot[12958]: go-librespot daemon starting...
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=debug msg="app state loaded"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=info msg="zeroconf server listening on port 45611"
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=debug msg="obtained new client token: AABNtka6i1Xck1xdpJAjltLjoANlQRqhhUAZk31mbgskg/ZRIXi4nN4jD05IN+WSmdvfG23KnQL7NuMxkI3DxXG22jbHXK5wHX2h6NNxMzFgkjBdaz7ZxDiwUVzEdHEPfPpMZuvL0oL/ZWyqSR18riSyCGmJZl3BGNDWSmxGIu7ZXhZu9iam5NfEl9yD/2zORpcB2SljmRGzcO3tbTRTJcPT1nmFAAidxMapEIIAVv5tMs+WREQsRqg="
Oct 30 23:21:45 volumio go-librespot[12959]: time="2025-10-30T23:21:45Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:46 volumio go-librespot[12959]: time="2025-10-30T23:21:46Z" level=debug msg="completed keyexchange"
Oct 30 23:21:46 volumio go-librespot[12959]: time="2025-10-30T23:21:46Z" level=debug msg="completed challenge"
Oct 30 23:21:46 volumio go-librespot[12959]: time="2025-10-30T23:21:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:48 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:48 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 300.
Oct 30 23:21:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:49 volumio go-librespot[12980]: go-librespot daemon starting...
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="app state loaded"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=info msg="zeroconf server listening on port 40097"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="obtained new client token: AAC5OqRoiuThfEelnLChTOijVraucy6apm7myIQQO9oEjldEPsbNOhjA3mS1LdutU69k6ywtA3HKoSRq5gKpJrHZbQ/hAYms3JCODu2lWBFWig9isolZFIcOT8hk52GY9++VxihWIhOc3fnvm7jf7pKbTQhmjickURWs3ah/c77S/IFnWxZ3g/zZ9BkEr0Uykriuov32MgPdAom8GP6XhDihueU42gS3ENiR7REkp6tgJauBqgqjsac="
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="connected to ap-gew1.spotify.com:443"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="completed keyexchange"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=debug msg="completed challenge"
Oct 30 23:21:49 volumio go-librespot[12981]: time="2025-10-30T23:21:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:51 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:51 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 301.
Oct 30 23:21:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:52 volumio go-librespot[12988]: go-librespot daemon starting...
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=debug msg="app state loaded"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=info msg="zeroconf server listening on port 46443"
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=debug msg="obtained new client token: AADFMtZqjtWa9s1+SJbKCv8KzoWeQmxjiNwG6wP9YXP9f1qTai1NA7jvXOl0O+NOmzpdAtB7lFHHaIRFjP9L6GHZ8IskTPOihJ0joeUaydc+0nr9t0EKSTS/MD+l8QR4KI/LvUP4TlLJBYW9Q6AlhpKmrqEZjGSPpksPaP8Ndj/ItHfgENP1SMyYsy9pZvnUB9YFFmFQMUTt2KYOmsl2KdF3W8n/34qCp8lYKGQCaWALhw1b1LG3qM8="
Oct 30 23:21:52 volumio go-librespot[12990]: time="2025-10-30T23:21:52Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:53 volumio go-librespot[12990]: time="2025-10-30T23:21:53Z" level=debug msg="completed keyexchange"
Oct 30 23:21:53 volumio go-librespot[12990]: time="2025-10-30T23:21:53Z" level=debug msg="completed challenge"
Oct 30 23:21:53 volumio go-librespot[12990]: time="2025-10-30T23:21:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:54 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:54 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 302.
Oct 30 23:21:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:56 volumio go-librespot[12998]: go-librespot daemon starting...
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="app state loaded"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=info msg="zeroconf server listening on port 43191"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="obtained new client token: AADOUuFPpUmSsx3sdF0F2RhNffh9PHQ5oI/zOnaZn6Da7BNlxo6RHn8nvxrnYfGZ7NXEJrfrq6GA5GkLr/ghL0cL5AA3291aCd7V5GfuZn2gjXvbjaevaf6Q9oIIznerGKisuPopwQk3GWHz2ydwv1IIGIHrk0SPq4850wrQiGmscuBvoDe61xMvzyn3By/gL5hdJXh6IQbhE2Gpe+mJHpraTls7/+hGOG02f7u/2squzhv0CHHPVuw="
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="completed keyexchange"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=debug msg="completed challenge"
Oct 30 23:21:56 volumio go-librespot[12999]: time="2025-10-30T23:21:56Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:21:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:21:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:21:57 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:21:57 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:21:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 303.
Oct 30 23:21:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:21:59 volumio go-librespot[13020]: go-librespot daemon starting...
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=debug msg="app state loaded"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=info msg="zeroconf server listening on port 33365"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=debug msg="obtained new client token: AAA68QyE/PeI7zACy3SDOUVkwt717zP+SK1EBTBu6Etazmejj9n1KBdQwhu9rNDcUd0QftKqcxJGEvqi18KFVnRoBuMf39WYckQmvtkcEur0mMaQvAQoHomR7SvhYfxlnzB5VagVTkZUVHMEJ0+kwHpWlvS78+1kpWexMBGEVOBRXXoco2TG/hJD7PZdJ5cThC34OOoQtJpsLpxeMYRi0jj8I1kIB8F9Uc59AThabWedgT4EoJ6rTTM="
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused"
Oct 30 23:21:59 volumio go-librespot[13021]: time="2025-10-30T23:21:59Z" level=debug msg="connected to ap-gew1.spotify.com:443"
Oct 30 23:22:00 volumio go-librespot[13021]: time="2025-10-30T23:22:00Z" level=debug msg="completed keyexchange"
Oct 30 23:22:00 volumio go-librespot[13021]: time="2025-10-30T23:22:00Z" level=debug msg="completed challenge"
Oct 30 23:22:00 volumio go-librespot[13021]: time="2025-10-30T23:22:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:22:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:22:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:22:00 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:22:00 volumio volumio[12466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:22:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 304.
Oct 30 23:22:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:22:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Oct 30 23:22:03 volumio go-librespot[13031]: go-librespot daemon starting...
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=info msg="running go-librespot 0.4.0"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="app state loaded"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=info msg="api server listening on 127.0.0.1:9879"
Oct 30 23:22:03 volumio volumio[12466]: info: Initializing connection to go-librespot Websocket
Oct 30 23:22:03 volumio volumio[12466]: info: Connection to go-librespot Websocket established
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="new websocket client"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=info msg="zeroconf server listening on port 33509"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="obtained new client token: AACDpvNKmKkcmib3q9ixBG5dsgpsRdfNhz4x6kpbN5JkuPBwQ2sG900uDdLGvWVjmVlHxQd/5214Z9SP/eGC0qL/7eYt6chP0z5NjtkVwV0ga55SK1n/PK8iYkfu9IonIgd032LSJGeq3Z8Iq6WA5cRCAGu2DPXSPx34Q1xVMGB734oIWdUXvcIipIaGyn/8B71BrKQt+ZDI2FpPJ+3F40EURtSMHM762FOydYbMdS9NHVsBX6qyxZE="
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="completed keyexchange"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=debug msg="completed challenge"
Oct 30 23:22:03 volumio go-librespot[13032]: time="2025-10-30T23:22:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction "
Oct 30 23:22:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Oct 30 23:22:03 volumio volumio[12466]: info: Connection to go-librespot Websocket closed
Oct 30 23:22:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Oct 30 23:22:06 volumio volumio[12466]: info: Getting Spotify volume
Oct 30 23:22:06 volumio volumio[12466]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 30 23:22:06 volumio volumio[12466]: Error: connect ECONNREFUSED 127.0.0.1:9879
Oct 30 23:22:06 volumio volumio[12466]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Oct 30 23:22:06 volumio volumio[12466]: errno: -111,
Oct 30 23:22:06 volumio volumio[12466]: code: 'ECONNREFUSED',
Oct 30 23:22:06 volumio volumio[12466]: syscall: 'connect',
Oct 30 23:22:06 volumio volumio[12466]: address: '127.0.0.1',
Oct 30 23:22:06 volumio volumio[12466]: port: 9879,
Oct 30 23:22:06 volumio volumio[12466]: response: undefined
Oct 30 23:22:06 volumio volumio[12466]: }
Oct 30 23:22:06 volumio volumio[12466]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 30 23:22:06 volumio sudo[13053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-30 23:21'
Oct 30 23:22:06 volumio sudo[13053]: 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="c22b72a8acb34a699a626adb0a09a6b88ee7233a"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="40400d6a6fa57cf20e36499e510876b3654e9c4e"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat Oct 4 16:40:08 UTC 2025"
VOLUMIO_VERSION="4.061"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="7f8ace80645f85765fa10c72d1769d04"