Feb 18 07:06:00 volumio volumio[13982]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 18 07:06:00 volumio volumio[13982]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 18 07:06:00 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:00 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:00 volumio volumio[13982]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 18 07:06:00 volumio volumio[13982]: info: MyVolumio login type: Token
Feb 18 07:06:00 volumio volumio[13982]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 18 07:06:00 volumio volumio[13982]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 18 07:06:02 volumio volumio[13982]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 18 07:06:02 volumio volumio[13982]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 18 07:06:02 volumio volumio[13982]: info: Streaming services startup
Feb 18 07:06:02 volumio volumio[13982]: info: Starting Streaming Daemon
Feb 18 07:06:02 volumio sudo[14354]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 18 07:06:02 volumio sudo[14354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:02 volumio volumio[13982]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 18 07:06:02 volumio sudo[14354]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:02 volumio volumio[13982]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:02 volumio volumio[13982]: error: Cannot start Volumio Streaming Daemon
Feb 18 07:06:02 volumio volumio[13982]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 18 07:06:02 volumio volumio[13982]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 18 07:06:02 volumio volumio[13982]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:06:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 18 07:06:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:03 volumio go-librespot[14361]: go-librespot daemon starting...
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=debug msg="app state loaded"
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:03 volumio go-librespot[14362]: time="2026-02-18T07:06:03+07:00" level=info msg="zeroconf server listening on port 41073"
Feb 18 07:06:03 volumio volumio[13982]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 18 07:06:04 volumio go-librespot[14362]: time="2026-02-18T07:06:04+07:00" level=debug msg="obtained new client token: AACBEvFbQnnhFzP8Dt1cuujDyA/v2L8qDnPINxlfKoiMQA6H+WFsczb373PETugQh/49PPTZxozCoIAS3WmRvdHRIfUt/82CLscj3kpb1VvQPe+TLA+6UPTpShUWWcT2fG6m+qj1T6K/rLc8TnFbEMsCJ1H5mHD+8gsjilVO+fl+XqpnU29Yz12UiVXUFqof224Y/wvWPuYnp9NecMnOps+dV0EmviALMRioPjLX2/PiudHEncDb/7T9xw=="
Feb 18 07:06:04 volumio go-librespot[14362]: time="2026-02-18T07:06:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:04 volumio go-librespot[14362]: time="2026-02-18T07:06:04+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:04 volumio go-librespot[14362]: time="2026-02-18T07:06:04+07:00" level=debug msg="completed challenge"
Feb 18 07:06:04 volumio go-librespot[14362]: time="2026-02-18T07:06:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:05 volumio volumio[13982]: info: MyVolumio token set successfully
Feb 18 07:06:05 volumio volumio[13982]: info: MYVOLUMIO: Adding device
Feb 18 07:06:05 volumio volumio[13982]: info: MYVOLUMIO: Evaluating Server
Feb 18 07:06:05 volumio volumio[13982]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:05 volumio volumio[13982]: info: MyVolumio status changed
Feb 18 07:06:05 volumio volumio[13982]: info: Streaming services startup
Feb 18 07:06:05 volumio volumio[13982]: info: Starting Streaming Daemon
Feb 18 07:06:05 volumio volumio[13982]: info: Removing browser output: myVolumio user plan is not superstar
Feb 18 07:06:05 volumio volumio[13982]: info: Removing audio output:
Feb 18 07:06:05 volumio volumio[13982]: info: Stoppping Tunnel 1
Feb 18 07:06:06 volumio sudo[14390]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 18 07:06:06 volumio sudo[14390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:06 volumio sudo[14390]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:06 volumio sudo[14393]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 18 07:06:06 volumio sudo[14393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:06 volumio volumio[13982]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:06:06 volumio volumio[13982]: error: Cannot start Volumio Streaming Daemon
Feb 18 07:06:06 volumio volumio[13982]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 18 07:06:06 volumio volumio[13982]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 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.
Feb 18 07:06:06 volumio sudo[14393]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:06 volumio volumio[13982]: info: Remote SSH Stopped
Feb 18 07:06:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Feb 18 07:06:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:07 volumio go-librespot[14395]: go-librespot daemon starting...
Feb 18 07:06:07 volumio go-librespot[14396]: time="2026-02-18T07:06:07+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:07 volumio go-librespot[14396]: time="2026-02-18T07:06:07+07:00" level=debug msg="app state loaded"
Feb 18 07:06:07 volumio go-librespot[14396]: time="2026-02-18T07:06:07+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:07 volumio volumio[13982]: info: Setting Geolocation for MyVolumio to as1
Feb 18 07:06:07 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:07 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:07 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=info msg="zeroconf server listening on port 39977"
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="obtained new client token: AADyXdgUAx/GMb1R0EDtVH1jAzX6kCqW+Brn0LF5tg627b/p/8fO5Rn2PIt2BFAkLge3ZBl0ta/YIcKGQSQ+7NjiAkuA4EJ7VKD5zt+44QLEiPQVLGFLVYww1d67k/Ru9ktRV7vfMVfOO536TyJI+9cbPADIdrJ19xg6OtEL0AXwxfo2qYFdsySgzsx+vmde2Bj8kbOg1KyCgTarJQ5bvaGD5qxzfltVPToQrzVj902AycBmZOiZkf/IoQ=="
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:08 volumio volumio[13982]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=debug msg="completed challenge"
Feb 18 07:06:08 volumio go-librespot[14396]: time="2026-02-18T07:06:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:08 volumio volumio[13982]: info: Updating MyVolumio device info
Feb 18 07:06:08 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:08 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:08 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:09 volumio volumio[13982]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:09 volumio volumio[13982]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:06:09 volumio volumio[13982]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 18 07:06:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Feb 18 07:06:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:11 volumio go-librespot[14417]: go-librespot daemon starting...
Feb 18 07:06:11 volumio go-librespot[14418]: time="2026-02-18T07:06:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:11 volumio go-librespot[14418]: time="2026-02-18T07:06:11+07:00" level=debug msg="app state loaded"
Feb 18 07:06:11 volumio go-librespot[14418]: time="2026-02-18T07:06:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:12 volumio volumio[13982]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="new websocket client"
Feb 18 07:06:12 volumio volumio[13982]: info: Connection to go-librespot Websocket established
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=info msg="zeroconf server listening on port 36209"
Feb 18 07:06:12 volumio volumio[13982]: info: MYVOLUMIO: Adding device
Feb 18 07:06:12 volumio volumio[13982]: info: MYVOLUMIO: Evaluating Server
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="obtained new client token: AACKc/bSTI6wpV4A8/jf3rtS39o4H776f4N2r99e73MAeXDDK13fIumpRxTIM6DkFljgDSVy+Vps5+Kk0olKkaUVMx4MDWZZxAjyXMi0MzsX1JVEPZ6td2NVXZ31/dJ50zdcNkeLYbomerbuNcB+G5TnHQcyiKouReMrzUFT0GpyBpEDfy91oEZxVuGqLgSkm9uBxF/sxWLhIJnH5B3TXITCoBHzL2iT1AOJaLineK4aLUZQWUdstZFqdg=="
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:12 volumio go-librespot[14418]: time="2026-02-18T07:06:12+07:00" level=debug msg="completed challenge"
Feb 18 07:06:13 volumio go-librespot[14418]: time="2026-02-18T07:06:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:13 volumio volumio[13982]: info: Connection to go-librespot Websocket closed
Feb 18 07:06:13 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:06:13 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:13 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 18 07:06:14 volumio volumio-remote-updater[25144]: Test mode disabled
Feb 18 07:06:14 volumio volumio-remote-updater[25144]: Alpha mode disabled
Feb 18 07:06:14 volumio volumio-remote-updater[25144]: Alpha legacy test mode disabled
Feb 18 07:06:14 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 18 07:06:14 volumio volumio[13982]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 18 07:06:14 volumio volumio[13982]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 18 07:06:15 volumio volumio[13982]: info: Getting Spotify volume
Feb 18 07:06:15 volumio volumio[13982]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 07:06:15 volumio volumio[13982]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:06:15 volumio volumio[13982]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 18 07:06:15 volumio volumio[13982]:   errno: -111,
Feb 18 07:06:15 volumio volumio[13982]:   code: 'ECONNREFUSED',
Feb 18 07:06:15 volumio volumio[13982]:   syscall: 'connect',
Feb 18 07:06:15 volumio volumio[13982]:   address: '127.0.0.1',
Feb 18 07:06:15 volumio volumio[13982]:   port: 9879,
Feb 18 07:06:15 volumio volumio[13982]:   response: undefined
Feb 18 07:06:15 volumio volumio[13982]: }
Feb 18 07:06:15 volumio volumio[13982]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 07:06:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 18 07:06:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:16 volumio go-librespot[14461]: go-librespot daemon starting...
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=debug msg="app state loaded"
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:16 volumio sudo[14470]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 07:05'
Feb 18 07:06:16 volumio sudo[14470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:16 volumio sudo[14470]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:16 volumio go-librespot[14462]: time="2026-02-18T07:06:16+07:00" level=info msg="zeroconf server listening on port 45621"
Feb 18 07:06:17 volumio volumio-remote-updater[25144]: [2026-02-18 07:06:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 18 07:06:17 volumio volumio-remote-updater[25144]: [2026-02-18 07:06:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 18 07:06:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:17 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 18 07:06:17 volumio systemd[1]: volumio.service: Consumed 57.831s CPU time.
Feb 18 07:06:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 18 07:06:17 volumio go-librespot[14462]: time="2026-02-18T07:06:17+07:00" level=debug msg="obtained new client token: AAB0p2KGzZ3LSKBowYYuycIDQqtZIXLtt73EEEoErQ0GFmIVlML39O4/PIu6syJSBWAVJUPDP3aXm3VkucF70CuZZJ/Y6bEam7UtfQVuxPBcbTySKmm3oxh2neFLRGbPWDZ5nKl+n9hvFfJawqvl5vERk/2V48SKDu+p4niAFYLX6Z4Yb+UPO5AHP9o7IE7HIUIqNtAO0hVOr/12PAap21j8JTHarb7z1TMSXPI4rohBZ/4UuhL0oA8="
Feb 18 07:06:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 18 07:06:17 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21541.
Feb 18 07:06:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 18 07:06:17 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 18 07:06:17 volumio systemd[1]: volumio.service: Consumed 57.831s CPU time.
Feb 18 07:06:17 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 18 07:06:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 18 07:06:17 volumio go-librespot[14462]: time="2026-02-18T07:06:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:17 volumio go-librespot[14462]: time="2026-02-18T07:06:17+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:17 volumio go-librespot[14462]: time="2026-02-18T07:06:17+07:00" level=debug msg="completed challenge"
Feb 18 07:06:17 volumio go-librespot[14462]: time="2026-02-18T07:06:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Feb 18 07:06:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:20 volumio go-librespot[14506]: go-librespot daemon starting...
Feb 18 07:06:20 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:20 volumio volumio[14484]: info: -----            Volumio3              ----
Feb 18 07:06:20 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:20 volumio volumio[14484]: info: -----          System startup          ----
Feb 18 07:06:20 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:20 volumio go-librespot[14507]: time="2026-02-18T07:06:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:20 volumio go-librespot[14507]: time="2026-02-18T07:06:20+07:00" level=debug msg="app state loaded"
Feb 18 07:06:20 volumio go-librespot[14507]: time="2026-02-18T07:06:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=info msg="zeroconf server listening on port 45285"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="obtained new client token: AAC94jXUaZS9LSIdSZUZEJZMbB5F4R6vYn2CwTm7etwxIDqm+c+/UVO20XPUEqM8ipX037t8WjRJcXc4sJZcfotktEMhkF+NFZLirWrY+e4gZ87Xmwk1NzohoEsNau8V9Cbh1yvhj+goRed7SZAE9cI58DaZxYHhwh1Clmc+TLzvijty27KriFWbqllVr3y2QIAzK+4/E7uxZbtp+QDmsRemwZNyxnfgdLXaaWmdCdlTc1zBzDmIrZCKYQ=="
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:21 volumio go-librespot[14507]: time="2026-02-18T07:06:21+07:00" level=debug msg="completed challenge"
Feb 18 07:06:22 volumio go-librespot[14507]: time="2026-02-18T07:06:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:22 volumio volumio-remote-updater[25144]: [2026-02-18 07:06:22] [connect] Successful connection
Feb 18 07:06:22 volumio volumio[14484]: info: MYVOLUMIO Environment detected
Feb 18 07:06:22 volumio volumio[14484]: info: Plugin folders cleanup
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning into folder /volumio/app/plugins/
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category audio_interface
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category miscellanea
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category music_service
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category plugins.json
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category system_controller
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category user_interface
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning into folder /data/plugins/
Feb 18 07:06:22 volumio volumio[14484]: info: Scanning category music_service
Feb 18 07:06:22 volumio volumio[14484]: info: Plugin folders cleanup completed
Feb 18 07:06:22 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:22 volumio volumio[14484]: info: -----      Core plugins startup        ----
Feb 18 07:06:22 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:22 volumio volumio[14484]: info: Loading plugins from folder /volumio/app/plugins/
Feb 18 07:06:22 volumio volumio[14484]: info: Adding plugin upnp to MyMusic Plugins
Feb 18 07:06:22 volumio volumio[14484]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 18 07:06:22 volumio volumio[14484]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 18 07:06:22 volumio volumio[14484]: info: Loading plugins from folder /data/plugins/
Feb 18 07:06:22 volumio volumio[14484]: info: Loading plugin "system"...
Feb 18 07:06:22 volumio volumio[14484]: info: Loading plugin "appearance"...
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "network"...
Feb 18 07:06:24 volumio volumio[14484]: info: Refreshing Cached IP Addresses
Feb 18 07:06:24 volumio sudo[14521]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 18 07:06:24 volumio sudo[14521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "services"...
Feb 18 07:06:24 volumio sudo[14523]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 18 07:06:24 volumio sudo[14521]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:24 volumio sudo[14523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "alsa_controller"...
Feb 18 07:06:24 volumio sudo[14523]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:24 volumio sudo[14531]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 18 07:06:24 volumio sudo[14531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:24 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "wizard"...
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "networkfs"...
Feb 18 07:06:24 volumio volumio[14484]: info: Starting Udev Watcher for removable devices
Feb 18 07:06:24 volumio volumio[14484]: info: Ignoring mount for partition: boot
Feb 18 07:06:24 volumio volumio[14484]: info: Ignoring mount for partition: volumio
Feb 18 07:06:24 volumio volumio[14484]: info: Ignoring mount for partition: volumio_data
Feb 18 07:06:24 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "volumio_command_line_client"...
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "upnp"...
Feb 18 07:06:24 volumio volumio[14484]: info: [1771373184773] Starting Upmpd Daemon
Feb 18 07:06:24 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "my_music"...
Feb 18 07:06:24 volumio volumio[14484]: info: Loading plugin "mpd"...
Feb 18 07:06:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Feb 18 07:06:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:25 volumio go-librespot[14554]: go-librespot daemon starting...
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+07:00" level=debug msg="app state loaded"
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:25 volumio volumio[14484]: info: Loading plugin "upnp_browser"...
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+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]"
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+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]"
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+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]"
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+07:00" level=info msg="zeroconf server listening on port 33587"
Feb 18 07:06:25 volumio go-librespot[14555]: time="2026-02-18T07:06:25+07:00" level=debug msg="obtained new client token: AADQk+cVbQE2bzKVeaTo97foWv6tjVy2c44QgaFG3//h1/IIR33k+Q9+zVykj7E0/ypeNj7DJa7AK7RGve4sohaqMG2uq4y1JMzrlfATA3S0mREGG7D94lD0lhS/zG8pzPmc0fotLcgvsJ9vDY9TnbSca+txDU63oVq0qFRPoYh3ZLGHmF0OkeQIOBlcV6QpkNXtlihZdLlu7DtT7JaNfxys5X9XLaybci7nhe4Dgbbw4AFqzLkH+mEd7Q=="
Feb 18 07:06:26 volumio go-librespot[14555]: time="2026-02-18T07:06:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:26 volumio go-librespot[14555]: time="2026-02-18T07:06:26+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:26 volumio go-librespot[14555]: time="2026-02-18T07:06:26+07:00" level=debug msg="completed challenge"
Feb 18 07:06:26 volumio go-librespot[14555]: time="2026-02-18T07:06:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:27 volumio sudo[14531]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:28 volumio volumio[14484]: info: Starting UPNP Browser
Feb 18 07:06:28 volumio volumio[14484]: info: Loading plugin "alarm-clock"...
Feb 18 07:06:28 volumio volumio[14484]: info: Loading plugin "airplay_emulation"...
Feb 18 07:06:28 volumio volumio[14484]: info: Starting Shairport Sync
Feb 18 07:06:28 volumio volumio[14484]: info: Loading plugin "last_100"...
Feb 18 07:06:28 volumio volumio[14484]: info: Loading plugin "webradio"...
Feb 18 07:06:28 volumio volumio[14484]: info: Loading plugin "i2s_dacs"...
Feb 18 07:06:28 volumio volumio[14484]: info: Loading plugin "volumiodiscovery"...
Feb 18 07:06:28 volumio volumio[14484]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:06:28 volumio volumio[14484]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:06:28 volumio node[14484]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:06:28 volumio volumio[14484]: *** WARNING *** For more information see 
Feb 18 07:06:28 volumio volumio[14484]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:06:28 volumio volumio[14484]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:06:28 volumio volumio[14484]: *** WARNING *** For more information see 
Feb 18 07:06:28 volumio node[14484]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:06:28 volumio node[14484]: *** WARNING *** For more information see 
Feb 18 07:06:28 volumio node[14484]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:06:28 volumio node[14484]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:06:28 volumio node[14484]: *** WARNING *** For more information see 
Feb 18 07:06:28 volumio volumio[14484]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 18 07:06:28 volumio volumio[14484]: info: Discovery: Started advertising with name: Volumio
Feb 18 07:06:29 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 18 07:06:29 volumio volumio[14484]: info: Loading plugin "spop"...
Feb 18 07:06:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 18 07:06:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:29 volumio go-librespot[14564]: go-librespot daemon starting...
Feb 18 07:06:29 volumio go-librespot[14565]: time="2026-02-18T07:06:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:29 volumio go-librespot[14565]: time="2026-02-18T07:06:29+07:00" level=debug msg="app state loaded"
Feb 18 07:06:29 volumio go-librespot[14565]: time="2026-02-18T07:06:29+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=info msg="zeroconf server listening on port 32883"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=debug msg="obtained new client token: AAClzqj7lq3K+z8YXZR5gr+ra7UiDcs7LPSaGRvYTwdCJLHSz/x8mR/AgohUsSa62OLKgAJ3l700gy7hoXJRBoaApWFWiwrWr3idNi7y9fN7WHIjMgwVhnFgUO2WDf4gtH4AujsnqaKHSVdt6NRqn9zhn7uTTubi/HSZOwlhteQ+BvkIvyevo7TUjMXpEfdyEGbYw3Z2g3fK6+RWL+FhlsJCQAIaLVh8ZBHKshMcPQ8fJJYh8U1gvDU="
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=debug msg="completed challenge"
Feb 18 07:06:30 volumio go-librespot[14565]: time="2026-02-18T07:06:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:30 volumio volumio[14484]: info: Loading plugin "ytcr"...
Feb 18 07:06:33 volumio volumio[14484]: info: Loading plugin "ytmusic"...
Feb 18 07:06:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Feb 18 07:06:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:33 volumio go-librespot[14572]: go-librespot daemon starting...
Feb 18 07:06:33 volumio go-librespot[14573]: time="2026-02-18T07:06:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:33 volumio go-librespot[14573]: time="2026-02-18T07:06:33+07:00" level=debug msg="app state loaded"
Feb 18 07:06:33 volumio go-librespot[14573]: time="2026-02-18T07:06:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=info msg="zeroconf server listening on port 33269"
Feb 18 07:06:34 volumio volumio-remote-updater[25144]: [2026-02-18 07:06:34] [connect] Successful connection
Feb 18 07:06:34 volumio volumio[14484]: info: Loading plugin "outputs"...
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=debug msg="obtained new client token: AABg86C42tclu3lLn++iFEs6DWzJmYERbIfvVracJCS7YNHpQw4qd+zJ/Le63LtQfZcg/VTYX9AYyobb96WLVt0K47LKcmulW+NBYiw5xsRMb5uICoCCB6ukOCuRaxeHMwG5FqBMwUt2ROqML7pG+kuyWPzXd9EyNRQJixHkip6wHV5o4G/3f/ioep5C2J3tEzVV9LT5igdw1uQ5DhJXTUgYSpcmuPV+jKRYT6fj0BvAFGNf/BRSTtC8og=="
Feb 18 07:06:34 volumio volumio[14484]: info: Loading plugin "albumart"...
Feb 18 07:06:34 volumio volumio[14484]: info: Plugin example_plugin is not enabled
Feb 18 07:06:34 volumio volumio[14484]: info: Loading plugin "inputs"...
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 18 07:06:34 volumio volumio[14484]: info: Loading plugin "updater_comm"...
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused"
Feb 18 07:06:34 volumio go-librespot[14573]: time="2026-02-18T07:06:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Feb 18 07:06:35 volumio volumio[14484]: info: Plugin mpdemulation is not enabled
Feb 18 07:06:35 volumio volumio[14484]: info: Loading plugin "rest_api"...
Feb 18 07:06:35 volumio volumio[14484]: info: Loading plugin "websocket"...
Feb 18 07:06:35 volumio go-librespot[14573]: time="2026-02-18T07:06:35+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:35 volumio go-librespot[14573]: time="2026-02-18T07:06:35+07:00" level=debug msg="completed challenge"
Feb 18 07:06:35 volumio volumio[14484]: info: Starting Socket.io Server version 1.7.4
Feb 18 07:06:35 volumio volumio[14484]: info: Loading plugin "RoonBridge"...
Feb 18 07:06:35 volumio go-librespot[14573]: time="2026-02-18T07:06:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:35 volumio volumio[14484]: info: Applying required configuration parameters for plugin RoonBridge
Feb 18 07:06:35 volumio volumio[14484]: info: Loading i18n strings for locale en
Feb 18 07:06:35 volumio volumio[14484]: Updating browse sources language
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::initPlayerControls
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 18 07:06:35 volumio volumio[14484]: Express server listening on port 3000
Feb 18 07:06:35 volumio volumio[14484]:  [Metrics]  WebUI:  15s 930.23ms 
Feb 18 07:06:35 volumio volumio[14594]: Forking 3 albumart workers
Feb 18 07:06:35 volumio volumio[14484]: info: CoreStateMachine::resetVolumioState
Feb 18 07:06:35 volumio volumio[14484]: info: CoreStateMachine::getcurrentVolume
Feb 18 07:06:35 volumio volumio[14484]: info: CoreCommandRouter::volumioRetrievevolume
Feb 18 07:06:36 volumio sudo[14620]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 18 07:06:36 volumio sudo[14620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:36 volumio sudo[14620]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:36 volumio sudo[14634]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 18 07:06:36 volumio sudo[14634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:36 volumio sudo[14634]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:36 volumio volumio[14484]: info: Volumio Network Manager: Network status updated: 1
Feb 18 07:06:36 volumio volumio[14484]: info: VolumeController:: Volume=100 Mute =false
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::pushState
Feb 18 07:06:36 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::volumioPushState
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::updateTrackBlock
Feb 18 07:06:36 volumio volumio[14484]: info: CorePlayQueue::getTrackBlock
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::volumioRetrievevolume
Feb 18 07:06:36 volumio volumio-remote-updater[25144]: [2026-02-18 07:06:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771373194 101
Feb 18 07:06:36 volumio volumio[14484]: 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: 1
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:36 volumio volumio[14484]: info: Reloading queue from file
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::setRepeat null single undefined
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::pushState
Feb 18 07:06:36 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::volumioPushState
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::setRandom null
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::pushState
Feb 18 07:06:36 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::volumioPushState
Feb 18 07:06:36 volumio volumio[14484]: info: Setting Device type: Raspberry PI
Feb 18 07:06:36 volumio volumio[14484]: info: Completed loading Core Plugins
Feb 18 07:06:36 volumio volumio[14484]: info: Preparing to generate the ALSA configuration file
Feb 18 07:06:36 volumio volumio[14484]: info: VolumeController:: Volume=100 Mute =false
Feb 18 07:06:36 volumio volumio[14484]: info: CoreStateMachine::pushState
Feb 18 07:06:36 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:36 volumio volumio[14484]: info: CoreCommandRouter::volumioPushState
Feb 18 07:06:36 volumio volumio[14484]: info: Asound.conf file unchanged, so no further update is needed
Feb 18 07:06:36 volumio volumio[14484]: info: Output device has changed, restarting MPD
Feb 18 07:06:37 volumio sudo[14655]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 18 07:06:37 volumio sudo[14655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:37 volumio volumio[14484]: info: Output device has changed, restarting Shairport Sync
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:37 volumio sudo[14657]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 18 07:06:37 volumio sudo[14657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:37 volumio sudo[14657]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:37 volumio sudo[14660]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 18 07:06:37 volumio sudo[14660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:37 volumio sudo[14655]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:37 volumio volumio[14484]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 18 07:06:37 volumio volumio[14484]: info: ___________ START PLUGINS ___________
Feb 18 07:06:37 volumio volumio[14484]: info: ControllerMpd::onStart: Initializing MPD
Feb 18 07:06:37 volumio volumio[14484]: info: Creating MPD Configuration file
Feb 18 07:06:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:06:37 volumio volumio[14484]: info: [1771373197331] CoreMusicLibrary::Adding element Media Servers
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:06:37 volumio sudo[14668]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 18 07:06:37 volumio volumio[14484]: info: UPNP Browser: Client initialized successfully
Feb 18 07:06:37 volumio sudo[14668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:37 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 18 07:06:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 18 07:06:37 volumio systemd[1]: mpd.service: Consumed 7.206s CPU time.
Feb 18 07:06:37 volumio sudo[14668]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:37 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 18 07:06:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 18 07:06:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 18 07:06:37 volumio sudo[14670]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 18 07:06:37 volumio sudo[14670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 18 07:06:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 18 07:06:37 volumio volumio[14484]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:37 volumio volumio[14484]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 18 07:06:37 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 18 07:06:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:06:37 volumio volumio[14484]: info: [1771373197724] CoreMusicLibrary::Adding element Last_100
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:06:37 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 18 07:06:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 18 07:06:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:06:37 volumio volumio[14484]: info: [1771373197747] CoreMusicLibrary::Adding element Webradio
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:06:37 volumio volumio[14484]: info: Initializing BBC Radios
Feb 18 07:06:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 18 07:06:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:06:37 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:38 volumio volumio[14484]: info: Creating Spotify config file
Feb 18 07:06:38 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Feb 18 07:06:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:38 volumio sudo[14692]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 18 07:06:38 volumio sudo[14692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 18 07:06:38 volumio sudo[14692]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:38 volumio go-librespot[14698]: go-librespot daemon starting...
Feb 18 07:06:38 volumio go-librespot[14700]: time="2026-02-18T07:06:38+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:38 volumio volumio[14607]: Starting albumart workers
Feb 18 07:06:39 volumio go-librespot[14700]: time="2026-02-18T07:06:39+07:00" level=info msg="zeroconf server listening on port 37463"
Feb 18 07:06:39 volumio volumio[14484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:06:39 volumio volumio[14484]: info: [1771373199332] CoreMusicLibrary::Adding element YouTube Music
Feb 18 07:06:39 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:06:39 volumio volumio[14484]: Cannot find translation for source YouTube Music
Feb 18 07:06:39 volumio volumio[14484]: info: Volumio Calling Home
Feb 18 07:06:39 volumio sudo[14710]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 18 07:06:39 volumio sudo[14710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:39 volumio volumio[14608]: Starting albumart workers
Feb 18 07:06:39 volumio volumio[14609]: Starting albumart workers
Feb 18 07:06:39 volumio sudo[14710]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:40 volumio volumio[14484]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 18 07:06:40 volumio volumio[14484]: info: Discovery: Found device Volumio
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::volumioGetState
Feb 18 07:06:40 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:40 volumio volumio[14484]: info: MPD Permissions set
Feb 18 07:06:40 volumio volumio[14484]: info: MPD Permissions set
Feb 18 07:06:40 volumio volumio[14484]: info: Upmpdcli Daemon Started
Feb 18 07:06:40 volumio volumio[14484]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 18 07:06:40 volumio volumio[14484]: info: Discovery: Found device Volumio
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::volumioGetState
Feb 18 07:06:40 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:40 volumio volumio[14484]: info: Spotify config file written
Feb 18 07:06:40 volumio volumio[14484]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio sudo[14716]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 18 07:06:40 volumio sudo[14716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 18 07:06:40 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 18 07:06:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:40 volumio go-librespot[14723]: go-librespot daemon starting...
Feb 18 07:06:40 volumio sudo[14716]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:40 volumio go-librespot[14726]: time="2026-02-18T07:06:40+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:40 volumio go-librespot[14726]: time="2026-02-18T07:06:40+07:00" level=debug msg="app state loaded"
Feb 18 07:06:40 volumio go-librespot[14726]: time="2026-02-18T07:06:40+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:40 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:06:41 volumio volumio[14484]: info: No need to fix Spotify hosts
Feb 18 07:06:41 volumio go-librespot[14726]: time="2026-02-18T07:06:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:41 volumio go-librespot[14726]: time="2026-02-18T07:06:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:41 volumio go-librespot[14726]: time="2026-02-18T07:06:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:41 volumio go-librespot[14726]: time="2026-02-18T07:06:41+07:00" level=info msg="zeroconf server listening on port 37575"
Feb 18 07:06:41 volumio volumio[14484]: info: Volumio called home
Feb 18 07:06:41 volumio go-librespot[14726]: time="2026-02-18T07:06:41+07:00" level=debug msg="obtained new client token: AABkRRruyJMVrCqVqQkuzClSpANg66FGSpyO90EDFrMg5opARqla5GVmHJl/gN3T2z6CoVFeCWZdBlPJ8qPrTj2non0NMQ6pt8WXpAuxyspnrX70Ywo15jdOEPVUZ13H7xMPAUINsnPH0juzYhDyD7TcvcQpDEzJ3/IRmyPyckkpcmKrvYEV8E6qPDMjkuXlUR6ZZErEwU4RjwrmVa7O97/wFHPRXTSf+rHzgbHuztS2UApMs0tCbvWzKw=="
Feb 18 07:06:42 volumio go-librespot[14726]: time="2026-02-18T07:06:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:42 volumio go-librespot[14726]: time="2026-02-18T07:06:42+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:42 volumio go-librespot[14726]: time="2026-02-18T07:06:42+07:00" level=debug msg="completed challenge"
Feb 18 07:06:42 volumio volumio[14484]: info: Starting Shairport Sync
Feb 18 07:06:42 volumio volumio[14484]: info: Starting Shairport Sync
Feb 18 07:06:42 volumio volumio[14484]: info: Starting Shairport Sync
Feb 18 07:06:42 volumio go-librespot[14726]: time="2026-02-18T07:06:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:42 volumio sudo[14756]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 18 07:06:42 volumio sudo[14756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:42 volumio sudo[14758]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 18 07:06:42 volumio sudo[14758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:42 volumio sudo[14760]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 18 07:06:42 volumio sudo[14760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 18 07:06:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 18 07:06:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:06:42 volumio systemd[1]: shairport-sync.service: Consumed 2.376s CPU time.
Feb 18 07:06:42 volumio volumio[14484]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 18 07:06:42 volumio volumio[14484]: SPOTIFY: BQCF-UKespvWMucdAupy5Onuel9K8TsrBSqy5HqL78wyLzLbUIzYNIw8s_azeeJ6OibhFVJs1Qd2IpQ6MlDUaCarAiVXvgniA8mu4c3-jntXJ8RYbfWt-U7VPhRWHEIhlPAP0zJ16_r6DC-bFkv0ftLQRznlyuTD3DU4WynUpHcp8wAmt0QEqao332-bAI4er67VOizPg1_2RsD2Qdn3xXavVWMzjpA5GEQiAfTcce-5Jsvbcw8bsheiEEYGHECMDSEQrOyKHkYq2A8GUGnYgU-erw0lyJ5Gb20DzncyCxjjOmFMg70uHoAd
Feb 18 07:06:42 volumio volumio[14484]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 18 07:06:42 volumio volumio[14484]: info: New Spotify access token = BQCF-UKespvWMucdAupy5Onuel9K8TsrBSqy5HqL78wyLzLbUIzYNIw8s_azeeJ6OibhFVJs1Qd2IpQ6MlDUaCarAiVXvgniA8mu4c3-jntXJ8RYbfWt-U7VPhRWHEIhlPAP0zJ16_r6DC-bFkv0ftLQRznlyuTD3DU4WynUpHcp8wAmt0QEqao332-bAI4er67VOizPg1_2RsD2Qdn3xXavVWMzjpA5GEQiAfTcce-5Jsvbcw8bsheiEEYGHECMDSEQrOyKHkYq2A8GUGnYgU-erw0lyJ5Gb20DzncyCxjjOmFMg70uHoAd
Feb 18 07:06:42 volumio volumio[14484]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 18 07:06:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:06:42 volumio sudo[14756]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:42 volumio sudo[14760]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:42 volumio volumio[14484]: info: CoreCommandRouter::volumioGetState
Feb 18 07:06:42 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 18 07:06:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 18 07:06:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:06:42 volumio volumio[14484]: info: Shairport-Sync Started
Feb 18 07:06:42 volumio volumio[14484]: Error adding Membership: Error: addMembership EINVAL
Feb 18 07:06:42 volumio volumio[14484]: info: Shairport-Sync Started
Feb 18 07:06:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:06:42 volumio sudo[14758]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:42 volumio volumio[14484]: info: Shairport-Sync Started
Feb 18 07:06:43 volumio volumio[14484]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"}
Feb 18 07:06:43 volumio volumio[14484]: info: Spotify Successfully logged in
Feb 18 07:06:43 volumio volumio[14484]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:06:43 volumio volumio[14484]: info: [1771373203098] CoreMusicLibrary::Adding element Spotify
Feb 18 07:06:43 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:06:43 volumio volumio[14484]: Cannot find translation for source YouTube Music
Feb 18 07:06:43 volumio volumio[14484]: Cannot find translation for source Spotify
Feb 18 07:06:44 volumio volumio[14484]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 18 07:06:44 volumio volumio[14484]: info: CoreCommandRouter::volumioRetrievevolume
Feb 18 07:06:44 volumio volumio[14484]: info: VolumeController:: Volume=100 Mute =false
Feb 18 07:06:44 volumio volumio[14484]: info: CoreCommandRouter::volumioGetState
Feb 18 07:06:44 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:44 volumio volumio[14484]: info: CoreStateMachine::pushState
Feb 18 07:06:44 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:44 volumio volumio[14484]: info: CoreCommandRouter::volumioPushState
Feb 18 07:06:45 volumio volumio[14484]: info: go-librespot daemon successfully initialized
Feb 18 07:06:45 volumio mpd[14705]: 2026-02-18T07:06:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 18 07:06:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 18 07:06:45 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 18 07:06:45 volumio sudo[14660]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:45 volumio sudo[14670]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:45 volumio go-librespot[14801]: go-librespot daemon starting...
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+07:00" level=debug msg="app state loaded"
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:45 volumio volumio[14484]: error: MPD error: The expression evaluated to a falsy value:
Feb 18 07:06:45 volumio volumio[14484]:   assert.ok(self.idling)
Feb 18 07:06:45 volumio volumio[14484]: error: The expression evaluated to a falsy value:
Feb 18 07:06:45 volumio volumio[14484]:   assert.ok(self.idling)
Feb 18 07:06:45 volumio volumio[14484]: info: MPD running with PID14705
Feb 18 07:06:45 volumio volumio[14484]:  ,establishing connection
Feb 18 07:06:45 volumio volumio[14484]: error: updateQueue error: null
Feb 18 07:06:45 volumio volumio[14484]: info: Completed starting Core Plugins
Feb 18 07:06:45 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:45 volumio volumio[14484]: info: -----    MyVolumio plugins startup     ----
Feb 18 07:06:45 volumio volumio[14484]: info: -------------------------------------------
Feb 18 07:06:45 volumio volumio[14484]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 18 07:06:45 volumio volumio[14484]: error: updateQueue error: null
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 18 07:06:45 volumio go-librespot[14802]: time="2026-02-18T07:06:45+07:00" level=info msg="zeroconf server listening on port 34291"
Feb 18 07:06:46 volumio go-librespot[14802]: time="2026-02-18T07:06:46+07:00" level=debug msg="obtained new client token: AACIpxur+yG6oqitf4RSbUsqwxdgKppGWiwoTmBLAOIwPbXU8sK/BjISnNPOuxwKN2SHNnFPVeHw6U4sc1MXWvZyIe7+vzaxK4braKHsbiu8SH3U9ROXgpv2ugmBoFHRlyQtklo6ObL9XIP5R65HFnL8PIRR+qdqmnNObw0ShZce6zn4mcWRX6HPTXMeUY6SV22nr1lZy1p25spTEolL0TtPD0ylISM+TwG2Qotm2HGYR3iLrqoN8J0="
Feb 18 07:06:46 volumio go-librespot[14802]: time="2026-02-18T07:06:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:46 volumio go-librespot[14802]: time="2026-02-18T07:06:46+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:46 volumio go-librespot[14802]: time="2026-02-18T07:06:46+07:00" level=debug msg="completed challenge"
Feb 18 07:06:46 volumio go-librespot[14802]: time="2026-02-18T07:06:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:48 volumio volumio[14484]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:48 volumio volumio[14484]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:06:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 18 07:06:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:49 volumio go-librespot[14809]: go-librespot daemon starting...
Feb 18 07:06:49 volumio go-librespot[14810]: time="2026-02-18T07:06:49+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:49 volumio go-librespot[14810]: time="2026-02-18T07:06:49+07:00" level=debug msg="app state loaded"
Feb 18 07:06:49 volumio go-librespot[14810]: time="2026-02-18T07:06:49+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+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]"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+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]"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+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]"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+07:00" level=info msg="zeroconf server listening on port 46455"
Feb 18 07:06:50 volumio volumio[14484]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+07:00" level=debug msg="obtained new client token: AABTX6RHuKynHTOT1KoOHoVtP/GVgLYJ3gH0AVRxSbvo0dzCIuGGQG8SIBC9spwpWg9FEELqUAZSCj9PlyaR6i6m5FXuXX7Y3mY/azQEXEfR33gi6/UC5Yx6o4xxWz3m8yw7DVC71blYR8EJRa1e2gC43K490mHPXYhn1q+6w90sbl45efBW7QVVillAe3O1Ua5m2KmSEWrpymN6wpy9FvFdwdUmFEkTBJGOX0ti9rroWUJVmMGaBVmZ0w=="
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+07:00" level=debug msg="completed challenge"
Feb 18 07:06:50 volumio go-librespot[14810]: time="2026-02-18T07:06:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:51 volumio volumio[14484]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:51 volumio volumio[14484]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:06:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 18 07:06:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:53 volumio go-librespot[14817]: go-librespot daemon starting...
Feb 18 07:06:53 volumio go-librespot[14818]: time="2026-02-18T07:06:53+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:53 volumio go-librespot[14818]: time="2026-02-18T07:06:53+07:00" level=debug msg="app state loaded"
Feb 18 07:06:53 volumio go-librespot[14818]: time="2026-02-18T07:06:53+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:54 volumio volumio[14484]: info: Initializing connection to go-librespot Websocket
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="new websocket client"
Feb 18 07:06:54 volumio volumio[14484]: info: Connection to go-librespot Websocket established
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin multiroom to MyMusic Plugins
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 18 07:06:54 volumio volumio[14484]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 18 07:06:54 volumio volumio[14484]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=info msg="zeroconf server listening on port 46871"
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="obtained new client token: AADgWs5JtCHNCHNhdFP31lxSXwdAs2Omo3OdRxuTvskFLRTyWTTzRrJEZJPiw4m4TnOV6Ag2dXVcVQ3GDNi/ELvZFu6VJjeVwMsDiEqlVWPHMZ5GoEH7nSdNOkZRDneE3bb8FDyci39qmscY0PSkY6CAthJrPFOsy3br5q6mp0DOE2ffLU3Gj2keL2KL0pcjAbYGeNMXma0Ky8uzV43fAvR6IDJdPBTQXvq3vNIHW0z55xp4niAug70dCA=="
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=debug msg="completed challenge"
Feb 18 07:06:54 volumio go-librespot[14818]: time="2026-02-18T07:06:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:56 volumio volumio[14484]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 18 07:06:56 volumio volumio[14484]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 18 07:06:56 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:56 volumio volumio[14484]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:06:56 volumio volumio[14484]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 18 07:06:56 volumio volumio[14484]: info: MyVolumio login type: Token
Feb 18 07:06:56 volumio volumio[14484]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 18 07:06:56 volumio volumio[14484]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 18 07:06:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 18 07:06:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:58 volumio volumio[14484]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 18 07:06:58 volumio volumio[14484]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 18 07:06:58 volumio volumio[14484]: info: Streaming services startup
Feb 18 07:06:58 volumio volumio[14484]: info: Starting Streaming Daemon
Feb 18 07:06:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:06:58 volumio go-librespot[14840]: go-librespot daemon starting...
Feb 18 07:06:58 volumio sudo[14842]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 18 07:06:58 volumio sudo[14842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:06:58 volumio volumio[14484]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=debug msg="app state loaded"
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:06:58 volumio sudo[14842]: pam_unix(sudo:session): session closed for user root
Feb 18 07:06:58 volumio volumio[14484]: info: Getting Spotify volume
Feb 18 07:06:58 volumio volumio[14484]: info: Connection to go-librespot Websocket closed
Feb 18 07:06:58 volumio volumio[14484]: error: Cannot start Volumio Streaming Daemon
Feb 18 07:06:58 volumio volumio[14484]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 18 07:06:58 volumio volumio[14484]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 18 07:06:58 volumio volumio[14484]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 18 07:06:58 volumio volumio[14484]: info: CoreCommandRouter::volumioGetState
Feb 18 07:06:58 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:58 volumio volumio[14484]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 18 07:06:58 volumio volumio[14484]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 18 07:06:58 volumio volumio[14484]: SPOTIFY: VOLUMIO VOLUME 100
Feb 18 07:06:58 volumio volumio[14484]: info: Aligning Spotify Volume to Volumio Volume
Feb 18 07:06:58 volumio volumio[14484]: info: CoreCommandRouter::volumioGetState
Feb 18 07:06:58 volumio volumio[14484]: info: CorePlayQueue::getTrack 0
Feb 18 07:06:58 volumio volumio[14484]: info: Setting Spotify Volume from Volumio: 100
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:06:58 volumio go-librespot[14843]: time="2026-02-18T07:06:58+07:00" level=info msg="zeroconf server listening on port 33511"
Feb 18 07:06:59 volumio go-librespot[14843]: time="2026-02-18T07:06:59+07:00" level=debug msg="obtained new client token: AAAuzN76U4kYLEWu5HzsdnNHxgPiHIQhFjcKIhxMZ8Np+cmMMIXjQFJ42DyQ0e0koJOqENEfAe7Ys0Y7bXfFSWWO6SF8MZbR8FoIPzPtioQW95qODKahpkt7GgIVRGjGPvGNr8/CTfgONdG+IjdWq431jvxltYxkJ8jujk0sABOnjar3s2G6ddSYT8VAvXDvI/epNa483xgFJqEoYbkA0Z4ZOJTIRDzpP9WvbMu3K4Ua7QYor6HoUFcrww=="
Feb 18 07:06:59 volumio go-librespot[14843]: time="2026-02-18T07:06:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:06:59 volumio go-librespot[14843]: time="2026-02-18T07:06:59+07:00" level=debug msg="completed keyexchange"
Feb 18 07:06:59 volumio go-librespot[14843]: time="2026-02-18T07:06:59+07:00" level=debug msg="completed challenge"
Feb 18 07:06:59 volumio go-librespot[14843]: time="2026-02-18T07:06:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:06:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:06:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:06:59 volumio volumio[14484]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 07:06:59 volumio volumio[14484]: Error: socket hang up
Feb 18 07:06:59 volumio volumio[14484]:     at connResetException (node:internal/errors:720:14)
Feb 18 07:06:59 volumio volumio[14484]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 18 07:06:59 volumio volumio[14484]:     at Socket.emit (node:events:526:35)
Feb 18 07:06:59 volumio volumio[14484]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 18 07:06:59 volumio volumio[14484]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 18 07:06:59 volumio volumio[14484]:   code: 'ECONNRESET',
Feb 18 07:06:59 volumio volumio[14484]:   response: undefined
Feb 18 07:06:59 volumio volumio[14484]: }
Feb 18 07:06:59 volumio volumio[14484]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 07:07:00 volumio sudo[14873]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 07:06'
Feb 18 07:07:00 volumio sudo[14873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:01 volumio sudo[14873]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:02 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:02] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 18 07:07:02 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:02] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 18 07:07:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 18 07:07:02 volumio systemd[1]: volumio.service: Consumed 55.390s CPU time.
Feb 18 07:07:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 18 07:07:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 18 07:07:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21542.
Feb 18 07:07:02 volumio go-librespot[14884]: go-librespot daemon starting...
Feb 18 07:07:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 18 07:07:02 volumio systemd[1]: volumio.service: Consumed 55.390s CPU time.
Feb 18 07:07:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 18 07:07:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 18 07:07:02 volumio go-librespot[14888]: time="2026-02-18T07:07:02+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:02 volumio go-librespot[14888]: time="2026-02-18T07:07:02+07:00" level=debug msg="app state loaded"
Feb 18 07:07:02 volumio go-librespot[14888]: time="2026-02-18T07:07:02+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=info msg="zeroconf server listening on port 41565"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="obtained new client token: AAB0U+3afhhPVvGA2endu0IZRslEpLd4E21/RjgBuDOcgyTyP8dIoN0GXMEZZmWkVFwNSIptJBp0BDgN93mLp6wi4nxijz6bMI3AZzWwgHlksZYGU1pLL1zusXT+Nv4fNRKVWM0RS8SzpAFj7YBQwFKhZePAeKSxyG+1SfhDLEymyK/GF6dhLfZ1M2XT2eg/L122cxyOJfo7V0XcQrdmf8H624h6NzDp+UPymL/cb5ueoqxD58F+wKo="
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=debug msg="completed challenge"
Feb 18 07:07:03 volumio go-librespot[14888]: time="2026-02-18T07:07:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:06 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:06 volumio volumio[14889]: info: -----            Volumio3              ----
Feb 18 07:07:06 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:06 volumio volumio[14889]: info: -----          System startup          ----
Feb 18 07:07:06 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 18 07:07:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:06 volumio go-librespot[14912]: go-librespot daemon starting...
Feb 18 07:07:06 volumio go-librespot[14913]: time="2026-02-18T07:07:06+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:06 volumio go-librespot[14913]: time="2026-02-18T07:07:06+07:00" level=debug msg="app state loaded"
Feb 18 07:07:06 volumio go-librespot[14913]: time="2026-02-18T07:07:06+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:07 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:07] [connect] Successful connection
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+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]"
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+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]"
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+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]"
Feb 18 07:07:07 volumio volumio[14889]: info: MYVOLUMIO Environment detected
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=info msg="zeroconf server listening on port 41471"
Feb 18 07:07:07 volumio volumio[14889]: info: Plugin folders cleanup
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning into folder /volumio/app/plugins/
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category audio_interface
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category miscellanea
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category music_service
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category plugins.json
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category system_controller
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category user_interface
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning into folder /data/plugins/
Feb 18 07:07:07 volumio volumio[14889]: info: Scanning category music_service
Feb 18 07:07:07 volumio volumio[14889]: info: Plugin folders cleanup completed
Feb 18 07:07:07 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:07 volumio volumio[14889]: info: -----      Core plugins startup        ----
Feb 18 07:07:07 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugins from folder /volumio/app/plugins/
Feb 18 07:07:07 volumio volumio[14889]: info: Adding plugin upnp to MyMusic Plugins
Feb 18 07:07:07 volumio volumio[14889]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 18 07:07:07 volumio volumio[14889]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugins from folder /data/plugins/
Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugin "system"...
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="obtained new client token: AADe4jcl22zsIiSsideXiqOmVuqzWEy8DD41oJTlh0P0ZRpFm/pAijRlOgKCFYTGBQBVSkls5rwGRLyTQS26OLug0SNptW/KF02ekLG2J06bNbuUex2sjSRSykNK0YlWt4BNL8SFRaYV+pAlCO2P3d1tC1hDh/Fv4YC9zPXYE32pKA7BPiknbSGfz8Rids3XKhnA2WrdyO/wlOBqs6MXVVnVsX7We8n3XiaTEmCdqyQe0hRKktyaw+DcDA=="
Feb 18 07:07:07 volumio volumio[14889]: info: Loading plugin "appearance"...
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=debug msg="completed challenge"
Feb 18 07:07:07 volumio go-librespot[14913]: time="2026-02-18T07:07:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "network"...
Feb 18 07:07:09 volumio volumio[14889]: info: Refreshing Cached IP Addresses
Feb 18 07:07:09 volumio sudo[14928]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 18 07:07:09 volumio sudo[14928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:09 volumio sudo[14930]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 18 07:07:09 volumio sudo[14930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:09 volumio sudo[14928]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "services"...
Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "alsa_controller"...
Feb 18 07:07:09 volumio sudo[14930]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:09 volumio sudo[14937]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 18 07:07:09 volumio sudo[14937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:09 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "wizard"...
Feb 18 07:07:09 volumio volumio[14889]: info: Loading plugin "networkfs"...
Feb 18 07:07:09 volumio volumio[14889]: info: Starting Udev Watcher for removable devices
Feb 18 07:07:10 volumio volumio[14889]: info: Ignoring mount for partition: boot
Feb 18 07:07:10 volumio volumio[14889]: info: Ignoring mount for partition: volumio
Feb 18 07:07:10 volumio volumio[14889]: info: Ignoring mount for partition: volumio_data
Feb 18 07:07:10 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "volumio_command_line_client"...
Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "upnp"...
Feb 18 07:07:10 volumio volumio[14889]: info: [1771373230055] Starting Upmpd Daemon
Feb 18 07:07:10 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "my_music"...
Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "mpd"...
Feb 18 07:07:10 volumio volumio[14889]: info: Loading plugin "upnp_browser"...
Feb 18 07:07:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 18 07:07:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:11 volumio go-librespot[14961]: go-librespot daemon starting...
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="app state loaded"
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:11 volumio go-librespot[14962]: time="2026-02-18T07:07:11+07:00" level=info msg="zeroconf server listening on port 38667"
Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="obtained new client token: AADX335wEjiYoqLLKkdACCeymUTrSrGC4kq1hhi46DKnmw+JO3QY80jmAGUj+wxWFzd+aCZOUM+rhedH6UCZtmKiuMBY70sJJQC+O8/+8oC2iM95jYyJmdYmxn0aMkTfNTMAlS0SI6OwnTGNADR4uIZ2xpi7wrcnuVT1qW71cqsIWm2dARyZ8PdJstbi2I2ceDCm9tjFN4GAmoLW5NnueC7ORlHN59ENee3b8KZdCJtI1iRjb0cHoVTAlw=="
Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=debug msg="completed challenge"
Feb 18 07:07:12 volumio go-librespot[14962]: time="2026-02-18T07:07:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:12 volumio sudo[14937]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:13 volumio volumio[14889]: info: Starting UPNP Browser
Feb 18 07:07:13 volumio volumio[14889]: info: Loading plugin "alarm-clock"...
Feb 18 07:07:13 volumio volumio[14889]: info: Loading plugin "airplay_emulation"...
Feb 18 07:07:14 volumio volumio[14889]: info: Starting Shairport Sync
Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "last_100"...
Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "webradio"...
Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "i2s_dacs"...
Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "volumiodiscovery"...
Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** For more information see 
Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:07:14 volumio volumio[14889]: *** WARNING *** For more information see 
Feb 18 07:07:14 volumio node[14889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:07:14 volumio node[14889]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:07:14 volumio volumio[14889]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 18 07:07:14 volumio node[14889]: *** WARNING *** For more information see 
Feb 18 07:07:14 volumio node[14889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 18 07:07:14 volumio node[14889]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 18 07:07:14 volumio node[14889]: *** WARNING *** For more information see 
Feb 18 07:07:14 volumio volumio[14889]: info: Discovery: Started advertising with name: Volumio
Feb 18 07:07:14 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 18 07:07:14 volumio volumio[14889]: info: Loading plugin "spop"...
Feb 18 07:07:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 18 07:07:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:15 volumio go-librespot[14971]: go-librespot daemon starting...
Feb 18 07:07:15 volumio go-librespot[14972]: time="2026-02-18T07:07:15+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:15 volumio go-librespot[14972]: time="2026-02-18T07:07:15+07:00" level=debug msg="app state loaded"
Feb 18 07:07:15 volumio go-librespot[14972]: time="2026-02-18T07:07:15+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=info msg="zeroconf server listening on port 34681"
Feb 18 07:07:16 volumio volumio[14889]: info: Loading plugin "ytcr"...
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="obtained new client token: AADSh9AAsA2TsJCJh3o43+5sbO04obf9q2akQ7VRD3vscedy0r9ikZYmLltnKGL5c723Huyj7y2cWMXpjZeigUbWnXTfICE39PB8pDptR8pEBarssRMvBDljeJVMs4hA5PQzZCXSpoy2gGhqimMv2Z/lLO+JnOthiZF8YftcUmILNFLQnZd2pujUE3rFfnT7K9nrgEtaWRAF3n21lPxi3Jra8nRxojkv1WB9e0/EN2jKsG/kvRi7FRwgkw=="
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=debug msg="completed challenge"
Feb 18 07:07:16 volumio go-librespot[14972]: time="2026-02-18T07:07:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:18 volumio volumio[14889]: info: Loading plugin "ytmusic"...
Feb 18 07:07:19 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:19] [connect] Successful connection
Feb 18 07:07:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 18 07:07:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:19 volumio go-librespot[14984]: go-librespot daemon starting...
Feb 18 07:07:19 volumio go-librespot[14986]: time="2026-02-18T07:07:19+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:19 volumio go-librespot[14986]: time="2026-02-18T07:07:19+07:00" level=debug msg="app state loaded"
Feb 18 07:07:19 volumio go-librespot[14986]: time="2026-02-18T07:07:19+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "outputs"...
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "albumart"...
Feb 18 07:07:20 volumio volumio[14889]: info: Plugin example_plugin is not enabled
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "inputs"...
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "updater_comm"...
Feb 18 07:07:20 volumio volumio[14889]: info: Plugin mpdemulation is not enabled
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "rest_api"...
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "websocket"...
Feb 18 07:07:20 volumio volumio[14889]: info: Starting Socket.io Server version 1.7.4
Feb 18 07:07:20 volumio volumio[14889]: info: Loading plugin "RoonBridge"...
Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+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]"
Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+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]"
Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+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]"
Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=info msg="zeroconf server listening on port 38043"
Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=debug msg="obtained new client token: AADtOCHR8uoCxAb6sd62Qmr+nIC1bMXhTPufSt87ORAsXXThAM0SA0ZTsXzDd8DzeqiGSH+E8IUi6o4ocfAPrc2QGUVIruDBJ3woqC+41Ik3LGIz+8KjfjhIMjrsRmq4HWvOYH/HJZHD3WuXV0T4zAdL5uEzhWnCi02lch35rZEGSCTJCxy2NjUye5B6mJOeH8Bay1i0FKd+6MOnapmQ4GmJbxqsItWpThXGCHVSwLtcuo2ZnI+BrMaREg=="
Feb 18 07:07:20 volumio volumio[14889]: info: Applying required configuration parameters for plugin RoonBridge
Feb 18 07:07:20 volumio volumio[14889]: info: Loading i18n strings for locale en
Feb 18 07:07:20 volumio go-librespot[14986]: time="2026-02-18T07:07:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:20 volumio volumio[14889]: Updating browse sources language
Feb 18 07:07:20 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:07:21 volumio go-librespot[14986]: time="2026-02-18T07:07:21+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:21 volumio go-librespot[14986]: time="2026-02-18T07:07:21+07:00" level=debug msg="completed challenge"
Feb 18 07:07:21 volumio go-librespot[14986]: time="2026-02-18T07:07:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::initPlayerControls
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:21 volumio volumio[15001]: Forking 3 albumart workers
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 18 07:07:21 volumio volumio[14889]: Express server listening on port 3000
Feb 18 07:07:21 volumio volumio[14889]:  [Metrics]  WebUI:  16s 189.39ms 
Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::resetVolumioState
Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::getcurrentVolume
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::volumioRetrievevolume
Feb 18 07:07:21 volumio sudo[15044]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 18 07:07:21 volumio sudo[15044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:21 volumio sudo[15044]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:21 volumio sudo[15046]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 18 07:07:21 volumio sudo[15046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:21 volumio sudo[15046]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:21 volumio volumio[14889]: info: Volumio Network Manager: Network status updated: 1
Feb 18 07:07:21 volumio volumio[14889]: info: VolumeController:: Volume=100 Mute =false
Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::pushState
Feb 18 07:07:21 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState
Feb 18 07:07:21 volumio volumio[14889]: info: CoreStateMachine::updateTrackBlock
Feb 18 07:07:21 volumio volumio[14889]: info: CorePlayQueue::getTrackBlock
Feb 18 07:07:21 volumio volumio[14889]: info: CoreCommandRouter::volumioRetrievevolume
Feb 18 07:07:21 volumio volumio-remote-updater[25144]: [2026-02-18 07:07:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771373239 101
Feb 18 07:07:22 volumio volumio[14889]: 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: 1
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:22 volumio volumio[14889]: info: Reloading queue from file
Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::setRepeat null single undefined
Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::pushState
Feb 18 07:07:22 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState
Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::setRandom null
Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::pushState
Feb 18 07:07:22 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState
Feb 18 07:07:22 volumio volumio[14889]: info: Setting Device type: Raspberry PI
Feb 18 07:07:22 volumio volumio[14889]: info: Completed loading Core Plugins
Feb 18 07:07:22 volumio volumio[14889]: info: Preparing to generate the ALSA configuration file
Feb 18 07:07:22 volumio volumio[14889]: info: VolumeController:: Volume=100 Mute =false
Feb 18 07:07:22 volumio volumio[14889]: info: CoreStateMachine::pushState
Feb 18 07:07:22 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState
Feb 18 07:07:22 volumio volumio[14889]: info: Asound.conf file unchanged, so no further update is needed
Feb 18 07:07:22 volumio volumio[14889]: info: Output device has changed, restarting MPD
Feb 18 07:07:22 volumio volumio[14889]: info: Output device has changed, restarting Shairport Sync
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:22 volumio sudo[15063]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 18 07:07:22 volumio sudo[15063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:22 volumio sudo[15065]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 18 07:07:22 volumio volumio[14889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 18 07:07:22 volumio sudo[15065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:22 volumio volumio[14889]: info: ___________ START PLUGINS ___________
Feb 18 07:07:22 volumio sudo[15067]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 18 07:07:22 volumio sudo[15067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:22 volumio sudo[15065]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:22 volumio volumio[14889]: info: ControllerMpd::onStart: Initializing MPD
Feb 18 07:07:22 volumio volumio[14889]: info: Creating MPD Configuration file
Feb 18 07:07:22 volumio sudo[15063]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:22 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:07:22 volumio volumio[14889]: info: [1771373242678] CoreMusicLibrary::Adding element Media Servers
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:07:22 volumio sudo[15076]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 18 07:07:22 volumio sudo[15076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:22 volumio sudo[15076]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:22 volumio volumio[14889]: info: UPNP Browser: Client initialized successfully
Feb 18 07:07:22 volumio sudo[15078]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 18 07:07:22 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 18 07:07:22 volumio sudo[15078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 18 07:07:22 volumio systemd[1]: mpd.service: Consumed 7.142s CPU time.
Feb 18 07:07:22 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 18 07:07:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 18 07:07:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 18 07:07:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 18 07:07:22 volumio volumio[14889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:22 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:22 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 18 07:07:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 18 07:07:22 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 18 07:07:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 18 07:07:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 18 07:07:23 volumio volumio[14889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:07:23 volumio volumio[14889]: info: [1771373243042] CoreMusicLibrary::Adding element Last_100
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:07:23 volumio volumio[14889]: info: [1771373243062] CoreMusicLibrary::Adding element Webradio
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:07:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 18 07:07:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:07:23 volumio volumio[14889]: info: Initializing BBC Radios
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:23 volumio volumio[14889]: info: Creating Spotify config file
Feb 18 07:07:23 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:23 volumio sudo[15092]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 18 07:07:23 volumio sudo[15092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 18 07:07:23 volumio sudo[15092]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 18 07:07:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:24 volumio go-librespot[15108]: go-librespot daemon starting...
Feb 18 07:07:24 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:07:24 volumio volumio[14889]: info: [1771373244459] CoreMusicLibrary::Adding element YouTube Music
Feb 18 07:07:24 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:07:24 volumio volumio[14889]: Cannot find translation for source YouTube Music
Feb 18 07:07:24 volumio go-librespot[15109]: time="2026-02-18T07:07:24+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:24 volumio volumio[14889]: info: Volumio Calling Home
Feb 18 07:07:24 volumio volumio[15012]: Starting albumart workers
Feb 18 07:07:24 volumio sudo[15116]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 18 07:07:24 volumio sudo[15116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:24 volumio volumio[15014]: Starting albumart workers
Feb 18 07:07:24 volumio sudo[15116]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:25 volumio volumio[15017]: Starting albumart workers
Feb 18 07:07:25 volumio go-librespot[15109]: time="2026-02-18T07:07:25+07:00" level=info msg="zeroconf server listening on port 44053"
Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: Found device Volumio
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState
Feb 18 07:07:25 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:25 volumio volumio[14889]: info: MPD Permissions set
Feb 18 07:07:25 volumio volumio[14889]: info: MPD Permissions set
Feb 18 07:07:25 volumio volumio[14889]: info: Upmpdcli Daemon Started
Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 18 07:07:25 volumio volumio[14889]: info: Discovery: Found device Volumio
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState
Feb 18 07:07:25 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:25 volumio volumio[14889]: info: Volumio called home
Feb 18 07:07:25 volumio volumio[14889]: info: Spotify config file written
Feb 18 07:07:25 volumio sudo[15124]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 18 07:07:25 volumio sudo[15124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:25 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 18 07:07:25 volumio volumio[14889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 18 07:07:25 volumio systemd[1]: go-librespot-daemon.service: Killing process 15122 (go-librespot) with signal SIGKILL.
Feb 18 07:07:25 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 18 07:07:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:25 volumio go-librespot[15126]: go-librespot daemon starting...
Feb 18 07:07:25 volumio sudo[15124]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:25 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="app state loaded"
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 18 07:07:26 volumio volumio[14889]: info: No need to fix Spotify hosts
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=info msg="zeroconf server listening on port 38207"
Feb 18 07:07:26 volumio go-librespot[15132]: time="2026-02-18T07:07:26+07:00" level=debug msg="obtained new client token: AAC7bJY0sGzZ4UN+fO3HAcYwhsqw/7KSSBW7VSPxW5/JCzBwJbVeDz4neYIUdMdQWdnwx8NcOC+4XaK3Jkci7qH6bdASoiVrS49RYEo4+8XfYcFPbB+PLhirxutRdiIybt2Hh25qIVcJO5LWmNsv3qGho0H3IGMMcQ1rK2vNglP3Vs5uen1k5hiNX7o5QNcIU5CQjvdl+dZpDj131eLjJNb2PBGI8k51i+cc6nXNxIxl5new4r8oJBzASQ=="
Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=debug msg="completed challenge"
Feb 18 07:07:27 volumio go-librespot[15132]: time="2026-02-18T07:07:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:27 volumio volumio[14889]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 18 07:07:27 volumio volumio[14889]: SPOTIFY: BQCWkSjAHH5qHPz7Vv1q1BfL8fb-ivW-MzxWuDO6P9P36BlyLEtuWEpLWmWaE1gaR7SwbDkNuARwQ3lN6fjN8uGF3JDsVpf-eRlfQPWUja6wG6TgcWXN9pcKDtq27EWp4Zs6RFOSv30O8xoJC4O2V5nVb8WCXOBU2bMyBaDGkmibd_G9SwZ-yMgv5QP6F_0oF-xj4ilfI9hfwWnvj7FuLTp0n-0eDpRhWY-IcCaaLaQfWCwZb1KJ_Ymsbv8TXxc4SzoQTvIkzqeKXgnBn2dKrZ_UH0-4wOA0IorNpUkeMeuQ_1ctcTFzTjTI
Feb 18 07:07:27 volumio volumio[14889]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 18 07:07:27 volumio volumio[14889]: info: New Spotify access token = BQCWkSjAHH5qHPz7Vv1q1BfL8fb-ivW-MzxWuDO6P9P36BlyLEtuWEpLWmWaE1gaR7SwbDkNuARwQ3lN6fjN8uGF3JDsVpf-eRlfQPWUja6wG6TgcWXN9pcKDtq27EWp4Zs6RFOSv30O8xoJC4O2V5nVb8WCXOBU2bMyBaDGkmibd_G9SwZ-yMgv5QP6F_0oF-xj4ilfI9hfwWnvj7FuLTp0n-0eDpRhWY-IcCaaLaQfWCwZb1KJ_Ymsbv8TXxc4SzoQTvIkzqeKXgnBn2dKrZ_UH0-4wOA0IorNpUkeMeuQ_1ctcTFzTjTI
Feb 18 07:07:27 volumio volumio[14889]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 18 07:07:27 volumio volumio[14889]: info: Starting Shairport Sync
Feb 18 07:07:27 volumio volumio[14889]: info: Starting Shairport Sync
Feb 18 07:07:27 volumio volumio[14889]: info: Starting Shairport Sync
Feb 18 07:07:27 volumio sudo[15166]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 18 07:07:27 volumio sudo[15166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:27 volumio sudo[15164]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 18 07:07:27 volumio sudo[15164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:27 volumio sudo[15168]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 18 07:07:27 volumio sudo[15168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 18 07:07:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 18 07:07:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:07:27 volumio systemd[1]: shairport-sync.service: Consumed 2.302s CPU time.
Feb 18 07:07:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:07:27 volumio sudo[15164]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:27 volumio sudo[15166]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:27 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState
Feb 18 07:07:27 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:27 volumio volumio[14889]: info: Shairport-Sync Started
Feb 18 07:07:27 volumio volumio[14889]: Error adding Membership: Error: addMembership EINVAL
Feb 18 07:07:27 volumio volumio[14889]: info: Shairport-Sync Started
Feb 18 07:07:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 18 07:07:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 18 07:07:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:07:28 volumio volumio[14889]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"}
Feb 18 07:07:28 volumio volumio[14889]: info: Spotify Successfully logged in
Feb 18 07:07:28 volumio volumio[14889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 18 07:07:28 volumio volumio[14889]: info: [1771373248084] CoreMusicLibrary::Adding element Spotify
Feb 18 07:07:28 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 07:07:28 volumio volumio[14889]: Cannot find translation for source YouTube Music
Feb 18 07:07:28 volumio volumio[14889]: Cannot find translation for source Spotify
Feb 18 07:07:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 18 07:07:28 volumio sudo[15168]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:28 volumio volumio[14889]: info: Shairport-Sync Started
Feb 18 07:07:29 volumio volumio[14889]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 18 07:07:29 volumio volumio[14889]: info: CoreCommandRouter::volumioRetrievevolume
Feb 18 07:07:29 volumio volumio[14889]: info: VolumeController:: Volume=100 Mute =false
Feb 18 07:07:29 volumio volumio[14889]: info: CoreCommandRouter::volumioGetState
Feb 18 07:07:29 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:29 volumio volumio[14889]: info: CoreStateMachine::pushState
Feb 18 07:07:29 volumio volumio[14889]: info: CorePlayQueue::getTrack 0
Feb 18 07:07:29 volumio volumio[14889]: info: CoreCommandRouter::volumioPushState
Feb 18 07:07:30 volumio volumio[14889]: info: go-librespot daemon successfully initialized
Feb 18 07:07:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 18 07:07:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:30 volumio go-librespot[15204]: go-librespot daemon starting...
Feb 18 07:07:30 volumio go-librespot[15205]: time="2026-02-18T07:07:30+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:30 volumio go-librespot[15205]: time="2026-02-18T07:07:30+07:00" level=debug msg="app state loaded"
Feb 18 07:07:30 volumio go-librespot[15205]: time="2026-02-18T07:07:30+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:30 volumio mpd[15107]: 2026-02-18T07:07:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 18 07:07:30 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 18 07:07:30 volumio sudo[15067]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:30 volumio sudo[15078]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:31 volumio volumio[14889]: error: MPD error: The expression evaluated to a falsy value:
Feb 18 07:07:31 volumio volumio[14889]:   assert.ok(self.idling)
Feb 18 07:07:31 volumio volumio[14889]: error: The expression evaluated to a falsy value:
Feb 18 07:07:31 volumio volumio[14889]:   assert.ok(self.idling)
Feb 18 07:07:31 volumio volumio[14889]: error: updateQueue error: null
Feb 18 07:07:31 volumio volumio[14889]: info: MPD running with PID15107
Feb 18 07:07:31 volumio volumio[14889]:  ,establishing connection
Feb 18 07:07:31 volumio volumio[14889]: info: Completed starting Core Plugins
Feb 18 07:07:31 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:31 volumio volumio[14889]: info: -----    MyVolumio plugins startup     ----
Feb 18 07:07:31 volumio volumio[14889]: info: -------------------------------------------
Feb 18 07:07:31 volumio volumio[14889]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 18 07:07:31 volumio volumio[14889]: error: updateQueue error: null
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=info msg="zeroconf server listening on port 38243"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="obtained new client token: AAAeae2qaWjrSm6AjnS7qNNAUpWnzr5Crn9M/nZWloc7mt44h6zE+QP3LV1UeUStToVj9grOcG5Zk/ZV0P1piVDMLNkheOqHUR05ArJC+KkXSW1vPjnjdhgRwcs71dEag3VUpEpEONftKrhZa331wdbiANvZvuU0hkoYuzw/p+zV5QjC3Y/xxvQNtCHbZ0ZdaR4GdvTSStOyb5/AoYeVRId30B7jwmQ47HSkUlKQDP70ym/zaBcBaBm8zw=="
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=debug msg="completed challenge"
Feb 18 07:07:31 volumio go-librespot[15205]: time="2026-02-18T07:07:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:33 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket
Feb 18 07:07:33 volumio volumio[14889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:07:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 18 07:07:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:35 volumio go-librespot[15216]: go-librespot daemon starting...
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="app state loaded"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+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]"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+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]"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+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]"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=info msg="zeroconf server listening on port 42331"
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="obtained new client token: AAAYVYP9MIs+LRR4JLJsFMoqpXIfynbpgqQQtRlodltx5yTHy7tdnK8kIQTwmiddLEGNiGqLQliU9deDGl5wFC3821dP1W/AqqOQCLcEpwRbXOFM2tRDzED3op0/ObpnYhJSk7hUJWjdB8iMD4izpXxmIuExV84tclgE9w91POowj8Y3puVYy7RLNMrpZR7VactlFfwmL36wy7TjPHemor2eKQbURaV9TempWvfkqKCPgtXnhVn7cmhzBg=="
Feb 18 07:07:35 volumio volumio[14889]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 18 07:07:35 volumio go-librespot[15217]: time="2026-02-18T07:07:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:36 volumio go-librespot[15217]: time="2026-02-18T07:07:36+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:36 volumio go-librespot[15217]: time="2026-02-18T07:07:36+07:00" level=debug msg="completed challenge"
Feb 18 07:07:36 volumio go-librespot[15217]: time="2026-02-18T07:07:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:36 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket
Feb 18 07:07:36 volumio volumio[14889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:07:39 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket
Feb 18 07:07:39 volumio volumio[14889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:07:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 18 07:07:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:39 volumio go-librespot[15225]: go-librespot daemon starting...
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=debug msg="app state loaded"
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin multiroom to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 18 07:07:39 volumio volumio[14889]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+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]"
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+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]"
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+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]"
Feb 18 07:07:39 volumio go-librespot[15226]: time="2026-02-18T07:07:39+07:00" level=info msg="zeroconf server listening on port 46251"
Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="obtained new client token: AAAthpee957eIsQJHBRKQaZZp8ABvAXXP4g+3zdbCabLvkK0dSYF3zLdhxVEXm7ivc9cHGIDWN1TfIs3LzDw22WW671Nv3+BqP2Gu5TmBaiuavjM0GubXpzstfc1I1h6558Zhk01CEIf7FK11/fD3NddljVB4ObutIMpuoYofmgm0LIiEJvoodfcE/Yg6n999UESXMqj2M7f+t5oHTlQF2sGqZlBlcPCMhChG6VLQ/XA27LaTwboY2A="
Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=debug msg="completed challenge"
Feb 18 07:07:40 volumio go-librespot[15226]: time="2026-02-18T07:07:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 18 07:07:41 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:41 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:41 volumio volumio[14889]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 18 07:07:41 volumio volumio[14889]: info: MyVolumio login type: Token
Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 18 07:07:41 volumio volumio[14889]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 18 07:07:43 volumio volumio[14889]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 18 07:07:43 volumio volumio[14889]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 18 07:07:43 volumio volumio[14889]: info: Streaming services startup
Feb 18 07:07:43 volumio volumio[14889]: info: Starting Streaming Daemon
Feb 18 07:07:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 18 07:07:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:43 volumio sudo[15249]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 18 07:07:43 volumio volumio[14889]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 18 07:07:43 volumio sudo[15249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:43 volumio go-librespot[15251]: go-librespot daemon starting...
Feb 18 07:07:43 volumio sudo[15249]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=debug msg="app state loaded"
Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:43 volumio volumio[14889]: info: Initializing connection to go-librespot Websocket
Feb 18 07:07:43 volumio volumio[14889]: error: Cannot start Volumio Streaming Daemon
Feb 18 07:07:43 volumio volumio[14889]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 18 07:07:43 volumio volumio[14889]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 18 07:07:43 volumio go-librespot[15256]: time="2026-02-18T07:07:43+07:00" level=debug msg="new websocket client"
Feb 18 07:07:43 volumio volumio[14889]: info: Connection to go-librespot Websocket established
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=info msg="zeroconf server listening on port 40163"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="obtained new client token: AAAadyoIhvfbc3pDe9x1PrCDdyNCbITSQPuwPLBZy1Cvf+JnJ4B5T8/4IbASBNQQLeU8z+OzzFykZJI1jBPdFpEzRuKkwWTfGMqZOoXWfb4jHPzj1ACMvAPTwFAABUVoZcC0uOzWKZetJQIpf/sOGEIUmzoz48D3gowSkE5swXmWt3kzn/AkGBheH4KAbeg1JJyK27Q+Mt8VmrMrAk5g0WXQfnn0qTB1lGjHbMT0ph0QkOIFQ8zz1M0+aQ=="
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 18 07:07:44 volumio volumio[14889]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="completed keyexchange"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=debug msg="completed challenge"
Feb 18 07:07:44 volumio go-librespot[15256]: time="2026-02-18T07:07:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 18 07:07:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 18 07:07:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 18 07:07:44 volumio volumio[14889]: info: Connection to go-librespot Websocket closed
Feb 18 07:07:45 volumio volumio[14889]: info: MyVolumio token set successfully
Feb 18 07:07:45 volumio volumio[14889]: info: MYVOLUMIO: Adding device
Feb 18 07:07:45 volumio volumio[14889]: info: MYVOLUMIO: Evaluating Server
Feb 18 07:07:46 volumio volumio[14889]: info: MyVolumio status changed
Feb 18 07:07:46 volumio volumio[14889]: info: Streaming services startup
Feb 18 07:07:46 volumio volumio[14889]: info: Starting Streaming Daemon
Feb 18 07:07:46 volumio volumio[14889]: info: Removing browser output: myVolumio user plan is not superstar
Feb 18 07:07:46 volumio volumio[14889]: info: Removing audio output:
Feb 18 07:07:46 volumio volumio[14889]: info: Stoppping Tunnel 1
Feb 18 07:07:46 volumio sudo[15284]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 18 07:07:46 volumio sudo[15284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:46 volumio sudo[15284]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:46 volumio sudo[15287]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 18 07:07:46 volumio volumio[14889]: error: Cannot start Volumio Streaming Daemon
Feb 18 07:07:46 volumio volumio[14889]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 18 07:07:46 volumio volumio[14889]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 18 07:07:46 volumio sudo[15287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 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.
Feb 18 07:07:46 volumio volumio[14889]: info: Setting Geolocation for MyVolumio to as1
Feb 18 07:07:46 volumio sudo[15287]: pam_unix(sudo:session): session closed for user root
Feb 18 07:07:46 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:46 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:46 volumio volumio[14889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 18 07:07:46 volumio volumio[14889]: info: Remote SSH Stopped
Feb 18 07:07:46 volumio volumio[14889]: info: Getting Spotify volume
Feb 18 07:07:46 volumio volumio[14889]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 07:07:46 volumio volumio[14889]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 18 07:07:46 volumio volumio[14889]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 18 07:07:46 volumio volumio[14889]:   errno: -111,
Feb 18 07:07:46 volumio volumio[14889]:   code: 'ECONNREFUSED',
Feb 18 07:07:46 volumio volumio[14889]:   syscall: 'connect',
Feb 18 07:07:46 volumio volumio[14889]:   address: '127.0.0.1',
Feb 18 07:07:46 volumio volumio[14889]:   port: 9879,
Feb 18 07:07:46 volumio volumio[14889]:   response: undefined
Feb 18 07:07:46 volumio volumio[14889]: }
Feb 18 07:07:46 volumio volumio[14889]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 07:07:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 18 07:07:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 18 07:07:47 volumio go-librespot[15301]: go-librespot daemon starting...
Feb 18 07:07:47 volumio go-librespot[15302]: time="2026-02-18T07:07:47+07:00" level=info msg="running go-librespot 0.4.0"
Feb 18 07:07:47 volumio go-librespot[15302]: time="2026-02-18T07:07:47+07:00" level=debug msg="app state loaded"
Feb 18 07:07:47 volumio go-librespot[15302]: time="2026-02-18T07:07:47+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 18 07:07:48 volumio sudo[15311]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 07:06'
Feb 18 07:07:48 volumio sudo[15311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=info msg="zeroconf server listening on port 45245"
Feb 18 07:07:48 volumio go-librespot[15302]: time="2026-02-18T07:07:48+07:00" level=debug msg="obtained new client token: AACG4b3YMp2CA6doNCjMHaVBS7SMjyLjn90mTUfq6d92FDm66NxsVUZJxBp+5lykyijqPIQOgtQI1eg++Wlo6vH7MnH0o8apCfdP5GH6RlPwKvWH3pWsWxdNNL+E1NDxWFX9sqUbkmklz+ePZDC/Za3rAOc87cAWN+AKcQVm+69Fcu6I9QWSwuIhLzRHt+HLGbXbYMNNp4JhezV0RWdH2pgCDoWCVHTLODpGa/pGRiXhbaSLy//BlZKs8Q=="
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025"
VOLUMIO_VERSION="4.084"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"