Feb 13 04:27:00 volumio volumio[5890]: info: MyVolumio token set successfully
Feb 13 04:27:00 volumio volumio[5890]: info: MYVOLUMIO: Adding device
Feb 13 04:27:00 volumio volumio[5890]: info: MYVOLUMIO: Evaluating Server
Feb 13 04:27:00 volumio volumio[5890]: info: MyVolumio status changed
Feb 13 04:27:00 volumio volumio[5890]: info: Streaming services startup
Feb 13 04:27:00 volumio volumio[5890]: info: Starting Streaming Daemon
Feb 13 04:27:00 volumio volumio[5890]: info: Removing browser output: myVolumio user plan is not superstar
Feb 13 04:27:00 volumio volumio[5890]: info: Removing audio output:
Feb 13 04:27:00 volumio volumio[5890]: info: Stoppping Tunnel 1
Feb 13 04:27:00 volumio sudo[6288]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 13 04:27:00 volumio sudo[6288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:00 volumio sudo[6288]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:00 volumio sudo[6292]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 13 04:27:00 volumio sudo[6292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:00 volumio volumio[5890]: error: Cannot start Volumio Streaming Daemon
Feb 13 04:27:00 volumio volumio[5890]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 13 04:27:00 volumio volumio[5890]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 13 04:27:00 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 13 04:27:00 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 13 04:27:00 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 13 04:27:00 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 13 04:27:00 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 13 04:27:00 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 13 04:27:00 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 13 04:27:00 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 13 04:27:00 volumio volumio[5890]: info: Setting Geolocation for MyVolumio to as1
Feb 13 04:27:00 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:00 volumio sudo[6292]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:00 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:00 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:00 volumio volumio[5890]: info: Remote SSH Stopped
Feb 13 04:27:01 volumio volumio[5890]: info: Initializing connection to go-librespot Websocket
Feb 13 04:27:01 volumio volumio[5890]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:27:01 volumio volumio[5890]: info: Updating MyVolumio device info
Feb 13 04:27:01 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:01 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:01 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 13 04:27:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:02 volumio volumio[5890]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 13 04:27:02 volumio go-librespot[6294]: go-librespot daemon starting...
Feb 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+07:00" level=debug msg="app state loaded"
Feb 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:02 volumio volumio[5890]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+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 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+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 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+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 13 04:27:02 volumio go-librespot[6295]: time="2026-02-13T04:27:02+07:00" level=info msg="zeroconf server listening on port 46803"
Feb 13 04:27:03 volumio go-librespot[6295]: time="2026-02-13T04:27:03+07:00" level=debug msg="obtained new client token: AAC5qHXkajvkH3kd4tjTdAMXSskdfoZtHC05KNnCu5R6wQ0RbHImGfQf5YXE/APnWySxqZhk5R9K2DD39ZgfFPInPB/txr0HUB+OIK8E/lpwCKVt6TpI7rlDlDWywCun18Ej2v/N0KqyXnitvWvEAVv2Pvek8iK7OWdBADC8CaUJ5fuCqQ054VeON0HZkbYf/ywBXg7SajegXLsb3S7z3Nb9fx1qpKoi7wvK7wvMehlGgnNORea+svI="
Feb 13 04:27:03 volumio go-librespot[6295]: time="2026-02-13T04:27:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:03 volumio go-librespot[6295]: time="2026-02-13T04:27:03+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:03 volumio go-librespot[6295]: time="2026-02-13T04:27:03+07:00" level=debug msg="completed challenge"
Feb 13 04:27:03 volumio go-librespot[6295]: time="2026-02-13T04:27: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 13 04:27:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:04 volumio volumio[5890]: info: Initializing connection to go-librespot Websocket
Feb 13 04:27:04 volumio volumio[5890]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:27:06 volumio volumio[5890]: info: MYVOLUMIO: Adding device
Feb 13 04:27:06 volumio volumio[5890]: info: MYVOLUMIO: Evaluating Server
Feb 13 04:27:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 13 04:27:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:06 volumio go-librespot[6317]: go-librespot daemon starting...
Feb 13 04:27:06 volumio go-librespot[6318]: time="2026-02-13T04:27:06+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:06 volumio go-librespot[6318]: time="2026-02-13T04:27:06+07:00" level=debug msg="app state loaded"
Feb 13 04:27:06 volumio go-librespot[6318]: time="2026-02-13T04:27:06+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+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 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+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 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+07:00" level=info msg="zeroconf server listening on port 39647"
Feb 13 04:27:07 volumio volumio[5890]: info: Initializing connection to go-librespot Websocket
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+07:00" level=debug msg="new websocket client"
Feb 13 04:27:07 volumio volumio[5890]: info: Connection to go-librespot Websocket established
Feb 13 04:27:07 volumio volumio[5890]: info: Setting Geolocation for MyVolumio to as1
Feb 13 04:27:07 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:07 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:07 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+07:00" level=debug msg="obtained new client token: AADZtFfP1I+YvB+KoUMOWYFVVdLe2rzdJoiT+ToEdAp3MqRanF01Bj6M6DHeb57UH6k1/KE6qOR8pDI0fpVb87NMOoTHVxiW5j0kLfrqe5Z0QOkrkcSSwtATOmY0xZwm/poFaQ9u1AvmYse9hdYW24XDKv11DB2X+OBmoiVhMx1QpD0IsTCLgwofTvOFv0zctnKl1VRwHXPR0hOIr2TIvztE84Jm3oPht99Ur+ettl8imYgu3rW5CkUyJA=="
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27:07+07:00" level=debug msg="completed challenge"
Feb 13 04:27:07 volumio go-librespot[6318]: time="2026-02-13T04:27: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 13 04:27:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:07 volumio volumio[5890]: info: Connection to go-librespot Websocket closed
Feb 13 04:27:07 volumio volumio[5890]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 13 04:27:08 volumio volumio[5890]: info: Updating MyVolumio device info
Feb 13 04:27:08 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:08 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:08 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:08 volumio volumio[5890]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 13 04:27:09 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:27:09 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:09 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 13 04:27:09 volumio volumio-remote-updater[643]: Test mode disabled
Feb 13 04:27:09 volumio volumio-remote-updater[643]: Alpha mode disabled
Feb 13 04:27:09 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled
Feb 13 04:27:09 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 13 04:27:09 volumio volumio[5890]: 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 13 04:27:09 volumio volumio[5890]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 13 04:27:10 volumio volumio[5890]: info: Getting Spotify volume
Feb 13 04:27:10 volumio volumio[5890]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 04:27:10 volumio volumio[5890]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:27:10 volumio volumio[5890]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 13 04:27:10 volumio volumio[5890]:   errno: -111,
Feb 13 04:27:10 volumio volumio[5890]:   code: 'ECONNREFUSED',
Feb 13 04:27:10 volumio volumio[5890]:   syscall: 'connect',
Feb 13 04:27:10 volumio volumio[5890]:   address: '127.0.0.1',
Feb 13 04:27:10 volumio volumio[5890]:   port: 9879,
Feb 13 04:27:10 volumio volumio[5890]:   response: undefined
Feb 13 04:27:10 volumio volumio[5890]: }
Feb 13 04:27:10 volumio volumio[5890]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 04:27:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 13 04:27:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:10 volumio go-librespot[6359]: go-librespot daemon starting...
Feb 13 04:27:10 volumio go-librespot[6360]: time="2026-02-13T04:27:10+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:10 volumio go-librespot[6360]: time="2026-02-13T04:27:10+07:00" level=debug msg="app state loaded"
Feb 13 04:27:10 volumio go-librespot[6360]: time="2026-02-13T04:27:10+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+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 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+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 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+07:00" level=info msg="zeroconf server listening on port 33833"
Feb 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+07:00" level=debug msg="obtained new client token: AADg19f4K+t0pK/cJ/ivNEM/TsiXd4C0aZ8FPNHFBPm3eF/37OdJ07IPh70Tn7qEhfrbL79rVxX5JBV92+MSI/fjvt+hM1Mi816aRKLKNC//gt0vmWpuL0MRbx/UTlm5rYOL3kUBBkUWvYDvJ/e6gVtWO3p2ZLkJ8fEdxBOVVrfaxRrCBltA6iHFYlluQpEX/1Pz0Ra0pct+rr/qltJJ/LCb7VkUeAkyLwsmYOBY39Aw+2cp6SemiZ0/yA=="
Feb 13 04:27:11 volumio sudo[6369]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 04:26'
Feb 13 04:27:11 volumio sudo[6369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:11 volumio go-librespot[6360]: time="2026-02-13T04:27:11+07:00" level=debug msg="completed challenge"
Feb 13 04:27:12 volumio go-librespot[6360]: time="2026-02-13T04:27: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 13 04:27:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:12 volumio sudo[6369]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:13 volumio volumio-remote-updater[643]: [2026-02-13 04:27:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 13 04:27:13 volumio volumio-remote-updater[643]: [2026-02-13 04:27:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 13 04:27:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 13 04:27:13 volumio systemd[1]: volumio.service: Consumed 58.714s CPU time.
Feb 13 04:27:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 04:27:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 04:27:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14252.
Feb 13 04:27:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 04:27:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 13 04:27:13 volumio systemd[1]: volumio.service: Consumed 58.714s CPU time.
Feb 13 04:27:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 13 04:27:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 04:27:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 13 04:27:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:15 volumio go-librespot[6400]: go-librespot daemon starting...
Feb 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+07:00" level=debug msg="app state loaded"
Feb 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+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 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+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 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+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 13 04:27:15 volumio go-librespot[6401]: time="2026-02-13T04:27:15+07:00" level=info msg="zeroconf server listening on port 35241"
Feb 13 04:27:16 volumio go-librespot[6401]: time="2026-02-13T04:27:16+07:00" level=debug msg="obtained new client token: AADD/Sq2cT+rHh+ImrZo/EVvXRiL9gEa/DhqT/O4gM18sf2Q8ttYCfW86H7OHw1Nz9xU1h7J20D1h2kMNIPhConOhIsUZobmBkOgLDdUZbotNmZAyMVP0Tx1NL/WgTna4iT03OP9TiBr5pwh4nEJu6Y6cTubb0689ysbXjm1KqkBfHkgiR9Ui36qLDRm8DVo2O1G02byqNg6i0TYvS9kQ5anoF9gCm8G1eW8oSnmA7hydlnZAO5YjO4="
Feb 13 04:27:16 volumio go-librespot[6401]: time="2026-02-13T04:27:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:16 volumio go-librespot[6401]: time="2026-02-13T04:27:16+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:16 volumio go-librespot[6401]: time="2026-02-13T04:27:16+07:00" level=debug msg="completed challenge"
Feb 13 04:27:16 volumio go-librespot[6401]: time="2026-02-13T04:27: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 13 04:27:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:17 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:17 volumio volumio[6385]: info: -----            Volumio3              ----
Feb 13 04:27:17 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:17 volumio volumio[6385]: info: -----          System startup          ----
Feb 13 04:27:17 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:18 volumio volumio-remote-updater[643]: [2026-02-13 04:27:18] [connect] Successful connection
Feb 13 04:27:18 volumio volumio[6385]: info: MYVOLUMIO Environment detected
Feb 13 04:27:19 volumio volumio[6385]: info: Plugin folders cleanup
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning into folder /volumio/app/plugins/
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category audio_interface
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category miscellanea
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category music_service
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category plugins.json
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category system_controller
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category user_interface
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning into folder /data/plugins/
Feb 13 04:27:19 volumio volumio[6385]: info: Scanning category music_service
Feb 13 04:27:19 volumio volumio[6385]: info: Plugin folders cleanup completed
Feb 13 04:27:19 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:19 volumio volumio[6385]: info: -----      Core plugins startup        ----
Feb 13 04:27:19 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:19 volumio volumio[6385]: info: Loading plugins from folder /volumio/app/plugins/
Feb 13 04:27:19 volumio volumio[6385]: info: Adding plugin upnp to MyMusic Plugins
Feb 13 04:27:19 volumio volumio[6385]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 13 04:27:19 volumio volumio[6385]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 13 04:27:19 volumio volumio[6385]: info: Loading plugins from folder /data/plugins/
Feb 13 04:27:19 volumio volumio[6385]: info: Loading plugin "system"...
Feb 13 04:27:19 volumio volumio[6385]: info: Loading plugin "appearance"...
Feb 13 04:27:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 13 04:27:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:19 volumio go-librespot[6421]: go-librespot daemon starting...
Feb 13 04:27:19 volumio go-librespot[6422]: time="2026-02-13T04:27:19+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:19 volumio go-librespot[6422]: time="2026-02-13T04:27:19+07:00" level=debug msg="app state loaded"
Feb 13 04:27:19 volumio go-librespot[6422]: time="2026-02-13T04:27:19+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+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 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+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 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+07:00" level=info msg="zeroconf server listening on port 34319"
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+07:00" level=debug msg="obtained new client token: AACLI0qJwiZe8Qp9Lz41onaG0hWPHHK0yhxj7+hl737YezSnzXOglYSGd4mSDJa5c3HGVkWNc73Ezv5C2QrTFEv3wzvgr0MYGfPJEXW8bld/YSonl3UWu8iIU9QWTsHfMzXCd6sRqTA9Q2L1b8l/9HEsDwgczIWHGaipqhSC1+M7G2SNJMnTsA0vn9BeXc4REDb51SucKXF4qB80iFxDnzolPTc3mZSStvQ578mBGvz18HCplkq+vMqyaA=="
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+07:00" level=debug msg="completed challenge"
Feb 13 04:27:20 volumio go-librespot[6422]: time="2026-02-13T04:27:20+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 13 04:27:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "network"...
Feb 13 04:27:21 volumio volumio[6385]: info: Refreshing Cached IP Addresses
Feb 13 04:27:21 volumio sudo[6430]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 04:27:21 volumio sudo[6430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:21 volumio sudo[6432]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 04:27:21 volumio sudo[6432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "services"...
Feb 13 04:27:21 volumio sudo[6430]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "alsa_controller"...
Feb 13 04:27:21 volumio sudo[6432]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:21 volumio sudo[6444]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 13 04:27:21 volumio sudo[6444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:21 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "wizard"...
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "networkfs"...
Feb 13 04:27:21 volumio volumio[6385]: info: Starting Udev Watcher for removable devices
Feb 13 04:27:21 volumio volumio[6385]: info: Ignoring mount for partition: boot
Feb 13 04:27:21 volumio volumio[6385]: info: Ignoring mount for partition: volumio
Feb 13 04:27:21 volumio volumio[6385]: info: Ignoring mount for partition: volumio_data
Feb 13 04:27:21 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "volumio_command_line_client"...
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "upnp"...
Feb 13 04:27:21 volumio volumio[6385]: info: [1770931641480] Starting Upmpd Daemon
Feb 13 04:27:21 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "my_music"...
Feb 13 04:27:21 volumio volumio[6385]: info: Loading plugin "mpd"...
Feb 13 04:27:22 volumio volumio[6385]: info: Loading plugin "upnp_browser"...
Feb 13 04:27:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 13 04:27:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:23 volumio go-librespot[6463]: go-librespot daemon starting...
Feb 13 04:27:23 volumio go-librespot[6464]: time="2026-02-13T04:27:23+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:23 volumio go-librespot[6464]: time="2026-02-13T04:27:23+07:00" level=debug msg="app state loaded"
Feb 13 04:27:23 volumio go-librespot[6464]: time="2026-02-13T04:27:23+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:24 volumio sudo[6444]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+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 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+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 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+07:00" level=info msg="zeroconf server listening on port 35353"
Feb 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+07:00" level=debug msg="obtained new client token: AABS5sNvda27V+INLkuKO4E3spO0tzqGXfcezjN1zkvma7dmdNs2iG/13L6Uv9nJXt8qI7JjpC+deVutM92VJaWRDX1RXA+uoZbJySYqMI8MUGqR9sosBEdNZ4Q0mKonGRq1ZzTTZeYvi7DTHoM1KOOj3cGFePY5F1EW6eKp70TJK0svTocZ6JMkppHKKD4CBHyV5RCuH9JH545SDsNXvmg7NFKxJE+LYxuLQcCy3rPr1EPLJ1KbK4r/5g=="
Feb 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:24 volumio go-librespot[6464]: time="2026-02-13T04:27:24+07:00" level=debug msg="completed challenge"
Feb 13 04:27:25 volumio go-librespot[6464]: time="2026-02-13T04:27:25+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 13 04:27:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:25 volumio volumio[6385]: info: Starting UPNP Browser
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "alarm-clock"...
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "airplay_emulation"...
Feb 13 04:27:25 volumio volumio[6385]: info: Starting Shairport Sync
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "last_100"...
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "webradio"...
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "i2s_dacs"...
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "volumiodiscovery"...
Feb 13 04:27:25 volumio volumio[6385]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:27:25 volumio volumio[6385]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:27:25 volumio volumio[6385]: *** WARNING *** For more information see 
Feb 13 04:27:25 volumio volumio[6385]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:27:25 volumio volumio[6385]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:27:25 volumio volumio[6385]: *** WARNING *** For more information see 
Feb 13 04:27:25 volumio node[6385]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:27:25 volumio node[6385]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:27:25 volumio node[6385]: *** WARNING *** For more information see 
Feb 13 04:27:25 volumio node[6385]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:27:25 volumio node[6385]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:27:25 volumio node[6385]: *** WARNING *** For more information see 
Feb 13 04:27:25 volumio volumio[6385]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 13 04:27:25 volumio volumio[6385]: info: Discovery: Started advertising with name: Volumio
Feb 13 04:27:25 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 04:27:25 volumio volumio[6385]: info: Loading plugin "spop"...
Feb 13 04:27:27 volumio volumio[6385]: info: Loading plugin "ytcr"...
Feb 13 04:27:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Feb 13 04:27:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:28 volumio go-librespot[6475]: go-librespot daemon starting...
Feb 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+07:00" level=debug msg="app state loaded"
Feb 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+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 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+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 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+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 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+07:00" level=info msg="zeroconf server listening on port 34899"
Feb 13 04:27:28 volumio go-librespot[6476]: time="2026-02-13T04:27:28+07:00" level=debug msg="obtained new client token: AAC68R7W9QnDhEI2fffTZjQ3nXxNWnnyaovG+Hjx17xZYCLq3SAy59wROogTmwt/0SKskDI8oiNl6dixgkdb1iob/BJbDnPqoqigC/yINgfPYzQQ55NCVy+4qh7+A3TkYf7C3YJSIEkLWqNULhRkMxV0g0QXQu0tnvvD+BtYES5yad680W2WHnNfnQu4OGDpcssdzj1u8QMuCeCxu6zFKhObtqUzPPKXf35wtcS3UEqo+OWBKxYqIH0UmA=="
Feb 13 04:27:29 volumio go-librespot[6476]: time="2026-02-13T04:27:29+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 13 04:27:29 volumio go-librespot[6476]: time="2026-02-13T04:27:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 04:27:29 volumio go-librespot[6476]: time="2026-02-13T04:27:29+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:29 volumio go-librespot[6476]: time="2026-02-13T04:27:29+07:00" level=debug msg="completed challenge"
Feb 13 04:27:29 volumio go-librespot[6476]: time="2026-02-13T04:27:29+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 13 04:27:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:30 volumio volumio[6385]: info: Loading plugin "ytmusic"...
Feb 13 04:27:31 volumio volumio-remote-updater[643]: [2026-02-13 04:27:31] [connect] Successful connection
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "outputs"...
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "albumart"...
Feb 13 04:27:31 volumio volumio[6385]: info: Plugin example_plugin is not enabled
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "inputs"...
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "updater_comm"...
Feb 13 04:27:31 volumio volumio[6385]: info: Plugin mpdemulation is not enabled
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "rest_api"...
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "websocket"...
Feb 13 04:27:31 volumio volumio[6385]: info: Starting Socket.io Server version 1.7.4
Feb 13 04:27:31 volumio volumio[6385]: info: Loading plugin "RoonBridge"...
Feb 13 04:27:32 volumio volumio[6385]: info: Applying required configuration parameters for plugin RoonBridge
Feb 13 04:27:32 volumio volumio[6385]: info: Loading i18n strings for locale en
Feb 13 04:27:32 volumio volumio[6385]: Updating browse sources language
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:27:32 volumio volumio[6499]: Forking 3 albumart workers
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::initPlayerControls
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 04:27:32 volumio volumio[6385]: Express server listening on port 3000
Feb 13 04:27:32 volumio volumio[6385]:  [Metrics]  WebUI:  15s 919.00ms 
Feb 13 04:27:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 13 04:27:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:32 volumio volumio[6385]: info: CoreStateMachine::resetVolumioState
Feb 13 04:27:32 volumio volumio[6385]: info: CoreStateMachine::getcurrentVolume
Feb 13 04:27:32 volumio volumio[6385]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 04:27:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:32 volumio go-librespot[6536]: go-librespot daemon starting...
Feb 13 04:27:32 volumio go-librespot[6541]: time="2026-02-13T04:27:32+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:32 volumio go-librespot[6541]: time="2026-02-13T04:27:32+07:00" level=debug msg="app state loaded"
Feb 13 04:27:32 volumio go-librespot[6541]: time="2026-02-13T04:27:32+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:32 volumio sudo[6550]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 04:27:32 volumio sudo[6550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:32 volumio sudo[6550]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:32 volumio sudo[6553]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 04:27:32 volumio sudo[6553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:32 volumio sudo[6553]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:32 volumio volumio[6385]: info: Volumio Network Manager: Network status updated: 1
Feb 13 04:27:33 volumio volumio[6385]: info: VolumeController:: Volume=100 Mute =false
Feb 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::pushState
Feb 13 04:27:33 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::volumioPushState
Feb 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::updateTrackBlock
Feb 13 04:27:33 volumio volumio[6385]: info: CorePlayQueue::getTrackBlock
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 04:27:33 volumio volumio-remote-updater[643]: [2026-02-13 04:27:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770931651 101
Feb 13 04:27:33 volumio volumio[6385]: 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 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:33 volumio volumio[6385]: info: Reloading queue from file
Feb 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+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 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+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 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+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 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::setRepeat null single undefined
Feb 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::pushState
Feb 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+07:00" level=info msg="zeroconf server listening on port 44499"
Feb 13 04:27:33 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::volumioPushState
Feb 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::setRandom null
Feb 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::pushState
Feb 13 04:27:33 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::volumioPushState
Feb 13 04:27:33 volumio volumio[6385]: info: Setting Device type: Raspberry PI
Feb 13 04:27:33 volumio volumio[6385]: info: Completed loading Core Plugins
Feb 13 04:27:33 volumio volumio[6385]: info: Preparing to generate the ALSA configuration file
Feb 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+07:00" level=debug msg="obtained new client token: AAAT51JmOt53JgZTQzgjqAWYeQTp4EkWTgxC4EkkgB9nOPtjD7ZLy7qAiWV/wV5fF30SqTEh5uYMU6DRCfr3b+WhQ9OhPX2xc2zVu2m0FK7atyVbPIQJgtbpmkqETF8LtGNjxPXyVBrKJ9BeVD7l+wQDIOSFAzsTLJ8c8w2RIYi7wCJ6rohDBE78HTrA4rhMifD/oxEiStA/7ckCclpGQ6aJcH/zFE49Ktfc4XNebamACjPctFyLjz0LnQ=="
Feb 13 04:27:33 volumio volumio[6385]: info: VolumeController:: Volume=100 Mute =false
Feb 13 04:27:33 volumio volumio[6385]: info: CoreStateMachine::pushState
Feb 13 04:27:33 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::volumioPushState
Feb 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+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 13 04:27:33 volumio volumio[6385]: info: Asound.conf file unchanged, so no further update is needed
Feb 13 04:27:33 volumio volumio[6385]: info: Output device has changed, restarting MPD
Feb 13 04:27:33 volumio volumio[6385]: info: Output device has changed, restarting Shairport Sync
Feb 13 04:27:33 volumio go-librespot[6541]: time="2026-02-13T04:27:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:33 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:33 volumio sudo[6567]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 13 04:27:34 volumio sudo[6567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:34 volumio sudo[6569]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 04:27:34 volumio go-librespot[6541]: time="2026-02-13T04:27:34+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:34 volumio go-librespot[6541]: time="2026-02-13T04:27:34+07:00" level=debug msg="completed challenge"
Feb 13 04:27:34 volumio sudo[6569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:34 volumio sudo[6571]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 04:27:34 volumio volumio[6385]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 04:27:34 volumio sudo[6569]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:34 volumio sudo[6571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:34 volumio volumio[6385]: info: ___________ START PLUGINS ___________
Feb 13 04:27:34 volumio volumio[6385]: info: ControllerMpd::onStart: Initializing MPD
Feb 13 04:27:34 volumio sudo[6567]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:34 volumio go-librespot[6541]: time="2026-02-13T04:27:34+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 13 04:27:34 volumio volumio[6385]: info: Creating MPD Configuration file
Feb 13 04:27:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:27:34 volumio volumio[6385]: info: [1770931654262] CoreMusicLibrary::Adding element Media Servers
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:27:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 13 04:27:34 volumio sudo[6582]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 04:27:34 volumio sudo[6582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:34 volumio volumio[6385]: info: UPNP Browser: Client initialized successfully
Feb 13 04:27:34 volumio sudo[6580]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 04:27:34 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 04:27:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 04:27:34 volumio sudo[6580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:34 volumio systemd[1]: mpd.service: Consumed 7.192s CPU time.
Feb 13 04:27:34 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 04:27:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 04:27:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 04:27:34 volumio sudo[6580]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 04:27:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 04:27:34 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 04:27:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 04:27:34 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 04:27:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 04:27:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 04:27:34 volumio volumio[6385]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 04:27:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 04:27:34 volumio volumio[6385]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:27:34 volumio volumio[6385]: info: [1770931654726] CoreMusicLibrary::Adding element Last_100
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:27:34 volumio volumio[6385]: info: [1770931654740] CoreMusicLibrary::Adding element Webradio
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:27:34 volumio volumio[6385]: info: Initializing BBC Radios
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:27:34 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:35 volumio volumio[6385]: info: Creating Spotify config file
Feb 13 04:27:35 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:35 volumio sudo[6593]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 13 04:27:35 volumio sudo[6593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 13 04:27:35 volumio sudo[6593]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:35 volumio volumio[6510]: Starting albumart workers
Feb 13 04:27:35 volumio volumio[6509]: Starting albumart workers
Feb 13 04:27:35 volumio volumio[6511]: Starting albumart workers
Feb 13 04:27:36 volumio volumio[6385]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:27:36 volumio volumio[6385]: info: [1770931656284] CoreMusicLibrary::Adding element YouTube Music
Feb 13 04:27:36 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:27:36 volumio volumio[6385]: Cannot find translation for source YouTube Music
Feb 13 04:27:36 volumio volumio[6385]: info: Volumio Calling Home
Feb 13 04:27:36 volumio sudo[6613]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 13 04:27:36 volumio sudo[6613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:36 volumio sudo[6613]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:37 volumio volumio[6385]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 13 04:27:37 volumio volumio[6385]: info: Discovery: Found device Volumio
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::volumioGetState
Feb 13 04:27:37 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Feb 13 04:27:37 volumio volumio[6385]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 13 04:27:37 volumio volumio[6385]: info: Discovery: Found device Volumio
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::volumioGetState
Feb 13 04:27:37 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:37 volumio volumio[6385]: info: MPD Permissions set
Feb 13 04:27:37 volumio volumio[6385]: info: MPD Permissions set
Feb 13 04:27:37 volumio volumio[6385]: info: Upmpdcli Daemon Started
Feb 13 04:27:37 volumio go-librespot[6618]: go-librespot daemon starting...
Feb 13 04:27:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:37 volumio volumio[6385]: info: Spotify config file written
Feb 13 04:27:37 volumio go-librespot[6625]: time="2026-02-13T04:27:37+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:37 volumio go-librespot[6625]: time="2026-02-13T04:27:37+07:00" level=debug msg="app state loaded"
Feb 13 04:27:37 volumio go-librespot[6625]: time="2026-02-13T04:27:37+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:37 volumio sudo[6635]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 13 04:27:37 volumio volumio[6385]: 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 13 04:27:37 volumio sudo[6635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 13 04:27:37 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 13 04:27:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:27:37 volumio volumio[6385]: info: No need to fix Spotify hosts
Feb 13 04:27:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:38 volumio go-librespot[6653]: go-librespot daemon starting...
Feb 13 04:27:38 volumio sudo[6635]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+07:00" level=debug msg="app state loaded"
Feb 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+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 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+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 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+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 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+07:00" level=info msg="zeroconf server listening on port 44883"
Feb 13 04:27:38 volumio volumio[6385]: info: Volumio called home
Feb 13 04:27:38 volumio volumio[6385]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 04:27:38 volumio volumio[6385]: SPOTIFY: BQDkeTGasaovpzw2XMWkO5TCqZ_8IvE2pPBroS20hDeauSjU1UM11Oo2zHYbAOtHdFayhwp4EtIyU_ZbDt8wDmmBh0C6BuXIbG0YjoBLmwDgeoGZz3bOK-WqQRi8y1uI1FcDLOFsFD10P1QHtRzUk7Ed0_LG9XUV-Icy46fU2Osv08FbtslbYiBexiQjnF3Tf12dQxJc7vB1bAsCeaVLhxZ_iHOdqIi9L56_kIAWYMBrqWLwY-k3_iMQCxsxEqsQNUEGOMox0gNuaODvnghMQ1tJNpsnOt8PWynqUhZvkW7pTVqVXBneTEMP
Feb 13 04:27:38 volumio volumio[6385]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 04:27:38 volumio volumio[6385]: info: New Spotify access token = BQDkeTGasaovpzw2XMWkO5TCqZ_8IvE2pPBroS20hDeauSjU1UM11Oo2zHYbAOtHdFayhwp4EtIyU_ZbDt8wDmmBh0C6BuXIbG0YjoBLmwDgeoGZz3bOK-WqQRi8y1uI1FcDLOFsFD10P1QHtRzUk7Ed0_LG9XUV-Icy46fU2Osv08FbtslbYiBexiQjnF3Tf12dQxJc7vB1bAsCeaVLhxZ_iHOdqIi9L56_kIAWYMBrqWLwY-k3_iMQCxsxEqsQNUEGOMox0gNuaODvnghMQ1tJNpsnOt8PWynqUhZvkW7pTVqVXBneTEMP
Feb 13 04:27:38 volumio volumio[6385]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 13 04:27:38 volumio volumio[6385]: info: Starting Shairport Sync
Feb 13 04:27:38 volumio volumio[6385]: info: Starting Shairport Sync
Feb 13 04:27:38 volumio go-librespot[6657]: time="2026-02-13T04:27:38+07:00" level=debug msg="obtained new client token: AABkDFCR+fGdXLLpIU6fADEExdH7ON17Ul+LQQK+NGgFsngP3taoK/KgtXyRl8Cisjr4I9U0H2pvadat2iHfs28Id74eeWvDag/JRda2bVO/FA9WdKiaRSStxwjkv+TyLyj2nqGp3nGMbRJX8E7lwRjmKa6oGpQdF24By6hY66bsWgweZs4/pHd4t46Lu6j9d2IlAOFSaxQmq16dG5GdNTuKXWYqwH9iFAc4T6Qcaj/PQUVktgvxSU+boA=="
Feb 13 04:27:38 volumio volumio[6385]: info: Starting Shairport Sync
Feb 13 04:27:38 volumio sudo[6669]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 04:27:38 volumio sudo[6669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:39 volumio sudo[6667]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 04:27:39 volumio go-librespot[6657]: time="2026-02-13T04:27:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:39 volumio sudo[6667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:39 volumio sudo[6665]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 04:27:39 volumio sudo[6665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 13 04:27:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 13 04:27:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 04:27:39 volumio systemd[1]: shairport-sync.service: Consumed 2.413s CPU time.
Feb 13 04:27:39 volumio go-librespot[6657]: time="2026-02-13T04:27:39+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:39 volumio go-librespot[6657]: time="2026-02-13T04:27:39+07:00" level=debug msg="completed challenge"
Feb 13 04:27:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 04:27:39 volumio go-librespot[6657]: time="2026-02-13T04:27:39+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 13 04:27:39 volumio sudo[6669]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:39 volumio sudo[6667]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:39 volumio sudo[6665]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:39 volumio volumio[6385]: info: Shairport-Sync Started
Feb 13 04:27:39 volumio volumio[6385]: Error adding Membership: Error: addMembership EINVAL
Feb 13 04:27:39 volumio volumio[6385]: info: CoreCommandRouter::volumioGetState
Feb 13 04:27:39 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:39 volumio volumio[6385]: info: Shairport-Sync Started
Feb 13 04:27:39 volumio volumio[6385]: info: Shairport-Sync Started
Feb 13 04:27:39 volumio volumio[6385]: 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 13 04:27:39 volumio volumio[6385]: info: Spotify Successfully logged in
Feb 13 04:27:39 volumio volumio[6385]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:27:39 volumio volumio[6385]: info: [1770931659710] CoreMusicLibrary::Adding element Spotify
Feb 13 04:27:39 volumio volumio[6385]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:27:39 volumio volumio[6385]: Cannot find translation for source YouTube Music
Feb 13 04:27:39 volumio volumio[6385]: Cannot find translation for source Spotify
Feb 13 04:27:40 volumio volumio[6385]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 13 04:27:40 volumio volumio[6385]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 04:27:40 volumio volumio[6385]: info: VolumeController:: Volume=100 Mute =false
Feb 13 04:27:40 volumio volumio[6385]: info: CoreCommandRouter::volumioGetState
Feb 13 04:27:40 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:40 volumio volumio[6385]: info: CoreStateMachine::pushState
Feb 13 04:27:40 volumio volumio[6385]: info: CorePlayQueue::getTrack 0
Feb 13 04:27:40 volumio volumio[6385]: info: CoreCommandRouter::volumioPushState
Feb 13 04:27:41 volumio volumio[6385]: info: go-librespot daemon successfully initialized
Feb 13 04:27:42 volumio mpd[6611]: 2026-02-13T04:27:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 13 04:27:42 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 13 04:27:42 volumio sudo[6571]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:42 volumio sudo[6582]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:42 volumio volumio[6385]: error: MPD error: The expression evaluated to a falsy value:
Feb 13 04:27:42 volumio volumio[6385]:   assert.ok(self.idling)
Feb 13 04:27:42 volumio volumio[6385]: error: The expression evaluated to a falsy value:
Feb 13 04:27:42 volumio volumio[6385]:   assert.ok(self.idling)
Feb 13 04:27:42 volumio volumio[6385]: error: updateQueue error: null
Feb 13 04:27:42 volumio volumio[6385]: info: MPD running with PID6611
Feb 13 04:27:42 volumio volumio[6385]:  ,establishing connection
Feb 13 04:27:42 volumio volumio[6385]: info: Completed starting Core Plugins
Feb 13 04:27:42 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:42 volumio volumio[6385]: info: -----    MyVolumio plugins startup     ----
Feb 13 04:27:42 volumio volumio[6385]: info: -------------------------------------------
Feb 13 04:27:42 volumio volumio[6385]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 13 04:27:42 volumio volumio[6385]: error: updateQueue error: null
Feb 13 04:27:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 13 04:27:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:42 volumio go-librespot[6710]: go-librespot daemon starting...
Feb 13 04:27:42 volumio go-librespot[6711]: time="2026-02-13T04:27:42+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:42 volumio go-librespot[6711]: time="2026-02-13T04:27:42+07:00" level=debug msg="app state loaded"
Feb 13 04:27:42 volumio go-librespot[6711]: time="2026-02-13T04:27:42+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+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 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+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 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+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 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+07:00" level=info msg="zeroconf server listening on port 46637"
Feb 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+07:00" level=debug msg="obtained new client token: AACkyEz8abkbU1jrz5MDvL1rj6D/Aoce219u19syVThDpUmEfZcHezP22k9nwS9beVH3l8pAMTl71bEb6Is+2M0l4Fo/7FmXfZ00EEoXdZhqbxOqJb4iMkuToAI1UMQE52mp7a/SDERevBMC+7BgjVkxglMb8TchJtePtAOqj3DX0KuJXAougab+83CgBX+H/YrkL8O96Ds40g0PQCCSeZ5ikDA9eFzKnBL/qA9zwmd06Ud94IDXAo4+nQ=="
Feb 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+07:00" level=debug msg="completed challenge"
Feb 13 04:27:43 volumio go-librespot[6711]: time="2026-02-13T04:27:43+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 13 04:27:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:44 volumio volumio[6385]: info: Initializing connection to go-librespot Websocket
Feb 13 04:27:44 volumio volumio[6385]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:27:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 13 04:27:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:46 volumio go-librespot[6719]: go-librespot daemon starting...
Feb 13 04:27:46 volumio go-librespot[6720]: time="2026-02-13T04:27:46+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:46 volumio go-librespot[6720]: time="2026-02-13T04:27:46+07:00" level=debug msg="app state loaded"
Feb 13 04:27:46 volumio go-librespot[6720]: time="2026-02-13T04:27:46+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:47 volumio volumio[6385]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+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 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+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 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+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 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+07:00" level=info msg="zeroconf server listening on port 44105"
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+07:00" level=debug msg="obtained new client token: AAB+EeTbXERMzl7T+kGogmVEUf2UoAHqk8UQe7luyXfGM5JzLkP+mtT1hA5sXLSwuRn09A3BQVtnqn0jYdLhRnzm4QK/DVOBf4sGMIxv+TOrK26Ae+A4w7uAtpp9B+sr5JPfKWLf/2ihtCq2rEtsgUYJ7wG5pReig84l+vea9bIfMBhcs3SwjspmIZsKlz1ca+nvjk8cNpmA5LCn816hGBV0ofUQZ/aB/AyGF1VO18cFGElnbGJ4Pg1clQ=="
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+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 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 04:27:47 volumio volumio[6385]: info: Initializing connection to go-librespot Websocket
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+07:00" level=debug msg="new websocket client"
Feb 13 04:27:47 volumio volumio[6385]: info: Connection to go-librespot Websocket established
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+07:00" level=debug msg="completed challenge"
Feb 13 04:27:47 volumio go-librespot[6720]: time="2026-02-13T04:27:47+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 13 04:27:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:48 volumio volumio[6385]: info: Connection to go-librespot Websocket closed
Feb 13 04:27:50 volumio volumio[6385]: info: Getting Spotify volume
Feb 13 04:27:50 volumio volumio[6385]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 04:27:50 volumio volumio[6385]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:27:50 volumio volumio[6385]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 13 04:27:50 volumio volumio[6385]:   errno: -111,
Feb 13 04:27:50 volumio volumio[6385]:   code: 'ECONNREFUSED',
Feb 13 04:27:50 volumio volumio[6385]:   syscall: 'connect',
Feb 13 04:27:50 volumio volumio[6385]:   address: '127.0.0.1',
Feb 13 04:27:50 volumio volumio[6385]:   port: 9879,
Feb 13 04:27:50 volumio volumio[6385]:   response: undefined
Feb 13 04:27:50 volumio volumio[6385]: }
Feb 13 04:27:50 volumio volumio[6385]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 04:27:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 13 04:27:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:51 volumio go-librespot[6738]: go-librespot daemon starting...
Feb 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+07:00" level=debug msg="app state loaded"
Feb 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+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 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+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 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+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 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+07:00" level=info msg="zeroconf server listening on port 41697"
Feb 13 04:27:51 volumio go-librespot[6740]: time="2026-02-13T04:27:51+07:00" level=debug msg="obtained new client token: AAAbEgsWdR0qTYxpx1x3YqJjatslFh7J0FpHizzZFVP4v1RJnfRFeJNIeGhaDl+TfVT7fHuitDOHOsp9Z2bfMcHpLB5Apiu2tX8NCgZ7A2fwDIytC2q2HAAT+U4M1OidbvNLsqHSvgf+Kwb4mziELhLBPyOIBkYp8VvMeKp88pvd+F1aAFKGIIbD9GRCZ+A3pjzge2WtcpxVGwPPb5rjAKR4ItD9zHQRmfWvjA/b9pKmFSfbg2V330aNWg=="
Feb 13 04:27:52 volumio go-librespot[6740]: time="2026-02-13T04:27:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:52 volumio go-librespot[6740]: time="2026-02-13T04:27:52+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:52 volumio go-librespot[6740]: time="2026-02-13T04:27:52+07:00" level=debug msg="completed challenge"
Feb 13 04:27:52 volumio go-librespot[6740]: time="2026-02-13T04:27:52+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 13 04:27:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:52 volumio sudo[6763]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 04:26'
Feb 13 04:27:52 volumio sudo[6763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:27:52 volumio sudo[6763]: pam_unix(sudo:session): session closed for user root
Feb 13 04:27:52 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:52 volumio volumio-remote-updater[643]: [2026-02-13 04:27:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 13 04:27:52 volumio volumio-remote-updater[643]: [2026-02-13 04:27:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 13 04:27:52 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 13 04:27:52 volumio systemd[1]: volumio.service: Consumed 49.247s CPU time.
Feb 13 04:27:52 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 04:27:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 04:27:53 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14253.
Feb 13 04:27:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 04:27:53 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 13 04:27:53 volumio systemd[1]: volumio.service: Consumed 49.247s CPU time.
Feb 13 04:27:53 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 13 04:27:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 04:27:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 13 04:27:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:55 volumio go-librespot[6790]: go-librespot daemon starting...
Feb 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+07:00" level=debug msg="app state loaded"
Feb 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+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 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+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 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+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 13 04:27:55 volumio go-librespot[6791]: time="2026-02-13T04:27:55+07:00" level=info msg="zeroconf server listening on port 36147"
Feb 13 04:27:56 volumio go-librespot[6791]: time="2026-02-13T04:27:56+07:00" level=debug msg="obtained new client token: AAD2iL+k82G/96KXJ+Ne7ZDGB5a3uCSqOr8Zwx5sTKkRGamQz2bnn6eotC2b1OdEgh7rAKTattA3AHAq/Elt2ZrpB0WDsziNZQBMDGGPlg/OD4nT1SddiDHSVAlbpahllOM8bztXoR70LVrVBaoBl0jDPw2D2r8SvcQPMgM6X6GK1/BKyWky43uV5xCfZM8tU4BaqSYsaFx+n0ARdWQKFalZML/IfOrt7UxnqLhvAcaquIuJE4RBdEA="
Feb 13 04:27:56 volumio go-librespot[6791]: time="2026-02-13T04:27:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:27:56 volumio go-librespot[6791]: time="2026-02-13T04:27:56+07:00" level=debug msg="completed keyexchange"
Feb 13 04:27:56 volumio go-librespot[6791]: time="2026-02-13T04:27:56+07:00" level=debug msg="completed challenge"
Feb 13 04:27:56 volumio go-librespot[6791]: time="2026-02-13T04:27:56+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 13 04:27:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:27:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:27:56 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:27:56 volumio volumio[6775]: info: -----            Volumio3              ----
Feb 13 04:27:56 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:27:56 volumio volumio[6775]: info: -----          System startup          ----
Feb 13 04:27:56 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:27:57 volumio volumio-remote-updater[643]: [2026-02-13 04:27:57] [connect] Successful connection
Feb 13 04:27:58 volumio volumio[6775]: info: MYVOLUMIO Environment detected
Feb 13 04:27:58 volumio volumio[6775]: info: Plugin folders cleanup
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning into folder /volumio/app/plugins/
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category audio_interface
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category miscellanea
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category music_service
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category plugins.json
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category system_controller
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category user_interface
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning into folder /data/plugins/
Feb 13 04:27:58 volumio volumio[6775]: info: Scanning category music_service
Feb 13 04:27:58 volumio volumio[6775]: info: Plugin folders cleanup completed
Feb 13 04:27:58 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:27:58 volumio volumio[6775]: info: -----      Core plugins startup        ----
Feb 13 04:27:58 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:27:58 volumio volumio[6775]: info: Loading plugins from folder /volumio/app/plugins/
Feb 13 04:27:58 volumio volumio[6775]: info: Adding plugin upnp to MyMusic Plugins
Feb 13 04:27:58 volumio volumio[6775]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 13 04:27:58 volumio volumio[6775]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 13 04:27:58 volumio volumio[6775]: info: Loading plugins from folder /data/plugins/
Feb 13 04:27:58 volumio volumio[6775]: info: Loading plugin "system"...
Feb 13 04:27:58 volumio volumio[6775]: info: Loading plugin "appearance"...
Feb 13 04:27:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 13 04:27:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:27:59 volumio go-librespot[6811]: go-librespot daemon starting...
Feb 13 04:27:59 volumio go-librespot[6812]: time="2026-02-13T04:27:59+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:27:59 volumio go-librespot[6812]: time="2026-02-13T04:27:59+07:00" level=debug msg="app state loaded"
Feb 13 04:27:59 volumio go-librespot[6812]: time="2026-02-13T04:27:59+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+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 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+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 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+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 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+07:00" level=info msg="zeroconf server listening on port 37757"
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "network"...
Feb 13 04:28:00 volumio volumio[6775]: info: Refreshing Cached IP Addresses
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+07:00" level=debug msg="obtained new client token: AAAw+KsVsDJD4Hx+TExH87SLopvNtktNxx02Bx7uHKgkMIweTNRDaxcxJizda++a45yeMJY1Xcq4wbEnaa0iCN6mzNqmNdlOr51709sFoywp4xA25QjF5WLDEwXHajKP+qURw0BTTyAT2dsPB2DpZhmo8NZfJiBHUjn21/uA7uGRvX1VWFxHijxaKsBtudPUQhGYBSbgnGpEHUM4ZQjqIAHOLcx32ggYTgCvS0Qryzbq3NUiqCKov4BJlg=="
Feb 13 04:28:00 volumio sudo[6822]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 04:28:00 volumio sudo[6822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:00 volumio sudo[6824]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 04:28:00 volumio sudo[6824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "services"...
Feb 13 04:28:00 volumio sudo[6822]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "alsa_controller"...
Feb 13 04:28:00 volumio sudo[6824]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+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 13 04:28:00 volumio sudo[6830]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 13 04:28:00 volumio sudo[6830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 04:28:00 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "wizard"...
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "networkfs"...
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+07:00" level=debug msg="completed challenge"
Feb 13 04:28:00 volumio volumio[6775]: info: Starting Udev Watcher for removable devices
Feb 13 04:28:00 volumio go-librespot[6812]: time="2026-02-13T04:28:00+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 13 04:28:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:00 volumio volumio[6775]: info: Ignoring mount for partition: boot
Feb 13 04:28:00 volumio volumio[6775]: info: Ignoring mount for partition: volumio
Feb 13 04:28:00 volumio volumio[6775]: info: Ignoring mount for partition: volumio_data
Feb 13 04:28:00 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "volumio_command_line_client"...
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "upnp"...
Feb 13 04:28:00 volumio volumio[6775]: info: [1770931680850] Starting Upmpd Daemon
Feb 13 04:28:00 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "my_music"...
Feb 13 04:28:00 volumio volumio[6775]: info: Loading plugin "mpd"...
Feb 13 04:28:01 volumio volumio[6775]: info: Loading plugin "upnp_browser"...
Feb 13 04:28:03 volumio sudo[6830]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 13 04:28:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:04 volumio go-librespot[6856]: go-librespot daemon starting...
Feb 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+07:00" level=debug msg="app state loaded"
Feb 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:04 volumio volumio[6775]: info: Starting UPNP Browser
Feb 13 04:28:04 volumio volumio[6775]: info: Loading plugin "alarm-clock"...
Feb 13 04:28:04 volumio volumio[6775]: info: Loading plugin "airplay_emulation"...
Feb 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+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 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+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 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+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 13 04:28:04 volumio volumio[6775]: info: Starting Shairport Sync
Feb 13 04:28:04 volumio go-librespot[6857]: time="2026-02-13T04:28:04+07:00" level=info msg="zeroconf server listening on port 34051"
Feb 13 04:28:04 volumio volumio[6775]: info: Loading plugin "last_100"...
Feb 13 04:28:04 volumio volumio[6775]: info: Loading plugin "webradio"...
Feb 13 04:28:04 volumio volumio[6775]: info: Loading plugin "i2s_dacs"...
Feb 13 04:28:05 volumio go-librespot[6857]: time="2026-02-13T04:28:05+07:00" level=debug msg="obtained new client token: AAAaSw1u41WwgBgxyDp+Wmxs0OmdO0NI0MSd08O98ul45w3jE6JFFcEmJ7na2tPmqP1Vs5HxzTwlsNYRhABps6gmgVlsI/J50jpa5k5HMyvTcbwMV22TF6o9QFSd+YdOzS5tr9zgXro0VeFIugQQwozDvx/etZVGnzZ2mrxk0qWRtfmIMYheuCKJY9KwWqJDlWcK19TYlyOthHfim7iqDXX5EBf4hnxgAwYXfQ6wtST8UzTPcFoJyP37CQ=="
Feb 13 04:28:05 volumio volumio[6775]: info: Loading plugin "volumiodiscovery"...
Feb 13 04:28:05 volumio volumio[6775]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:28:05 volumio volumio[6775]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:28:05 volumio volumio[6775]: *** WARNING *** For more information see 
Feb 13 04:28:05 volumio volumio[6775]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:28:05 volumio volumio[6775]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:28:05 volumio volumio[6775]: *** WARNING *** For more information see 
Feb 13 04:28:05 volumio node[6775]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:28:05 volumio node[6775]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:28:05 volumio node[6775]: *** WARNING *** For more information see 
Feb 13 04:28:05 volumio node[6775]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 04:28:05 volumio node[6775]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 04:28:05 volumio node[6775]: *** WARNING *** For more information see 
Feb 13 04:28:05 volumio volumio[6775]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 13 04:28:05 volumio volumio[6775]: info: Discovery: Started advertising with name: Volumio
Feb 13 04:28:05 volumio go-librespot[6857]: time="2026-02-13T04:28:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:05 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 04:28:05 volumio volumio[6775]: info: Loading plugin "spop"...
Feb 13 04:28:05 volumio go-librespot[6857]: time="2026-02-13T04:28:05+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:05 volumio go-librespot[6857]: time="2026-02-13T04:28:05+07:00" level=debug msg="completed challenge"
Feb 13 04:28:05 volumio go-librespot[6857]: time="2026-02-13T04:28:05+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 13 04:28:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:06 volumio volumio[6775]: info: Loading plugin "ytcr"...
Feb 13 04:28:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 13 04:28:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:08 volumio go-librespot[6867]: go-librespot daemon starting...
Feb 13 04:28:08 volumio go-librespot[6868]: time="2026-02-13T04:28:08+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:08 volumio go-librespot[6868]: time="2026-02-13T04:28:08+07:00" level=debug msg="app state loaded"
Feb 13 04:28:08 volumio go-librespot[6868]: time="2026-02-13T04:28:08+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+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 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+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 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+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 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+07:00" level=info msg="zeroconf server listening on port 36291"
Feb 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+07:00" level=debug msg="obtained new client token: AACsSoL3gDyP1LdPZ00Mf6IBCCQkawgl2E2zx0xRKifpo/WRshoRxAxThdMFoGsGPA+6hE3Xw53cUAubhUxIXI009+Ti/sryhHE+zwgRirq+Pw2eh+Ao1eETPkdK6L/Q04YZaedd6EGzn60cmw9Sf/vJffqxNLzcdnfgKY/hKQoOD7XlLXXfj8qKO4mJVDhiWWzjBAVrwMxb0BZ4VHQMXakqPlEPIGvllGUaAt9IrpzLJmiTHex4jSGUhA=="
Feb 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+07:00" level=debug msg="completed challenge"
Feb 13 04:28:09 volumio volumio[6775]: info: Loading plugin "ytmusic"...
Feb 13 04:28:09 volumio go-librespot[6868]: time="2026-02-13T04:28:09+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 13 04:28:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:10 volumio volumio-remote-updater[643]: [2026-02-13 04:28:10] [connect] Successful connection
Feb 13 04:28:10 volumio volumio[6775]: info: Loading plugin "outputs"...
Feb 13 04:28:10 volumio volumio[6775]: info: Loading plugin "albumart"...
Feb 13 04:28:10 volumio volumio[6775]: info: Plugin example_plugin is not enabled
Feb 13 04:28:10 volumio volumio[6775]: info: Loading plugin "inputs"...
Feb 13 04:28:10 volumio volumio[6775]: info: Loading plugin "updater_comm"...
Feb 13 04:28:10 volumio volumio[6775]: info: Plugin mpdemulation is not enabled
Feb 13 04:28:10 volumio volumio[6775]: info: Loading plugin "rest_api"...
Feb 13 04:28:11 volumio volumio[6775]: info: Loading plugin "websocket"...
Feb 13 04:28:11 volumio volumio[6775]: info: Starting Socket.io Server version 1.7.4
Feb 13 04:28:11 volumio volumio[6775]: info: Loading plugin "RoonBridge"...
Feb 13 04:28:11 volumio volumio[6775]: info: Applying required configuration parameters for plugin RoonBridge
Feb 13 04:28:11 volumio volumio[6775]: info: Loading i18n strings for locale en
Feb 13 04:28:11 volumio volumio[6775]: Updating browse sources language
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::initPlayerControls
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 04:28:11 volumio volumio[6775]: Express server listening on port 3000
Feb 13 04:28:11 volumio volumio[6775]:  [Metrics]  WebUI:  16s 15.09ms 
Feb 13 04:28:11 volumio volumio[6889]: Forking 3 albumart workers
Feb 13 04:28:11 volumio volumio[6775]: info: CoreStateMachine::resetVolumioState
Feb 13 04:28:11 volumio volumio[6775]: info: CoreStateMachine::getcurrentVolume
Feb 13 04:28:11 volumio volumio[6775]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 04:28:12 volumio sudo[6915]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 04:28:12 volumio sudo[6915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:12 volumio sudo[6915]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:12 volumio sudo[6930]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 04:28:12 volumio sudo[6930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:12 volumio sudo[6930]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:12 volumio volumio[6775]: info: Volumio Network Manager: Network status updated: 1
Feb 13 04:28:12 volumio volumio[6775]: info: VolumeController:: Volume=100 Mute =false
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::pushState
Feb 13 04:28:12 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::volumioPushState
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::updateTrackBlock
Feb 13 04:28:12 volumio volumio[6775]: info: CorePlayQueue::getTrackBlock
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 04:28:12 volumio volumio-remote-updater[643]: [2026-02-13 04:28:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770931690 101
Feb 13 04:28:12 volumio volumio[6775]: 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 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:12 volumio volumio[6775]: info: Reloading queue from file
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::setRepeat null single undefined
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::pushState
Feb 13 04:28:12 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::volumioPushState
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::setRandom null
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::pushState
Feb 13 04:28:12 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::volumioPushState
Feb 13 04:28:12 volumio volumio[6775]: info: Setting Device type: Raspberry PI
Feb 13 04:28:12 volumio volumio[6775]: info: Completed loading Core Plugins
Feb 13 04:28:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 13 04:28:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:12 volumio volumio[6775]: info: Preparing to generate the ALSA configuration file
Feb 13 04:28:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:12 volumio go-librespot[6948]: go-librespot daemon starting...
Feb 13 04:28:12 volumio volumio[6775]: info: VolumeController:: Volume=100 Mute =false
Feb 13 04:28:12 volumio volumio[6775]: info: CoreStateMachine::pushState
Feb 13 04:28:12 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:12 volumio volumio[6775]: info: CoreCommandRouter::volumioPushState
Feb 13 04:28:12 volumio go-librespot[6950]: time="2026-02-13T04:28:12+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:13 volumio go-librespot[6950]: time="2026-02-13T04:28:13+07:00" level=debug msg="app state loaded"
Feb 13 04:28:13 volumio go-librespot[6950]: time="2026-02-13T04:28:13+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:13 volumio volumio[6775]: info: Asound.conf file unchanged, so no further update is needed
Feb 13 04:28:13 volumio volumio[6775]: info: Output device has changed, restarting MPD
Feb 13 04:28:13 volumio sudo[6957]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 13 04:28:13 volumio volumio[6775]: info: Output device has changed, restarting Shairport Sync
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:13 volumio sudo[6957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:13 volumio sudo[6959]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 04:28:13 volumio sudo[6959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:13 volumio sudo[6959]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:13 volumio sudo[6961]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 04:28:13 volumio sudo[6961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:13 volumio volumio[6775]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 04:28:13 volumio volumio[6775]: info: ___________ START PLUGINS ___________
Feb 13 04:28:13 volumio volumio[6775]: info: ControllerMpd::onStart: Initializing MPD
Feb 13 04:28:13 volumio volumio[6775]: info: Creating MPD Configuration file
Feb 13 04:28:13 volumio sudo[6957]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 04:28:13 volumio sudo[6970]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:28:13 volumio volumio[6775]: info: [1770931693433] CoreMusicLibrary::Adding element Media Servers
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:28:13 volumio sudo[6970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:13 volumio sudo[6970]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:13 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 04:28:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 04:28:13 volumio systemd[1]: mpd.service: Consumed 7.046s CPU time.
Feb 13 04:28:13 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 04:28:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 04:28:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 04:28:13 volumio volumio[6775]: info: UPNP Browser: Client initialized successfully
Feb 13 04:28:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 04:28:13 volumio sudo[6974]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 04:28:13 volumio sudo[6974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:13 volumio go-librespot[6950]: time="2026-02-13T04:28:13+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 13 04:28:13 volumio go-librespot[6950]: time="2026-02-13T04:28:13+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 13 04:28:13 volumio go-librespot[6950]: time="2026-02-13T04:28:13+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 13 04:28:13 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 04:28:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 04:28:13 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 04:28:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 04:28:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 04:28:13 volumio go-librespot[6950]: time="2026-02-13T04:28:13+07:00" level=info msg="zeroconf server listening on port 40085"
Feb 13 04:28:13 volumio volumio[6775]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 04:28:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 04:28:13 volumio volumio[6775]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:28:13 volumio volumio[6775]: info: [1770931693963] CoreMusicLibrary::Adding element Last_100
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:28:13 volumio volumio[6775]: info: [1770931693982] CoreMusicLibrary::Adding element Webradio
Feb 13 04:28:13 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:28:14 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:28:14 volumio volumio[6775]: info: Initializing BBC Radios
Feb 13 04:28:14 volumio go-librespot[6950]: time="2026-02-13T04:28:14+07:00" level=debug msg="obtained new client token: AAAZ7NsFU1TwOZKgvWsDt4HoWp0lV1y0ORkWmXAbnw3EpsDp6fLWe1fwMLRPVWPHlCJ7Qm7zLeQxwI7fioGnNKc6W4VFsEeY4ykHx42oF33uqYqtj05s831phK8Dr8kjlsF5B/x6X0ZgTerB6T6eEayW+T1hm7Lu/kINRKkrAZR5Fu6QqBy+DeH0VlVLq2jFNxqtrr396vS7tIWQwdp+QX1JyCsaXRkS+baGqXdoMPY0uRcUmDLS"
Feb 13 04:28:14 volumio go-librespot[6950]: time="2026-02-13T04:28:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:14 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 04:28:14 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:14 volumio volumio[6775]: info: Creating Spotify config file
Feb 13 04:28:14 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:14 volumio go-librespot[6950]: time="2026-02-13T04:28:14+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:14 volumio go-librespot[6950]: time="2026-02-13T04:28:14+07:00" level=debug msg="completed challenge"
Feb 13 04:28:14 volumio sudo[6984]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 13 04:28:14 volumio sudo[6984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 13 04:28:14 volumio go-librespot[6950]: time="2026-02-13T04:28:14+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 13 04:28:14 volumio sudo[6984]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:15 volumio volumio[6775]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:28:15 volumio volumio[6775]: info: [1770931695216] CoreMusicLibrary::Adding element YouTube Music
Feb 13 04:28:15 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:28:15 volumio volumio[6775]: Cannot find translation for source YouTube Music
Feb 13 04:28:15 volumio volumio[6775]: info: Volumio Calling Home
Feb 13 04:28:15 volumio volumio[6905]: Starting albumart workers
Feb 13 04:28:15 volumio sudo[7005]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 13 04:28:15 volumio sudo[7005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:15 volumio volumio[6902]: Starting albumart workers
Feb 13 04:28:15 volumio sudo[7005]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:16 volumio volumio[6775]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 13 04:28:16 volumio volumio[6775]: info: Discovery: Found device Volumio
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::volumioGetState
Feb 13 04:28:16 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:16 volumio volumio[6904]: Starting albumart workers
Feb 13 04:28:16 volumio volumio[6775]: info: MPD Permissions set
Feb 13 04:28:16 volumio volumio[6775]: info: MPD Permissions set
Feb 13 04:28:16 volumio volumio[6775]: info: Upmpdcli Daemon Started
Feb 13 04:28:16 volumio volumio[6775]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 13 04:28:16 volumio volumio[6775]: info: Discovery: Found device Volumio
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::volumioGetState
Feb 13 04:28:16 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:16 volumio volumio[6775]: info: Spotify config file written
Feb 13 04:28:16 volumio sudo[7011]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 13 04:28:16 volumio sudo[7011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:16 volumio volumio[6775]: 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 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:16 volumio go-librespot[7018]: go-librespot daemon starting...
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:16 volumio sudo[7011]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:16 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 04:28:16 volumio volumio[6775]: info: No need to fix Spotify hosts
Feb 13 04:28:16 volumio go-librespot[7024]: time="2026-02-13T04:28:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:16 volumio go-librespot[7024]: time="2026-02-13T04:28:16+07:00" level=debug msg="app state loaded"
Feb 13 04:28:16 volumio go-librespot[7024]: time="2026-02-13T04:28:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:17 volumio go-librespot[7024]: time="2026-02-13T04:28:17+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 13 04:28:17 volumio go-librespot[7024]: time="2026-02-13T04:28:17+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 13 04:28:17 volumio go-librespot[7024]: time="2026-02-13T04:28:17+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 13 04:28:17 volumio go-librespot[7024]: time="2026-02-13T04:28:17+07:00" level=info msg="zeroconf server listening on port 40645"
Feb 13 04:28:17 volumio volumio[6775]: info: Volumio called home
Feb 13 04:28:18 volumio go-librespot[7024]: time="2026-02-13T04:28:18+07:00" level=debug msg="obtained new client token: AACOPKjuaxUghkl4Wuddxlw4phnte0KZJ021rup8pwF4Qfj8gp/xF8oMR+kT/pjZfmw413ln3clrn0Z+rB3MGti1nT3KBrCO4ZyUBTeEF5xieVHlm8D1r84J4XclsTdku6R8TZutpKjik9Yj6xKAtKsCIl+cISGUFA1xEOrsDi7iZYXBmZcfdWLAoGxemQyAx2uqRNTGKCSymCvFaZaSMkUlosqMUAc84iBFDvS2D2TRaeipRK5altKA8w=="
Feb 13 04:28:18 volumio volumio[6775]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 04:28:18 volumio volumio[6775]: SPOTIFY: BQDsGrjM7j_Xd4uec3dAKOdIe_-lKuGjKrFTpZ4pYPoBPS_26Kjos4RanWulNioIh3xj_WzTvARAlfwUdipPTkRuDQUqB0CIpnJ8Lzqr3vsxQzo7bJmn0CGP0RqsZz34I_R1d3KsSvn1kLwIgkoij8NY8cLetc4luGUztVjjwJftiC7vuMd4VA89swQn227uD1kE-yQio2lCXhh9MpxFM0QOEJCocSxgmFYKF2-AphPcum220N944g88QDQV2z8H6Kz9H4T6RZ2SJj981ex1xVqTSJ3lP0QarLF0u6hvL8x_5uREceUJt7ow
Feb 13 04:28:18 volumio volumio[6775]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 04:28:18 volumio volumio[6775]: info: New Spotify access token = BQDsGrjM7j_Xd4uec3dAKOdIe_-lKuGjKrFTpZ4pYPoBPS_26Kjos4RanWulNioIh3xj_WzTvARAlfwUdipPTkRuDQUqB0CIpnJ8Lzqr3vsxQzo7bJmn0CGP0RqsZz34I_R1d3KsSvn1kLwIgkoij8NY8cLetc4luGUztVjjwJftiC7vuMd4VA89swQn227uD1kE-yQio2lCXhh9MpxFM0QOEJCocSxgmFYKF2-AphPcum220N944g88QDQV2z8H6Kz9H4T6RZ2SJj981ex1xVqTSJ3lP0QarLF0u6hvL8x_5uREceUJt7ow
Feb 13 04:28:18 volumio volumio[6775]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 13 04:28:18 volumio volumio[6775]: info: Starting Shairport Sync
Feb 13 04:28:18 volumio volumio[6775]: info: Starting Shairport Sync
Feb 13 04:28:18 volumio go-librespot[7024]: time="2026-02-13T04:28:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:18 volumio volumio[6775]: info: Starting Shairport Sync
Feb 13 04:28:18 volumio sudo[7044]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 04:28:18 volumio sudo[7044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:18 volumio go-librespot[7024]: time="2026-02-13T04:28:18+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:18 volumio go-librespot[7024]: time="2026-02-13T04:28:18+07:00" level=debug msg="completed challenge"
Feb 13 04:28:18 volumio sudo[7047]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 04:28:18 volumio sudo[7047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:18 volumio sudo[7049]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 04:28:18 volumio sudo[7049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:18 volumio go-librespot[7024]: time="2026-02-13T04:28:18+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 13 04:28:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 13 04:28:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 13 04:28:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 04:28:18 volumio systemd[1]: shairport-sync.service: Consumed 2.209s CPU time.
Feb 13 04:28:18 volumio volumio[6775]: info: CoreCommandRouter::volumioGetState
Feb 13 04:28:18 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 04:28:18 volumio sudo[7044]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:18 volumio sudo[7047]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:18 volumio sudo[7049]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:18 volumio volumio[6775]: info: Shairport-Sync Started
Feb 13 04:28:18 volumio volumio[6775]: Error adding Membership: Error: addMembership EINVAL
Feb 13 04:28:18 volumio volumio[6775]: info: Shairport-Sync Started
Feb 13 04:28:18 volumio volumio[6775]: info: Shairport-Sync Started
Feb 13 04:28:18 volumio volumio[6775]: 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 13 04:28:18 volumio volumio[6775]: info: Spotify Successfully logged in
Feb 13 04:28:18 volumio volumio[6775]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 04:28:18 volumio volumio[6775]: info: [1770931698892] CoreMusicLibrary::Adding element Spotify
Feb 13 04:28:18 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 04:28:18 volumio volumio[6775]: Cannot find translation for source YouTube Music
Feb 13 04:28:18 volumio volumio[6775]: Cannot find translation for source Spotify
Feb 13 04:28:19 volumio volumio[6775]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 13 04:28:19 volumio volumio[6775]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 04:28:19 volumio volumio[6775]: info: VolumeController:: Volume=100 Mute =false
Feb 13 04:28:19 volumio volumio[6775]: info: CoreCommandRouter::volumioGetState
Feb 13 04:28:19 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:19 volumio volumio[6775]: info: CoreStateMachine::pushState
Feb 13 04:28:19 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:19 volumio volumio[6775]: info: CoreCommandRouter::volumioPushState
Feb 13 04:28:21 volumio volumio[6775]: info: go-librespot daemon successfully initialized
Feb 13 04:28:21 volumio mpd[7003]: 2026-02-13T04:28:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 13 04:28:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 13 04:28:21 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 13 04:28:21 volumio sudo[6961]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:21 volumio sudo[6974]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:21 volumio go-librespot[7092]: go-librespot daemon starting...
Feb 13 04:28:21 volumio go-librespot[7095]: time="2026-02-13T04:28:21+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:21 volumio go-librespot[7095]: time="2026-02-13T04:28:21+07:00" level=debug msg="app state loaded"
Feb 13 04:28:21 volumio go-librespot[7095]: time="2026-02-13T04:28:21+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:21 volumio volumio[6775]: error: MPD error: The expression evaluated to a falsy value:
Feb 13 04:28:21 volumio volumio[6775]:   assert.ok(self.idling)
Feb 13 04:28:21 volumio volumio[6775]: error: The expression evaluated to a falsy value:
Feb 13 04:28:21 volumio volumio[6775]:   assert.ok(self.idling)
Feb 13 04:28:21 volumio volumio[6775]: error: updateQueue error: null
Feb 13 04:28:21 volumio volumio[6775]: info: MPD running with PID7003
Feb 13 04:28:21 volumio volumio[6775]:  ,establishing connection
Feb 13 04:28:21 volumio volumio[6775]: info: Completed starting Core Plugins
Feb 13 04:28:21 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:28:21 volumio volumio[6775]: info: -----    MyVolumio plugins startup     ----
Feb 13 04:28:21 volumio volumio[6775]: info: -------------------------------------------
Feb 13 04:28:21 volumio volumio[6775]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 13 04:28:21 volumio volumio[6775]: error: updateQueue error: null
Feb 13 04:28:21 volumio go-librespot[7095]: time="2026-02-13T04:28: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 04:28:21 volumio go-librespot[7095]: time="2026-02-13T04:28:21+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 13 04:28:21 volumio go-librespot[7095]: time="2026-02-13T04:28:21+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 13 04:28:22 volumio go-librespot[7095]: time="2026-02-13T04:28:22+07:00" level=info msg="zeroconf server listening on port 34209"
Feb 13 04:28:22 volumio go-librespot[7095]: time="2026-02-13T04:28:22+07:00" level=debug msg="obtained new client token: AACClAAhLLejajEVWHn30ir/H1R2mn2wjqNMZxX5Y9bk4QmpvddV0zqC3t52RJNcQySeVpX9ewTlsmc9jbbw+RhnEHxnuIdEZyE52i2I0kGCW7g4iBUk/H/uE0q/445NHG6s8HzZxgGZlgmnvQfZWf5bIA+Sam8EqAyT1X7QKjUndHlNB1Hy2T6oxjD4vERVob1qpP2q0+4z5o80FCiD036ekJLvapCyATGEJMCCVx/mcy1SSmwrDgs="
Feb 13 04:28:22 volumio go-librespot[7095]: time="2026-02-13T04:28:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:22 volumio go-librespot[7095]: time="2026-02-13T04:28:22+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:22 volumio go-librespot[7095]: time="2026-02-13T04:28:22+07:00" level=debug msg="completed challenge"
Feb 13 04:28:22 volumio go-librespot[7095]: time="2026-02-13T04:28: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 13 04:28:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:24 volumio volumio[6775]: info: Initializing connection to go-librespot Websocket
Feb 13 04:28:24 volumio volumio[6775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:28:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 13 04:28:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:25 volumio go-librespot[7102]: go-librespot daemon starting...
Feb 13 04:28:25 volumio go-librespot[7103]: time="2026-02-13T04:28:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:25 volumio go-librespot[7103]: time="2026-02-13T04:28:25+07:00" level=debug msg="app state loaded"
Feb 13 04:28:25 volumio go-librespot[7103]: time="2026-02-13T04:28:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+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 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+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 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+07:00" level=info msg="zeroconf server listening on port 44035"
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+07:00" level=debug msg="obtained new client token: AADTtbshHJdXsm+U3XPU4kzRCIbM7q/4AdU59FgjFlX0bvtDiwOFUdDUTX+PCh2EEaZ/w5RDqQVghsTAkwThCna0upd1Xl/00BvVncDpjHT6Y/QElePC3vLIqlwVN+ntLHZpLOISzu80QaFzkBAEEU9JdIIFSbPmT694F3aSRxpOrrmD+D+fJM+bn9LOC3muzjTDtxc62999W/0DEt51OHo94A8ZCzROgxMxFjZ21WW45uTVK3MBvLgeog=="
Feb 13 04:28:26 volumio volumio[6775]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28:26+07:00" level=debug msg="completed challenge"
Feb 13 04:28:26 volumio go-librespot[7103]: time="2026-02-13T04:28: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 13 04:28:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:27 volumio volumio[6775]: info: Initializing connection to go-librespot Websocket
Feb 13 04:28:27 volumio volumio[6775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 04:28:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Feb 13 04:28:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:29 volumio go-librespot[7114]: go-librespot daemon starting...
Feb 13 04:28:29 volumio go-librespot[7115]: time="2026-02-13T04:28:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:29 volumio go-librespot[7115]: time="2026-02-13T04:28:29+07:00" level=debug msg="app state loaded"
Feb 13 04:28:29 volumio go-librespot[7115]: time="2026-02-13T04:28:29+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:30 volumio volumio[6775]: info: Initializing connection to go-librespot Websocket
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+07:00" level=debug msg="new websocket client"
Feb 13 04:28:30 volumio volumio[6775]: info: Connection to go-librespot Websocket established
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28: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-gew4.spotify.com:80]"
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+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 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+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 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+07:00" level=info msg="zeroconf server listening on port 33387"
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin multiroom to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 13 04:28:30 volumio volumio[6775]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+07:00" level=debug msg="obtained new client token: AAAc8S9v5FEBN0/OxoHxMQgSY88soH6tCbvCNlemTAU4VURnDcaCKLRbBjQy32NXzMFasRPpQ1vnVnOug0SZyaU/lAb5mrKNbHtrxbltOrSLhAMr4h0mmpcb12O5MUQBIY18QPDnSzhIF/Ma4Y5V1RpV/xl2CKEBBFLStXSC7nTYE/ge9VTnTGjDGesT+MAX7cuWO0eLuFXvRZCndRXmdDz3d9y/nT+SfWYLymKoFyQBqIgRP0Qie/4Sxg=="
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28:30+07:00" level=debug msg="completed challenge"
Feb 13 04:28:30 volumio go-librespot[7115]: time="2026-02-13T04:28: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 13 04:28:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:32 volumio volumio[6775]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 13 04:28:32 volumio volumio[6775]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 13 04:28:32 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:32 volumio volumio[6775]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 04:28:32 volumio volumio[6775]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 13 04:28:32 volumio volumio[6775]: info: MyVolumio login type: Token
Feb 13 04:28:32 volumio volumio[6775]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 13 04:28:32 volumio volumio[6775]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 13 04:28:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 13 04:28:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 04:28:34 volumio go-librespot[7136]: go-librespot daemon starting...
Feb 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28:34+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28:34+07:00" level=debug msg="app state loaded"
Feb 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28:34+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 04:28:34 volumio volumio[6775]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 13 04:28:34 volumio volumio[6775]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 13 04:28:34 volumio volumio[6775]: info: Streaming services startup
Feb 13 04:28:34 volumio volumio[6775]: info: Starting Streaming Daemon
Feb 13 04:28:34 volumio sudo[7145]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 13 04:28:34 volumio sudo[7145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 04:28:34 volumio volumio[6775]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 13 04:28:34 volumio sudo[7145]: pam_unix(sudo:session): session closed for user root
Feb 13 04:28:34 volumio volumio[6775]: info: Getting Spotify volume
Feb 13 04:28:34 volumio volumio[6775]: info: Connection to go-librespot Websocket closed
Feb 13 04:28:34 volumio volumio[6775]: error: Cannot start Volumio Streaming Daemon
Feb 13 04:28:34 volumio volumio[6775]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 13 04:28:34 volumio volumio[6775]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 13 04:28:34 volumio volumio[6775]: 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 13 04:28:34 volumio volumio[6775]: info: CoreCommandRouter::volumioGetState
Feb 13 04:28:34 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:34 volumio volumio[6775]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 13 04:28:34 volumio volumio[6775]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 13 04:28:34 volumio volumio[6775]: SPOTIFY: VOLUMIO VOLUME 100
Feb 13 04:28:34 volumio volumio[6775]: info: Aligning Spotify Volume to Volumio Volume
Feb 13 04:28:34 volumio volumio[6775]: info: CoreCommandRouter::volumioGetState
Feb 13 04:28:34 volumio volumio[6775]: info: CorePlayQueue::getTrack 0
Feb 13 04:28:34 volumio volumio[6775]: info: Setting Spotify Volume from Volumio: 100
Feb 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28: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 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28: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 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28: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 13 04:28:34 volumio go-librespot[7137]: time="2026-02-13T04:28:34+07:00" level=info msg="zeroconf server listening on port 41301"
Feb 13 04:28:35 volumio go-librespot[7137]: time="2026-02-13T04:28:35+07:00" level=debug msg="obtained new client token: AADFDg6AZ+zrZBdH/K4yF0JdbDKVXk/wtpFp1r24PLJgQGJ2wASKHyx5rXRcZyvkOc/teXF9JiqeDWCG7fcUneVeKmHKx/bgOxr265Oq63T4NIyVtItm5JqKd89pKSAWPhAvBjPGwlW/QsGf/bbEuengmWL9m1LHEdFXUKEviufC49fn64+Eq47QT1trcEfRfY0KHCpu39AlJylRlABWHcTgHKPklpLYXfuJvPCfEnf4dZqeO551LUAv1A=="
Feb 13 04:28:35 volumio go-librespot[7137]: time="2026-02-13T04:28:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 04:28:35 volumio go-librespot[7137]: time="2026-02-13T04:28:35+07:00" level=debug msg="completed keyexchange"
Feb 13 04:28:35 volumio go-librespot[7137]: time="2026-02-13T04:28:35+07:00" level=debug msg="completed challenge"
Feb 13 04:28:35 volumio go-librespot[7137]: time="2026-02-13T04:28: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 13 04:28:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 04:28:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 04:28:35 volumio volumio[6775]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 04:28:35 volumio volumio[6775]: Error: socket hang up
Feb 13 04:28:35 volumio volumio[6775]:     at connResetException (node:internal/errors:720:14)
Feb 13 04:28:35 volumio volumio[6775]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 13 04:28:35 volumio volumio[6775]:     at Socket.emit (node:events:526:35)
Feb 13 04:28:35 volumio volumio[6775]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 13 04:28:35 volumio volumio[6775]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 13 04:28:35 volumio volumio[6775]:   code: 'ECONNRESET',
Feb 13 04:28:35 volumio volumio[6775]:   response: undefined
Feb 13 04:28:35 volumio volumio[6775]: }
Feb 13 04:28:35 volumio volumio[6775]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 04:28:36 volumio sudo[7165]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 04:27'
Feb 13 04:28:36 volumio sudo[7165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="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"