Feb 09 04:12:00 volumio volumio[8540]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:12:00 volumio volumio[8540]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:12:00 volumio volumio[8540]: info: Streaming services startup Feb 09 04:12:00 volumio volumio[8540]: info: Starting Streaming Daemon Feb 09 04:12:00 volumio sudo[8900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:12:00 volumio sudo[8900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:00 volumio volumio[8540]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:12:00 volumio sudo[8900]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:00 volumio volumio[8540]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:00 volumio volumio[8540]: error: Cannot start Volumio Streaming Daemon Feb 09 04:12:00 volumio volumio[8540]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:12:00 volumio volumio[8540]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:12:00 volumio volumio[8540]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 04:12:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:00 volumio go-librespot[8906]: go-librespot daemon starting... Feb 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12:00+07:00" level=debug msg="app state loaded" Feb 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12: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 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12: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 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12: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 09 04:12:00 volumio go-librespot[8907]: time="2026-02-09T04:12:00+07:00" level=info msg="zeroconf server listening on port 41065" Feb 09 04:12:01 volumio go-librespot[8907]: time="2026-02-09T04:12:01+07:00" level=debug msg="obtained new client token: AAD11WegKZ3+a5dHdOf4em5gryVd70Vlve4fwXJ9gjP5NLUFzjO+iTKmBPVEUSgMMWyHiYjjDeHlKlbhva4ta71hmCgpTo2I0ZMc3wdq3KmCJlDXcw+VDWMM39JbQ1MRA6GSeREsD667Rhfiz9sJ3I2OlBx7+XEdAS+srttwDQ1AwC4NDwUdcsmA5DAep/7OwPNsnzFdC7W5JBsSKOv/aL5eTqVz1RNONYiI0IQ7YKSv/9/akTLQFCQ=" Feb 09 04:12:01 volumio volumio[8540]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 09 04:12:01 volumio go-librespot[8907]: time="2026-02-09T04:12:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:01 volumio go-librespot[8907]: time="2026-02-09T04:12:01+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:01 volumio go-librespot[8907]: time="2026-02-09T04:12:01+07:00" level=debug msg="completed challenge" Feb 09 04:12:01 volumio go-librespot[8907]: time="2026-02-09T04:12:01+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 09 04:12:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:02 volumio volumio[8540]: info: MyVolumio token set successfully Feb 09 04:12:02 volumio volumio[8540]: info: MYVOLUMIO: Adding device Feb 09 04:12:02 volumio volumio[8540]: info: MYVOLUMIO: Evaluating Server Feb 09 04:12:02 volumio volumio[8540]: info: MyVolumio status changed Feb 09 04:12:02 volumio volumio[8540]: info: Streaming services startup Feb 09 04:12:02 volumio volumio[8540]: info: Starting Streaming Daemon Feb 09 04:12:02 volumio volumio[8540]: info: Removing browser output: myVolumio user plan is not superstar Feb 09 04:12:02 volumio volumio[8540]: info: Removing audio output: Feb 09 04:12:02 volumio volumio[8540]: info: Stoppping Tunnel 1 Feb 09 04:12:02 volumio sudo[8935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:12:02 volumio sudo[8935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:02 volumio sudo[8935]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:03 volumio sudo[8938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 09 04:12:03 volumio sudo[8938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:03 volumio volumio[8540]: error: Cannot start Volumio Streaming Daemon Feb 09 04:12:03 volumio volumio[8540]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:12:03 volumio volumio[8540]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:12:03 volumio volumio[8540]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:12:03 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:03 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:03 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:03 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 09 04:12:03 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 09 04:12:03 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 09 04:12:03 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 09 04:12:03 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 09 04:12:03 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 09 04:12:03 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 09 04:12:03 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 09 04:12:03 volumio sudo[8938]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:03 volumio volumio[8540]: info: Remote SSH Stopped Feb 09 04:12:03 volumio volumio[8540]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:03 volumio volumio[8540]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:03 volumio volumio[8540]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:12:04 volumio volumio[8540]: info: Updating MyVolumio device info Feb 09 04:12:04 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:04 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:04 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 09 04:12:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:04 volumio go-librespot[8940]: go-librespot daemon starting... Feb 09 04:12:04 volumio go-librespot[8941]: time="2026-02-09T04:12:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:04 volumio go-librespot[8941]: time="2026-02-09T04:12:04+07:00" level=debug msg="app state loaded" Feb 09 04:12:04 volumio go-librespot[8941]: time="2026-02-09T04:12:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+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 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+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 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+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 09 04:12:05 volumio volumio[8540]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+07:00" level=info msg="zeroconf server listening on port 33627" Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+07:00" level=debug msg="obtained new client token: AAA6kAZ5XWpyVorYWyk27osg7+DOkSCbzerLmzCu/Mp6ZBkH7e/r/RMlHd7VHdCWAG6QAq7g51tt1c5Y7KK1qT/xCmS30XKd20syU+78CTbGtmhWStmXgcfmkYzKFyoEknNHwzcTMr0nVSFnH2WVBtPr/4f5yGhm2S4BCRvW1Cic9pB24sMNxBW89JjAofaV/JO95jzDtRBZt3kfE4FHsDw9OeEnp1KgggCivAscMgbl/dndEA5/QtNfGA==" Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12:05+07:00" level=debug msg="completed challenge" Feb 09 04:12:05 volumio go-librespot[8941]: time="2026-02-09T04:12: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 09 04:12:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:06 volumio volumio[8540]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:06 volumio volumio[8540]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:07 volumio volumio[8540]: info: MYVOLUMIO: Adding device Feb 09 04:12:07 volumio volumio[8540]: info: MYVOLUMIO: Evaluating Server Feb 09 04:12:08 volumio volumio[8540]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:12:08 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:08 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:08 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 09 04:12:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:08 volumio go-librespot[8980]: go-librespot daemon starting... Feb 09 04:12:08 volumio volumio[8540]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:12:08 volumio go-librespot[8981]: time="2026-02-09T04:12:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:08 volumio go-librespot[8981]: time="2026-02-09T04:12:08+07:00" level=debug msg="app state loaded" Feb 09 04:12:08 volumio go-librespot[8981]: time="2026-02-09T04:12:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:09 volumio volumio[8540]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+07:00" level=debug msg="new websocket client" Feb 09 04:12:09 volumio volumio[8540]: info: Connection to go-librespot Websocket established Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+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 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+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 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+07:00" level=info msg="zeroconf server listening on port 38673" Feb 09 04:12:09 volumio volumio[8540]: info: Updating MyVolumio device info Feb 09 04:12:09 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:09 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:09 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+07:00" level=debug msg="obtained new client token: AACN2S40aCYTgsypbHZUPN/+3qQKuGMg8VrCRMLKhY6m1HzCe2ka+u+tSid953TN+DUjvqTkHWOx3BgIC1/VPUq1TX4RxTyDjusJpb10Jfliv4esgYv+B+l3PlbM+L1KZkVoE+m5dxOJo8dfztUdpTwG0wzk2F/3kg4YHeN9LBHfFsmdAAQWWq2iLGNd0Hr3jwg4VDytEUX8Btd1CugjcRgMatPw2ndka8dzej2Uxx9HYvkGk09PR4RFpg==" Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12:09+07:00" level=debug msg="completed challenge" Feb 09 04:12:09 volumio go-librespot[8981]: time="2026-02-09T04:12: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 09 04:12:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:09 volumio volumio[8540]: info: Connection to go-librespot Websocket closed Feb 09 04:12:09 volumio volumio[8540]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:12:11 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:12:11 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:11 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 09 04:12:11 volumio volumio-remote-updater[643]: Test mode disabled Feb 09 04:12:11 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 09 04:12:11 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 09 04:12:11 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 09 04:12:12 volumio volumio[8540]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 09 04:12:12 volumio volumio[8540]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 09 04:12:12 volumio volumio[8540]: info: Getting Spotify volume Feb 09 04:12:12 volumio volumio[8540]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:12:12 volumio volumio[8540]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:12 volumio volumio[8540]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 04:12:12 volumio volumio[8540]: errno: -111, Feb 09 04:12:12 volumio volumio[8540]: code: 'ECONNREFUSED', Feb 09 04:12:12 volumio volumio[8540]: syscall: 'connect', Feb 09 04:12:12 volumio volumio[8540]: address: '127.0.0.1', Feb 09 04:12:12 volumio volumio[8540]: port: 9879, Feb 09 04:12:12 volumio volumio[8540]: response: undefined Feb 09 04:12:12 volumio volumio[8540]: } Feb 09 04:12:12 volumio volumio[8540]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:12:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 09 04:12:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:13 volumio go-librespot[9006]: go-librespot daemon starting... Feb 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+07:00" level=debug msg="app state loaded" Feb 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+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 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+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 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+07:00" level=info msg="zeroconf server listening on port 44215" Feb 09 04:12:13 volumio sudo[9016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:11' Feb 09 04:12:13 volumio sudo[9016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:13 volumio go-librespot[9007]: time="2026-02-09T04:12:13+07:00" level=debug msg="obtained new client token: AADc/w7qnLA6aOYPhM109bhDvYXPjnyD3dArx5X1JJ2w/FBPrPz/PkcWrKbYPv0O4y8t4ex/qaZcnocnzz6pN9yexKhH1nNQyCBnZQ57ZhRbBrcWHYkw9s+gg2RAkyZlsIjGybKfiRjRVleTGm3jNVshRZFAOxCYeTSuIoSgHNejMrChO0oTXocKjTZN2OP+YOeLh5c7Nf48Z7vn4ufre41S/NkY0WFnmNjfT80x3wn5iAmYJfSpg2eScQ==" Feb 09 04:12:14 volumio go-librespot[9007]: time="2026-02-09T04:12:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:14 volumio sudo[9016]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:14 volumio go-librespot[9007]: time="2026-02-09T04:12:14+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:14 volumio go-librespot[9007]: time="2026-02-09T04:12:14+07:00" level=debug msg="completed challenge" Feb 09 04:12:14 volumio go-librespot[9007]: time="2026-02-09T04:12: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 09 04:12:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:15 volumio volumio-remote-updater[643]: [2026-02-09 04:12:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 04:12:15 volumio volumio-remote-updater[643]: [2026-02-09 04:12:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 04:12:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 04:12:15 volumio systemd[1]: volumio.service: Consumed 58.383s CPU time. Feb 09 04:12:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:12:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:12:15 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8184. Feb 09 04:12:15 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:12:15 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 04:12:15 volumio systemd[1]: volumio.service: Consumed 58.383s CPU time. Feb 09 04:12:15 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 04:12:15 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:12:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 09 04:12:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:17 volumio go-librespot[9046]: go-librespot daemon starting... Feb 09 04:12:17 volumio go-librespot[9047]: time="2026-02-09T04:12:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:17 volumio go-librespot[9047]: time="2026-02-09T04:12:17+07:00" level=debug msg="app state loaded" Feb 09 04:12:17 volumio go-librespot[9047]: time="2026-02-09T04:12:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+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 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+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 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+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 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+07:00" level=info msg="zeroconf server listening on port 34805" Feb 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+07:00" level=debug msg="obtained new client token: AACJgVPHMQbwsUSlU8esy0wxZqc6br3uXhhL8TeAk/Oxf+rOIYbQplrHavYBRyrjL1sRWbcDvuQd93pANn2WpH40OExMru33l045scQtGABq4K1TwG7w2YBZBuslz7fLOotebuj1k/Tbx7POY9T2i2EAuj8L1zb3dE4ZivtR3NFnmlV2Nf8upXllpo4GbBC09GXCmY6SfV1bAowhWoDMOJY8AnWRRqTYRfKEW2MRovgdToF5jcKi36fyvA==" Feb 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12:18+07:00" level=debug msg="completed challenge" Feb 09 04:12:18 volumio go-librespot[9047]: time="2026-02-09T04:12: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 09 04:12:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:19 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:19 volumio volumio[9031]: info: ----- Volumio3 ---- Feb 09 04:12:19 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:19 volumio volumio[9031]: info: ----- System startup ---- Feb 09 04:12:19 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:20 volumio volumio-remote-updater[643]: [2026-02-09 04:12:20] [connect] Successful connection Feb 09 04:12:20 volumio volumio[9031]: info: MYVOLUMIO Environment detected Feb 09 04:12:20 volumio volumio[9031]: info: Plugin folders cleanup Feb 09 04:12:20 volumio volumio[9031]: info: Scanning into folder /volumio/app/plugins/ Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category audio_interface Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category miscellanea Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category music_service Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category plugins.json Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category system_controller Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category user_interface Feb 09 04:12:20 volumio volumio[9031]: info: Scanning into folder /data/plugins/ Feb 09 04:12:20 volumio volumio[9031]: info: Scanning category music_service Feb 09 04:12:20 volumio volumio[9031]: info: Plugin folders cleanup completed Feb 09 04:12:20 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:21 volumio volumio[9031]: info: ----- Core plugins startup ---- Feb 09 04:12:21 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:21 volumio volumio[9031]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 04:12:21 volumio volumio[9031]: info: Adding plugin upnp to MyMusic Plugins Feb 09 04:12:21 volumio volumio[9031]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 04:12:21 volumio volumio[9031]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 04:12:21 volumio volumio[9031]: info: Loading plugins from folder /data/plugins/ Feb 09 04:12:21 volumio volumio[9031]: info: Loading plugin "system"... Feb 09 04:12:21 volumio volumio[9031]: info: Loading plugin "appearance"... Feb 09 04:12:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 09 04:12:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:21 volumio go-librespot[9066]: go-librespot daemon starting... Feb 09 04:12:21 volumio go-librespot[9067]: time="2026-02-09T04:12:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:21 volumio go-librespot[9067]: time="2026-02-09T04:12:21+07:00" level=debug msg="app state loaded" Feb 09 04:12:21 volumio go-librespot[9067]: time="2026-02-09T04:12:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+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 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+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 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+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 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+07:00" level=info msg="zeroconf server listening on port 42401" Feb 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+07:00" level=debug msg="obtained new client token: AADBZY/AVS8k4+iWdA+tfgCv2kOb82sgMnAaaeGSnlGceAuMzW0nal7H4rmRoOlNFDxmWPnRP+WvkN34Z7FAjNLuIe9J3vil3cs/YTf5FKZ6BlJuDygwE/ZhojR+fzKJrWIjgATKewSMsF1ChDQl4P6XdgV9MtQMUJyoZwdop76OIhR3WrLnb6TcnMhgIp5DWBhUewq8rywaSEOXAQRP1yvZ6WiCwCPqtVlD/dLe70Q633fS6t6eBN2QMA==" Feb 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:22 volumio go-librespot[9067]: time="2026-02-09T04:12:22+07:00" level=debug msg="completed challenge" Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "network"... Feb 09 04:12:23 volumio volumio[9031]: info: Refreshing Cached IP Addresses Feb 09 04:12:23 volumio go-librespot[9067]: time="2026-02-09T04:12:23+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 09 04:12:23 volumio sudo[9075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:12:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:23 volumio sudo[9075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:23 volumio sudo[9077]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:12:23 volumio sudo[9077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:23 volumio sudo[9075]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "services"... Feb 09 04:12:23 volumio sudo[9077]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "alsa_controller"... Feb 09 04:12:23 volumio sudo[9087]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 04:12:23 volumio sudo[9087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:23 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "wizard"... Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "networkfs"... Feb 09 04:12:23 volumio volumio[9031]: info: Starting Udev Watcher for removable devices Feb 09 04:12:23 volumio volumio[9031]: info: Ignoring mount for partition: boot Feb 09 04:12:23 volumio volumio[9031]: info: Ignoring mount for partition: volumio Feb 09 04:12:23 volumio volumio[9031]: info: Ignoring mount for partition: volumio_data Feb 09 04:12:23 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "volumio_command_line_client"... Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "upnp"... Feb 09 04:12:23 volumio volumio[9031]: info: [1770585143437] Starting Upmpd Daemon Feb 09 04:12:23 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "my_music"... Feb 09 04:12:23 volumio volumio[9031]: info: Loading plugin "mpd"... Feb 09 04:12:24 volumio volumio[9031]: info: Loading plugin "upnp_browser"... Feb 09 04:12:25 volumio sudo[9087]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 09 04:12:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:26 volumio go-librespot[9108]: go-librespot daemon starting... Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=debug msg="app state loaded" Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:12:26 volumio go-librespot[9109]: time="2026-02-09T04:12:26+07:00" level=info msg="zeroconf server listening on port 35819" Feb 09 04:12:27 volumio volumio[9031]: info: Starting UPNP Browser Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "alarm-clock"... Feb 09 04:12:27 volumio go-librespot[9109]: time="2026-02-09T04:12:27+07:00" level=debug msg="obtained new client token: AABBNTushJ1EXYva+tnr1S5zuko7dKuWagJES+WdFIK+HmCoEFm2VAxAwA9nWbeRIyy38hUKbxy6h9cNGRt5M6Du6cYevvqRLAtb+jeXgMZXbfvXmVW5L+9JarBxSUiZY7CVVY2cDcgKC4/ebwBRT5FDzT+MlGBi5ZBjuFPlcIVR+EqlRnOECxpIIBnX2ojHFXcqGZbk5/x4YGUMS8FeWbZ3mih8Dm+R5GVniLe7alFHb0Gpzaj0Fzk=" Feb 09 04:12:27 volumio go-librespot[9109]: time="2026-02-09T04:12:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "airplay_emulation"... Feb 09 04:12:27 volumio go-librespot[9109]: time="2026-02-09T04:12:27+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:27 volumio go-librespot[9109]: time="2026-02-09T04:12:27+07:00" level=debug msg="completed challenge" Feb 09 04:12:27 volumio volumio[9031]: info: Starting Shairport Sync Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "last_100"... Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "webradio"... Feb 09 04:12:27 volumio go-librespot[9109]: time="2026-02-09T04:12:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:12:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "i2s_dacs"... Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "volumiodiscovery"... Feb 09 04:12:27 volumio volumio[9031]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:12:27 volumio volumio[9031]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:12:27 volumio volumio[9031]: *** WARNING *** For more information see Feb 09 04:12:27 volumio volumio[9031]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:12:27 volumio volumio[9031]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:12:27 volumio volumio[9031]: *** WARNING *** For more information see Feb 09 04:12:27 volumio node[9031]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:12:27 volumio node[9031]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:12:27 volumio node[9031]: *** WARNING *** For more information see Feb 09 04:12:27 volumio node[9031]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:12:27 volumio node[9031]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:12:27 volumio node[9031]: *** WARNING *** For more information see Feb 09 04:12:27 volumio volumio[9031]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 04:12:27 volumio volumio[9031]: info: Discovery: Started advertising with name: Volumio Feb 09 04:12:27 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:12:27 volumio volumio[9031]: info: Loading plugin "spop"... Feb 09 04:12:29 volumio volumio[9031]: info: Loading plugin "ytcr"... Feb 09 04:12:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 09 04:12:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:30 volumio go-librespot[9120]: go-librespot daemon starting... Feb 09 04:12:30 volumio go-librespot[9121]: time="2026-02-09T04:12:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:30 volumio go-librespot[9121]: time="2026-02-09T04:12:30+07:00" level=debug msg="app state loaded" Feb 09 04:12:30 volumio go-librespot[9121]: time="2026-02-09T04:12:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=info msg="zeroconf server listening on port 38827" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="obtained new client token: AABS4QZPz1uCQpk67MpxPQ8UEmsPHDzO2bkJ42WWR5UjsG7zkREcPDAY9eJJqPKEB53VgKnv2nhCIko4Y9TGNxmjOmVy06E7j2If3kHkQx4N17QwPbmxlJBtb1x1lHWgvP1Cm16vAVgxm4fWngm3ZOxJPvKA9wmP8rFAP4vf9a8fmPkQ5uiKZdYKTlO5+FnDF2QppxgD5iuUM2+NeUUqTT2Qw3w/nfnUhDVF6I/B6lp25CK+dYkw4U/8Jw==" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=debug msg="completed challenge" Feb 09 04:12:31 volumio go-librespot[9121]: time="2026-02-09T04:12:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:12:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:32 volumio volumio[9031]: info: Loading plugin "ytmusic"... Feb 09 04:12:33 volumio volumio-remote-updater[643]: [2026-02-09 04:12:33] [connect] Successful connection Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "outputs"... Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "albumart"... Feb 09 04:12:33 volumio volumio[9031]: info: Plugin example_plugin is not enabled Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "inputs"... Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "updater_comm"... Feb 09 04:12:33 volumio volumio[9031]: info: Plugin mpdemulation is not enabled Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "rest_api"... Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "websocket"... Feb 09 04:12:33 volumio volumio[9031]: info: Starting Socket.io Server version 1.7.4 Feb 09 04:12:33 volumio volumio[9031]: info: Loading plugin "RoonBridge"... Feb 09 04:12:34 volumio volumio[9031]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 04:12:34 volumio volumio[9031]: info: Loading i18n strings for locale en Feb 09 04:12:34 volumio volumio[9031]: Updating browse sources language Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:12:34 volumio volumio[9142]: Forking 3 albumart workers Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::initPlayerControls Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:12:34 volumio volumio[9031]: Express server listening on port 3000 Feb 09 04:12:34 volumio volumio[9031]: [Metrics] WebUI: 16s 80.23ms Feb 09 04:12:34 volumio volumio[9031]: info: CoreStateMachine::resetVolumioState Feb 09 04:12:34 volumio volumio[9031]: info: CoreStateMachine::getcurrentVolume Feb 09 04:12:34 volumio volumio[9031]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:12:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 09 04:12:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:34 volumio go-librespot[9188]: go-librespot daemon starting... Feb 09 04:12:34 volumio sudo[9186]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:12:34 volumio sudo[9186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:34 volumio volumio[9031]: info: Volumio Network Manager: Network status updated: 1 Feb 09 04:12:34 volumio sudo[9186]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:34 volumio sudo[9189]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:12:34 volumio sudo[9189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:34 volumio go-librespot[9191]: time="2026-02-09T04:12:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:34 volumio go-librespot[9191]: time="2026-02-09T04:12:34+07:00" level=debug msg="app state loaded" Feb 09 04:12:34 volumio go-librespot[9191]: time="2026-02-09T04:12:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:35 volumio sudo[9189]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:35 volumio volumio[9031]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::pushState Feb 09 04:12:35 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::volumioPushState Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::updateTrackBlock Feb 09 04:12:35 volumio volumio[9031]: info: CorePlayQueue::getTrackBlock Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:12:35 volumio volumio-remote-updater[643]: [2026-02-09 04:12:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770585153 101 Feb 09 04:12:35 volumio volumio[9031]: 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 09 04:12:35 volumio volumio[9031]: info: Reloading queue from file Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::setRepeat null single undefined Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::pushState Feb 09 04:12:35 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::volumioPushState Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::setRandom null Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::pushState Feb 09 04:12:35 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::volumioPushState Feb 09 04:12:35 volumio volumio[9031]: info: Setting Device type: Raspberry PI Feb 09 04:12:35 volumio go-librespot[9191]: time="2026-02-09T04:12:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:12:35 volumio go-librespot[9191]: time="2026-02-09T04:12:35+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 09 04:12:35 volumio go-librespot[9191]: time="2026-02-09T04:12:35+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 09 04:12:35 volumio volumio[9031]: info: Completed loading Core Plugins Feb 09 04:12:35 volumio volumio[9031]: info: Preparing to generate the ALSA configuration file Feb 09 04:12:35 volumio go-librespot[9191]: time="2026-02-09T04:12:35+07:00" level=info msg="zeroconf server listening on port 36445" Feb 09 04:12:35 volumio volumio[9031]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:12:35 volumio volumio[9031]: info: CoreStateMachine::pushState Feb 09 04:12:35 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::volumioPushState Feb 09 04:12:35 volumio volumio[9031]: info: Asound.conf file unchanged, so no further update is needed Feb 09 04:12:35 volumio volumio[9031]: info: Output device has changed, restarting MPD Feb 09 04:12:35 volumio sudo[9212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 04:12:35 volumio sudo[9212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:35 volumio volumio[9031]: info: Output device has changed, restarting Shairport Sync Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:35 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:35 volumio go-librespot[9191]: time="2026-02-09T04:12:35+07:00" level=debug msg="obtained new client token: AADgNovV8JTYA+kL1Fd84ilqaGwO2uOOdjFdfaRGHJApZXZ1m2eoTBGszs5DSUgUnYEfoDBSzMHDRy7CSimjYSl49aEWhNCSKyOObHP9pgFy6P5lx1axFAkWGPUhh70CWUKygfXEMH7fp0FR+FM64DYq4lQZ6Nzm1V4VpBOUN3IXE7Flokz/D4h3b2k+UYubfLUWT/xvuRE2spwf7KegdwMx13TW0d9yRcjH894Fi7U93lnglASBaFJ0pw==" Feb 09 04:12:35 volumio sudo[9214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:12:35 volumio sudo[9214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:35 volumio sudo[9214]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:35 volumio volumio[9031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:12:35 volumio volumio[9031]: info: ___________ START PLUGINS ___________ Feb 09 04:12:35 volumio volumio[9031]: info: ControllerMpd::onStart: Initializing MPD Feb 09 04:12:36 volumio volumio[9031]: info: Creating MPD Configuration file Feb 09 04:12:36 volumio sudo[9217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:12:36 volumio go-librespot[9191]: time="2026-02-09T04:12:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:36 volumio sudo[9217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:12:36 volumio sudo[9212]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:36 volumio volumio[9031]: info: [1770585156063] CoreMusicLibrary::Adding element Media Servers Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:12:36 volumio volumio[9031]: info: UPNP Browser: Client initialized successfully Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:36 volumio go-librespot[9191]: time="2026-02-09T04:12:36+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:36 volumio go-librespot[9191]: time="2026-02-09T04:12:36+07:00" level=debug msg="completed challenge" Feb 09 04:12:36 volumio sudo[9224]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:12:36 volumio sudo[9224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 04:12:36 volumio sudo[9224]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:36 volumio sudo[9227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:12:36 volumio sudo[9227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:36 volumio go-librespot[9191]: time="2026-02-09T04:12:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:12:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:36 volumio volumio[9031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:12:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:12:36 volumio systemd[1]: mpd.service: Consumed 7.169s CPU time. Feb 09 04:12:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:12:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:12:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:12:36 volumio volumio[9031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:12:36 volumio volumio[9031]: info: [1770585156444] CoreMusicLibrary::Adding element Last_100 Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:12:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:12:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:12:36 volumio volumio[9031]: info: [1770585156498] CoreMusicLibrary::Adding element Webradio Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:12:36 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:12:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:12:36 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:12:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:12:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:12:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:12:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:12:36 volumio volumio[9031]: info: Initializing BBC Radios Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:36 volumio volumio[9031]: info: Creating Spotify config file Feb 09 04:12:36 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:37 volumio sudo[9241]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 04:12:37 volumio sudo[9241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 04:12:37 volumio sudo[9241]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:37 volumio volumio[9031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:12:37 volumio volumio[9031]: info: [1770585157906] CoreMusicLibrary::Adding element YouTube Music Feb 09 04:12:37 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:12:37 volumio volumio[9031]: Cannot find translation for source YouTube Music Feb 09 04:12:38 volumio volumio[9031]: info: Volumio Calling Home Feb 09 04:12:38 volumio volumio[9154]: Starting albumart workers Feb 09 04:12:38 volumio sudo[9258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 04:12:38 volumio sudo[9258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:38 volumio volumio[9152]: Starting albumart workers Feb 09 04:12:38 volumio sudo[9258]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:38 volumio volumio[9153]: Starting albumart workers Feb 09 04:12:39 volumio volumio[9031]: info: MPD Permissions set Feb 09 04:12:39 volumio volumio[9031]: info: MPD Permissions set Feb 09 04:12:39 volumio volumio[9031]: info: Upmpdcli Daemon Started Feb 09 04:12:39 volumio volumio[9031]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:12:39 volumio volumio[9031]: info: Discovery: Found device Volumio Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::volumioGetState Feb 09 04:12:39 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:39 volumio volumio[9031]: info: Volumio called home Feb 09 04:12:39 volumio volumio[9031]: info: Spotify config file written Feb 09 04:12:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 09 04:12:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:39 volumio volumio[9031]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:12:39 volumio volumio[9031]: info: Discovery: Found device Volumio Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::volumioGetState Feb 09 04:12:39 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:39 volumio go-librespot[9264]: go-librespot daemon starting... Feb 09 04:12:39 volumio sudo[9265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 04:12:39 volumio sudo[9265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:39 volumio go-librespot[9266]: time="2026-02-09T04:12:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:39 volumio go-librespot[9266]: time="2026-02-09T04:12:39+07:00" level=debug msg="app state loaded" Feb 09 04:12:39 volumio go-librespot[9266]: time="2026-02-09T04:12:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:39 volumio volumio[9031]: 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 09 04:12:39 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 04:12:39 volumio systemd[1]: go-librespot-daemon.service: Killing process 9268 (go-librespot) with signal SIGKILL. Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 04:12:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:39 volumio go-librespot[9273]: go-librespot daemon starting... Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:39 volumio sudo[9265]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio go-librespot[9279]: time="2026-02-09T04:12:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:39 volumio go-librespot[9279]: time="2026-02-09T04:12:39+07:00" level=debug msg="app state loaded" Feb 09 04:12:39 volumio go-librespot[9279]: time="2026-02-09T04:12:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:12:39 volumio volumio[9031]: info: No need to fix Spotify hosts Feb 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+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 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+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 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+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 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+07:00" level=info msg="zeroconf server listening on port 38287" Feb 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+07:00" level=debug msg="obtained new client token: AABMKhHXZ2XUobSKH2JG30Ei/n8RqHzvPqvnIR/kPON8xIiseNVY0j7NHb+cBwMv+JGl9fx+BF1EzrWATXhg8kkIgmsK870npoJayLbx54JVKCtmG/DqK0A7kgqfNP+nmp9sOZqYOVuLBNbMbTvXObqDEKV+gZNDfp9r3xkS/nk3Ykw4Eh9GqoaJkXSGpiI8zqhWhdHNefKX2aSbAtQ9g7BkYRKolfRww0yuWdTezs2k1tOO3Ws4ieFM9A==" Feb 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+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 09 04:12:40 volumio go-librespot[9279]: time="2026-02-09T04:12:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 04:12:40 volumio volumio[9031]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:12:40 volumio volumio[9031]: SPOTIFY: BQDOg_G3y-l2HHLRqAGNACOm6NgERuGPTYIOmzdcFwLTj2ZJ6SSHIS5a7li52QaZJfrc7pLzqnU2CBnCofl11IFkBN_usS1aJUibYOzfXnZ_7vf9HmfMKOfPdjsdPdWvPL41KonDlL44YxnDqgRYqxYr9-NiR1D642_rWWpunoKLMeBoETQpDyp4U9iBB6JAfcTUubHlTIkt4fWoCSgNU4szM3hJDgzOkqhIrwDx_KeRNGdVwOU2PlNloWB0iTDtn2UxVLhLm_rchBUiBry1aQuoSbnEQqC-iEyFpU2Ut7i698WYLEt6dW8b Feb 09 04:12:40 volumio volumio[9031]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:12:40 volumio volumio[9031]: info: New Spotify access token = BQDOg_G3y-l2HHLRqAGNACOm6NgERuGPTYIOmzdcFwLTj2ZJ6SSHIS5a7li52QaZJfrc7pLzqnU2CBnCofl11IFkBN_usS1aJUibYOzfXnZ_7vf9HmfMKOfPdjsdPdWvPL41KonDlL44YxnDqgRYqxYr9-NiR1D642_rWWpunoKLMeBoETQpDyp4U9iBB6JAfcTUubHlTIkt4fWoCSgNU4szM3hJDgzOkqhIrwDx_KeRNGdVwOU2PlNloWB0iTDtn2UxVLhLm_rchBUiBry1aQuoSbnEQqC-iEyFpU2Ut7i698WYLEt6dW8b Feb 09 04:12:40 volumio volumio[9031]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 04:12:40 volumio volumio[9031]: info: Starting Shairport Sync Feb 09 04:12:40 volumio volumio[9031]: info: Starting Shairport Sync Feb 09 04:12:41 volumio volumio[9031]: info: Starting Shairport Sync Feb 09 04:12:41 volumio sudo[9313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:12:41 volumio sudo[9313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:41 volumio go-librespot[9279]: time="2026-02-09T04:12:41+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:41 volumio go-librespot[9279]: time="2026-02-09T04:12:41+07:00" level=debug msg="completed challenge" Feb 09 04:12:41 volumio sudo[9316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:12:41 volumio sudo[9316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:41 volumio go-librespot[9279]: time="2026-02-09T04:12:41+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 09 04:12:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:12:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:12:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:12:41 volumio systemd[1]: shairport-sync.service: Consumed 2.449s CPU time. Feb 09 04:12:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:41 volumio sudo[9318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:12:41 volumio sudo[9318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:12:41 volumio sudo[9313]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:12:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:12:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:12:41 volumio volumio[9031]: info: Shairport-Sync Started Feb 09 04:12:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:12:41 volumio sudo[9318]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:41 volumio volumio[9031]: Error adding Membership: Error: addMembership EINVAL Feb 09 04:12:41 volumio sudo[9316]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:41 volumio volumio[9031]: info: Shairport-Sync Started Feb 09 04:12:41 volumio volumio[9031]: info: CoreCommandRouter::volumioGetState Feb 09 04:12:41 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:41 volumio volumio[9031]: info: Shairport-Sync Started Feb 09 04:12:41 volumio volumio[9031]: 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 09 04:12:41 volumio volumio[9031]: info: Spotify Successfully logged in Feb 09 04:12:41 volumio volumio[9031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:12:41 volumio volumio[9031]: info: [1770585161811] CoreMusicLibrary::Adding element Spotify Feb 09 04:12:41 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:12:41 volumio volumio[9031]: Cannot find translation for source YouTube Music Feb 09 04:12:41 volumio volumio[9031]: Cannot find translation for source Spotify Feb 09 04:12:42 volumio volumio[9031]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 04:12:42 volumio volumio[9031]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:12:42 volumio volumio[9031]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:12:42 volumio volumio[9031]: info: CoreCommandRouter::volumioGetState Feb 09 04:12:42 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:42 volumio volumio[9031]: info: CoreStateMachine::pushState Feb 09 04:12:42 volumio volumio[9031]: info: CorePlayQueue::getTrack 0 Feb 09 04:12:42 volumio volumio[9031]: info: CoreCommandRouter::volumioPushState Feb 09 04:12:43 volumio volumio[9031]: info: go-librespot daemon successfully initialized Feb 09 04:12:43 volumio mpd[9256]: 2026-02-09T04:12:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 04:12:43 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 04:12:44 volumio sudo[9227]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:44 volumio sudo[9217]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:44 volumio volumio[9031]: error: MPD error: The expression evaluated to a falsy value: Feb 09 04:12:44 volumio volumio[9031]: assert.ok(self.idling) Feb 09 04:12:44 volumio volumio[9031]: error: The expression evaluated to a falsy value: Feb 09 04:12:44 volumio volumio[9031]: assert.ok(self.idling) Feb 09 04:12:44 volumio volumio[9031]: info: MPD running with PID9256 Feb 09 04:12:44 volumio volumio[9031]: ,establishing connection Feb 09 04:12:44 volumio volumio[9031]: error: updateQueue error: null Feb 09 04:12:44 volumio volumio[9031]: info: Completed starting Core Plugins Feb 09 04:12:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 04:12:44 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:44 volumio volumio[9031]: info: ----- MyVolumio plugins startup ---- Feb 09 04:12:44 volumio volumio[9031]: info: ------------------------------------------- Feb 09 04:12:44 volumio volumio[9031]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 04:12:44 volumio volumio[9031]: error: updateQueue error: null Feb 09 04:12:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:44 volumio go-librespot[9358]: go-librespot daemon starting... Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=debug msg="app state loaded" Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:12:44 volumio go-librespot[9359]: time="2026-02-09T04:12:44+07:00" level=info msg="zeroconf server listening on port 43703" Feb 09 04:12:45 volumio go-librespot[9359]: time="2026-02-09T04:12:45+07:00" level=debug msg="obtained new client token: AADRE06xkdp1juCUGvfHx3RXpac/dJ4RDmZYJVXY/gtyPJSBgfp9/wnh74FEdIStNxGsgTD4P93JLtpfbG7SPQEzhC6Qak2L6m5cSK8i/mTRelRrFL36MQl2QKvB7GqgWdoCG2sb93B3Ijxx4FmNC3K6VH3UnN6TWTaHn3UrieJ5I+NG7HqliGg4s7wVkNPKEkuzIvQGuKznfiiDox56hwznQRQ0eE3x5QsR0J6WLyCZPd61GSY3mnU=" Feb 09 04:12:45 volumio go-librespot[9359]: time="2026-02-09T04:12:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:45 volumio go-librespot[9359]: time="2026-02-09T04:12:45+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:45 volumio go-librespot[9359]: time="2026-02-09T04:12:45+07:00" level=debug msg="completed challenge" Feb 09 04:12:45 volumio go-librespot[9359]: time="2026-02-09T04:12:45+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 09 04:12:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:46 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:46 volumio volumio[9031]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 04:12:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:48 volumio go-librespot[9367]: go-librespot daemon starting... Feb 09 04:12:48 volumio go-librespot[9368]: time="2026-02-09T04:12:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:48 volumio go-librespot[9368]: time="2026-02-09T04:12:48+07:00" level=debug msg="app state loaded" Feb 09 04:12:48 volumio go-librespot[9368]: time="2026-02-09T04:12:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:49 volumio volumio[9031]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+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 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+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 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+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 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+07:00" level=info msg="zeroconf server listening on port 42375" Feb 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+07:00" level=debug msg="obtained new client token: AACfuAM9ZVBhC0hxBkokv7fxGAQLSaUigjEvUhZiZCDdsIKD6wGVY0DP+ytnRcAo4P0+BGpS3Dzy63FcTXKTR93bx8G87Pjv3IObQfctzxUd1jXjXKMoyfymGt8Mh7zRsONQ42jr/tWlASbGK02tU7jLnyqsL2f3Usruq8fJHpKPIOdF9VGVfRjPIsBEY3mArG4lSK4syi/8GLrEYQ1w6GZ0aK+ZQGS7tUBoU+/Ynhmun0rU7nfM60+uCg==" Feb 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+07:00" level=debug msg="completed challenge" Feb 09 04:12:49 volumio go-librespot[9368]: time="2026-02-09T04:12:49+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 09 04:12:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:49 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:49 volumio volumio[9031]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 04:12:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:52 volumio go-librespot[9375]: go-librespot daemon starting... Feb 09 04:12:52 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:52 volumio volumio[9031]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:52 volumio go-librespot[9376]: time="2026-02-09T04:12:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:52 volumio go-librespot[9376]: time="2026-02-09T04:12:52+07:00" level=debug msg="app state loaded" Feb 09 04:12:52 volumio go-librespot[9376]: time="2026-02-09T04:12:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:12:53 volumio volumio[9031]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+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 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+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 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+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 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+07:00" level=info msg="zeroconf server listening on port 46589" Feb 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+07:00" level=debug msg="obtained new client token: AACAsmRGK0xyfX0XSiQGoBbOnETlpzqO4y6RBdPWwH+LZZA6o+BWBGdK4N8Nsn1JBeKKvUow2IZecIOkJkJGOb7OJvZTIc54pksUUQpVy733wijT+akSKLXIwk1J8NbsJDDcJvGUXtv85YS2gfjchclo9kRCnKQl5PbH+UUaLK7ObRT45anMi39cEKNddQdsy+4lPOtvXUH/wAGzPzYxVFd2socjCRdokuWLEU8Kohwtj383FKNdCc2thA==" Feb 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:53 volumio go-librespot[9376]: time="2026-02-09T04:12:53+07:00" level=debug msg="completed challenge" Feb 09 04:12:54 volumio go-librespot[9376]: time="2026-02-09T04:12:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:12:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:54 volumio volumio[9031]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:12:54 volumio volumio[9031]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:12:54 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:54 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:12:54 volumio volumio[9031]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:12:55 volumio volumio[9031]: info: MyVolumio login type: Token Feb 09 04:12:55 volumio volumio[9031]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:12:55 volumio volumio[9031]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:12:56 volumio volumio[9031]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:12:56 volumio volumio[9031]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:12:56 volumio volumio[9031]: info: Streaming services startup Feb 09 04:12:56 volumio volumio[9031]: info: Starting Streaming Daemon Feb 09 04:12:56 volumio sudo[9398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:12:56 volumio sudo[9398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:56 volumio volumio[9031]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:12:56 volumio sudo[9398]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:56 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:12:57 volumio volumio[9031]: error: Cannot start Volumio Streaming Daemon Feb 09 04:12:57 volumio volumio[9031]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:12:57 volumio volumio[9031]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:12:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 04:12:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:57 volumio volumio[9031]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:12:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:12:57 volumio go-librespot[9405]: go-librespot daemon starting... Feb 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+07:00" level=debug msg="app state loaded" Feb 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+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 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+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 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+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 09 04:12:57 volumio go-librespot[9406]: time="2026-02-09T04:12:57+07:00" level=info msg="zeroconf server listening on port 35949" Feb 09 04:12:57 volumio volumio[9031]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 09 04:12:58 volumio go-librespot[9406]: time="2026-02-09T04:12:58+07:00" level=debug msg="obtained new client token: AACM3JLTL9vdRkK/UadsyTAu55hbiLUYKRQs+KL37xRzgkbMlEwwM0e8DEHvAQLmngxVuVKU2qMN6AwHAK8OfQAmO8y3jpiX3AH+P/gD9sg61pAPSLTgI+dNJuVT07m91B1uknC04+0/+KSft0sBKedGh2oArJjEnkY8psBploGz1ej4IxCArQ0LKDN2y9WbWeE8k1qfI0KtYFun2JT7L/uhbfdhLsjJYfnalhBwq5JhiQzn0XcuI1SXlA==" Feb 09 04:12:58 volumio go-librespot[9406]: time="2026-02-09T04:12:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:12:58 volumio go-librespot[9406]: time="2026-02-09T04:12:58+07:00" level=debug msg="completed keyexchange" Feb 09 04:12:58 volumio go-librespot[9406]: time="2026-02-09T04:12:58+07:00" level=debug msg="completed challenge" Feb 09 04:12:58 volumio go-librespot[9406]: time="2026-02-09T04:12:58+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 09 04:12:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:12:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:12:58 volumio volumio[9031]: info: MyVolumio token set successfully Feb 09 04:12:58 volumio volumio[9031]: info: MYVOLUMIO: Adding device Feb 09 04:12:58 volumio volumio[9031]: info: MYVOLUMIO: Evaluating Server Feb 09 04:12:59 volumio volumio[9031]: info: MyVolumio status changed Feb 09 04:12:59 volumio volumio[9031]: info: Streaming services startup Feb 09 04:12:59 volumio volumio[9031]: info: Starting Streaming Daemon Feb 09 04:12:59 volumio volumio[9031]: info: Removing browser output: myVolumio user plan is not superstar Feb 09 04:12:59 volumio volumio[9031]: info: Removing audio output: Feb 09 04:12:59 volumio volumio[9031]: info: Stoppping Tunnel 1 Feb 09 04:12:59 volumio sudo[9434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:12:59 volumio sudo[9434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:59 volumio sudo[9434]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:59 volumio sudo[9437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 09 04:12:59 volumio sudo[9437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:12:59 volumio volumio[9031]: error: Cannot start Volumio Streaming Daemon Feb 09 04:12:59 volumio volumio[9031]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:12:59 volumio volumio[9031]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:12:59 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 09 04:12:59 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 09 04:12:59 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 09 04:12:59 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 09 04:12:59 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 09 04:12:59 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 09 04:12:59 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 09 04:12:59 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 09 04:12:59 volumio sudo[9437]: pam_unix(sudo:session): session closed for user root Feb 09 04:12:59 volumio volumio[9031]: info: Remote SSH Stopped Feb 09 04:13:00 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:13:00 volumio volumio[9031]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:13:00 volumio volumio[9031]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:13:00 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:00 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:00 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:01 volumio volumio[9031]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:13:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 09 04:13:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:01 volumio go-librespot[9443]: go-librespot daemon starting... Feb 09 04:13:01 volumio go-librespot[9444]: time="2026-02-09T04:13:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:01 volumio go-librespot[9444]: time="2026-02-09T04:13:01+07:00" level=debug msg="app state loaded" Feb 09 04:13:01 volumio go-librespot[9444]: time="2026-02-09T04:13:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:01 volumio volumio[9031]: info: Updating MyVolumio device info Feb 09 04:13:01 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:01 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:01 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+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 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+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 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+07:00" level=info msg="zeroconf server listening on port 36495" Feb 09 04:13:02 volumio volumio[9031]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+07:00" level=debug msg="obtained new client token: AADHUXKWUkyOyucvej2paqFZZvFMLjx9ZVjRe+eGL/Y4+b/v3Iq59x3lY6RFg5Cp1TZ2/MuVK9VaAHJfETB3DAy5tY2ORSIwmndOEUP+N10odM8M6pWgACaGvhXUkZKEtBpyNB7X31xofrWfJqW70ShE6MgNF/y9zHoug/8UW4BvjJ9bjx3qjrh//ej+On9sCF/h8JgnBTb4qN172Bgc81WM/FMFzDdLUNQ7NAPNRowlzkR7Qw9a+DRNBg==" Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+07:00" level=debug msg="completed challenge" Feb 09 04:13:02 volumio go-librespot[9444]: time="2026-02-09T04:13:02+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 09 04:13:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:03 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:13:03 volumio volumio[9031]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:13:05 volumio volumio[9031]: info: MYVOLUMIO: Adding device Feb 09 04:13:05 volumio volumio[9031]: info: MYVOLUMIO: Evaluating Server Feb 09 04:13:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 09 04:13:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:05 volumio go-librespot[9481]: go-librespot daemon starting... Feb 09 04:13:05 volumio go-librespot[9484]: time="2026-02-09T04:13:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:05 volumio go-librespot[9484]: time="2026-02-09T04:13:05+07:00" level=debug msg="app state loaded" Feb 09 04:13:05 volumio go-librespot[9484]: time="2026-02-09T04:13:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:06 volumio volumio[9031]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:13:06 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:06 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:06 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:06 volumio volumio[9031]: info: Initializing connection to go-librespot Websocket Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+07:00" level=debug msg="new websocket client" Feb 09 04:13:06 volumio volumio[9031]: info: Connection to go-librespot Websocket established Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+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 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+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 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+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 09 04:13:06 volumio volumio[9031]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+07:00" level=info msg="zeroconf server listening on port 39093" Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+07:00" level=debug msg="obtained new client token: AACx23L1uonedZwZEoHsEpoQr0IoDo1eKz4ZfqB3bcxpB0tXpStMMry7UqqqYVauc8gH4AWUDQu9xveyP3XyMRDNx9axbWNDx5Nf/ZCESxSjobA4OzoxCEecGPa6mKRzYR0qfLtXwk14zsz3o8jfch9IRmjVqmU4Zaj8GB9Bh0yPz5PZtoe03tTOQ3IeekI7LAO1zDuniDpx8yeXkp7O3AkP9w3BgM3RDMV/YtdTkzjln0qFAzudLg99FQ==" Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+07:00" level=debug msg="completed challenge" Feb 09 04:13:06 volumio go-librespot[9484]: time="2026-02-09T04:13:06+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 09 04:13:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:06 volumio volumio[9031]: info: Connection to go-librespot Websocket closed Feb 09 04:13:07 volumio volumio[9031]: info: Updating MyVolumio device info Feb 09 04:13:07 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:07 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:07 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:07 volumio volumio[9031]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:13:07 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:13:07 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:07 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 09 04:13:08 volumio volumio-remote-updater[643]: Test mode disabled Feb 09 04:13:08 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 09 04:13:08 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 09 04:13:08 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 09 04:13:08 volumio volumio[9031]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 09 04:13:08 volumio volumio[9031]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 09 04:13:09 volumio volumio[9031]: info: Getting Spotify volume Feb 09 04:13:09 volumio volumio[9031]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:13:09 volumio volumio[9031]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:13:09 volumio volumio[9031]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 04:13:09 volumio volumio[9031]: errno: -111, Feb 09 04:13:09 volumio volumio[9031]: code: 'ECONNREFUSED', Feb 09 04:13:09 volumio volumio[9031]: syscall: 'connect', Feb 09 04:13:09 volumio volumio[9031]: address: '127.0.0.1', Feb 09 04:13:09 volumio volumio[9031]: port: 9879, Feb 09 04:13:09 volumio volumio[9031]: response: undefined Feb 09 04:13:09 volumio volumio[9031]: } Feb 09 04:13:09 volumio volumio[9031]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:13:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 09 04:13:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:10 volumio go-librespot[9508]: go-librespot daemon starting... Feb 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+07:00" level=debug msg="app state loaded" Feb 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:10 volumio sudo[9518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:12' Feb 09 04:13:10 volumio sudo[9518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+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 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+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 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+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 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+07:00" level=info msg="zeroconf server listening on port 42351" Feb 09 04:13:10 volumio go-librespot[9509]: time="2026-02-09T04:13:10+07:00" level=debug msg="obtained new client token: AADJovfrbbUEFAwQ/yeTeDxFfxAWvRJBzbdUltGQkk2FdKwSGKfg74/fT7CdgtBGeaeeNpV0wpNXr3lw/ImMrRELQCdallXa/WngQdJV9UZuYBfE+emfWSfjwjeB97ytF+Q9UjPGWWfDYCud37/szf8Uvfbzf06zd0ZGvAklsN3/Ak2B1ykIwO2RXbToLSjiNXz2BaLJqHn8fXkTft4dcmeHc9EyfzHJd9VPBa+G+EDb2zQOMfCYBZFHig==" Feb 09 04:13:10 volumio sudo[9518]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:11 volumio go-librespot[9509]: time="2026-02-09T04:13:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:11 volumio volumio-remote-updater[643]: [2026-02-09 04:13:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 04:13:11 volumio volumio-remote-updater[643]: [2026-02-09 04:13:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 04:13:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 04:13:11 volumio systemd[1]: volumio.service: Consumed 58.274s CPU time. Feb 09 04:13:11 volumio go-librespot[9509]: time="2026-02-09T04:13:11+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:11 volumio go-librespot[9509]: time="2026-02-09T04:13:11+07:00" level=debug msg="completed challenge" Feb 09 04:13:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:13:11 volumio go-librespot[9509]: time="2026-02-09T04:13:11+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 09 04:13:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8185. Feb 09 04:13:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:13:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 04:13:11 volumio systemd[1]: volumio.service: Consumed 58.274s CPU time. Feb 09 04:13:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 04:13:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 09 04:13:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:14 volumio go-librespot[9543]: go-librespot daemon starting... Feb 09 04:13:14 volumio go-librespot[9544]: time="2026-02-09T04:13:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:14 volumio go-librespot[9544]: time="2026-02-09T04:13:14+07:00" level=debug msg="app state loaded" Feb 09 04:13:14 volumio go-librespot[9544]: time="2026-02-09T04:13:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:14 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:14 volumio volumio[9531]: info: ----- Volumio3 ---- Feb 09 04:13:14 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:14 volumio volumio[9531]: info: ----- System startup ---- Feb 09 04:13:14 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:14 volumio go-librespot[9544]: time="2026-02-09T04:13:14+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 09 04:13:14 volumio go-librespot[9544]: time="2026-02-09T04:13:14+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 09 04:13:14 volumio go-librespot[9544]: time="2026-02-09T04:13:14+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 09 04:13:15 volumio go-librespot[9544]: time="2026-02-09T04:13:15+07:00" level=info msg="zeroconf server listening on port 34335" Feb 09 04:13:15 volumio go-librespot[9544]: time="2026-02-09T04:13:15+07:00" level=debug msg="obtained new client token: AACoqOhrPM7nToAFldd8c57miAoQfXL4J9+yLHg461odMbxHqKT+QmviCbof+TZR86TEjcoFY9EV4XoRSCLg33Tg9qS/3i5k8L5TLTeG7mPmEkN2QgXLz1lRu/nurHMWUiYfRvtYXljkL4QJIS6lRfTBoFvnPVSEmqEpcNpngZhgLn7lpxZ7CXiMvBibmgGuUcrTuoEo05zNJm8yB3VJuEbCDaoPQ/ypYira8hOMT6oDOaGiCtaa9fc=" Feb 09 04:13:15 volumio go-librespot[9544]: time="2026-02-09T04:13:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:15 volumio go-librespot[9544]: time="2026-02-09T04:13:15+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:15 volumio go-librespot[9544]: time="2026-02-09T04:13:15+07:00" level=debug msg="completed challenge" Feb 09 04:13:15 volumio go-librespot[9544]: time="2026-02-09T04:13:15+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 09 04:13:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:16 volumio volumio-remote-updater[643]: [2026-02-09 04:13:16] [connect] Successful connection Feb 09 04:13:16 volumio volumio[9531]: info: MYVOLUMIO Environment detected Feb 09 04:13:16 volumio volumio[9531]: info: Plugin folders cleanup Feb 09 04:13:16 volumio volumio[9531]: info: Scanning into folder /volumio/app/plugins/ Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category audio_interface Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category miscellanea Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category music_service Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category plugins.json Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category system_controller Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category user_interface Feb 09 04:13:16 volumio volumio[9531]: info: Scanning into folder /data/plugins/ Feb 09 04:13:16 volumio volumio[9531]: info: Scanning category music_service Feb 09 04:13:16 volumio volumio[9531]: info: Plugin folders cleanup completed Feb 09 04:13:16 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:16 volumio volumio[9531]: info: ----- Core plugins startup ---- Feb 09 04:13:16 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:16 volumio volumio[9531]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 04:13:16 volumio volumio[9531]: info: Adding plugin upnp to MyMusic Plugins Feb 09 04:13:16 volumio volumio[9531]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 04:13:16 volumio volumio[9531]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 04:13:16 volumio volumio[9531]: info: Loading plugins from folder /data/plugins/ Feb 09 04:13:16 volumio volumio[9531]: info: Loading plugin "system"... Feb 09 04:13:16 volumio volumio[9531]: info: Loading plugin "appearance"... Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "network"... Feb 09 04:13:18 volumio volumio[9531]: info: Refreshing Cached IP Addresses Feb 09 04:13:18 volumio sudo[9565]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:13:18 volumio sudo[9565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:18 volumio sudo[9565]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:18 volumio sudo[9567]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:13:18 volumio sudo[9567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "services"... Feb 09 04:13:18 volumio sudo[9567]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "alsa_controller"... Feb 09 04:13:18 volumio sudo[9575]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 04:13:18 volumio sudo[9575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:18 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "wizard"... Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "networkfs"... Feb 09 04:13:18 volumio volumio[9531]: info: Starting Udev Watcher for removable devices Feb 09 04:13:18 volumio volumio[9531]: info: Ignoring mount for partition: boot Feb 09 04:13:18 volumio volumio[9531]: info: Ignoring mount for partition: volumio Feb 09 04:13:18 volumio volumio[9531]: info: Ignoring mount for partition: volumio_data Feb 09 04:13:18 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "volumio_command_line_client"... Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "upnp"... Feb 09 04:13:18 volumio volumio[9531]: info: [1770585198744] Starting Upmpd Daemon Feb 09 04:13:18 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "my_music"... Feb 09 04:13:18 volumio volumio[9531]: info: Loading plugin "mpd"... Feb 09 04:13:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 09 04:13:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:18 volumio go-librespot[9599]: go-librespot daemon starting... Feb 09 04:13:18 volumio go-librespot[9600]: time="2026-02-09T04:13:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:18 volumio go-librespot[9600]: time="2026-02-09T04:13:18+07:00" level=debug msg="app state loaded" Feb 09 04:13:18 volumio go-librespot[9600]: time="2026-02-09T04:13:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:19 volumio volumio[9531]: info: Loading plugin "upnp_browser"... Feb 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+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 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+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 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+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 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+07:00" level=info msg="zeroconf server listening on port 34455" Feb 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+07:00" level=debug msg="obtained new client token: AACO3B+/cB+Ej+5qJet1r677pAz9poQNpm1QKmxCYo5EUyr2H1EtswmnujyzL1uc54kyQpTOmLjyrQLCXSzVwyzM3T1UOr52H0xFTGjxmxUWNrewS4xl1p7zE/l5po/QA+FnGErwIDw6Urq9lyvsx6SoHocIu/jf/frG//kxPJenY3O3CoA6gPJIrc7X5ZUYHg+s///KamW6BPn8RmAg3PPE0IbQmxgydmwyX7hSqRqBaOvPFnjkJoNcZw==" Feb 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+07:00" level=debug msg="completed challenge" Feb 09 04:13:19 volumio go-librespot[9600]: time="2026-02-09T04:13:19+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 09 04:13:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:21 volumio sudo[9575]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:22 volumio volumio[9531]: info: Starting UPNP Browser Feb 09 04:13:22 volumio volumio[9531]: info: Loading plugin "alarm-clock"... Feb 09 04:13:22 volumio volumio[9531]: info: Loading plugin "airplay_emulation"... Feb 09 04:13:22 volumio volumio[9531]: info: Starting Shairport Sync Feb 09 04:13:22 volumio volumio[9531]: info: Loading plugin "last_100"... Feb 09 04:13:22 volumio volumio[9531]: info: Loading plugin "webradio"... Feb 09 04:13:22 volumio volumio[9531]: info: Loading plugin "i2s_dacs"... Feb 09 04:13:22 volumio volumio[9531]: info: Loading plugin "volumiodiscovery"... Feb 09 04:13:22 volumio volumio[9531]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:13:22 volumio volumio[9531]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:13:22 volumio node[9531]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:13:22 volumio volumio[9531]: *** WARNING *** For more information see Feb 09 04:13:22 volumio volumio[9531]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:13:22 volumio volumio[9531]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:13:22 volumio volumio[9531]: *** WARNING *** For more information see Feb 09 04:13:22 volumio node[9531]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:13:22 volumio node[9531]: *** WARNING *** For more information see Feb 09 04:13:22 volumio node[9531]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:13:22 volumio node[9531]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:13:22 volumio node[9531]: *** WARNING *** For more information see Feb 09 04:13:22 volumio volumio[9531]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 04:13:22 volumio volumio[9531]: info: Discovery: Started advertising with name: Volumio Feb 09 04:13:23 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:13:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 09 04:13:23 volumio volumio[9531]: info: Loading plugin "spop"... Feb 09 04:13:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:23 volumio go-librespot[9610]: go-librespot daemon starting... Feb 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+07:00" level=debug msg="app state loaded" Feb 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+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 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+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 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+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 09 04:13:23 volumio go-librespot[9611]: time="2026-02-09T04:13:23+07:00" level=info msg="zeroconf server listening on port 41633" Feb 09 04:13:24 volumio go-librespot[9611]: time="2026-02-09T04:13:24+07:00" level=debug msg="obtained new client token: AABaayubskaHn/Zq7vEgGJc9D0mOdwAVmCB0qSO94wPKs4aZgtCf7fOIWBobVilo3S48izHpf+1rqqdzECVFILmDjpXd04jkFzL78RRX3CKYALNDYO7O0RxRuJQBCx+RECbzYlp5LOIFScpauws7SYlH1s1OtJDasYsnm5NzUzHpTAeMN69H7qLHSYvro8zW+klDilHi6RmBv3g19g6Og7tf4sCpBPt3M7MIZO/aN9P9N0jhTacxlT1U4w==" Feb 09 04:13:24 volumio go-librespot[9611]: time="2026-02-09T04:13:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:24 volumio go-librespot[9611]: time="2026-02-09T04:13:24+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:24 volumio go-librespot[9611]: time="2026-02-09T04:13:24+07:00" level=debug msg="completed challenge" Feb 09 04:13:24 volumio go-librespot[9611]: time="2026-02-09T04:13:24+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 09 04:13:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:24 volumio volumio[9531]: info: Loading plugin "ytcr"... Feb 09 04:13:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 09 04:13:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:27 volumio volumio[9531]: info: Loading plugin "ytmusic"... Feb 09 04:13:27 volumio go-librespot[9619]: go-librespot daemon starting... Feb 09 04:13:27 volumio go-librespot[9620]: time="2026-02-09T04:13:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:27 volumio go-librespot[9620]: time="2026-02-09T04:13:27+07:00" level=debug msg="app state loaded" Feb 09 04:13:27 volumio go-librespot[9620]: time="2026-02-09T04:13:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13: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 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13: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 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13: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 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13:28+07:00" level=info msg="zeroconf server listening on port 41379" Feb 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13:28+07:00" level=debug msg="obtained new client token: AABwVRVUI3VAtE9HjxLHglaIjPk045iH2nMsBFCNMllNw8sW1Sl9acHqBmAvVI3OOtTSsKphtYAHxZxbaKf6FyCNzKhbRrqJRxfn10+iGI52fbn7xTLS/8vS0u/Qd20HY84zmWgHEou+aojEQ0c3anzYUaEXmPo16Ta9mvxQjxrBuxBisefHxF5yOPC6PtHMjrDafagV6qa0tgS6ZXBGOIEF/Wl+ybAxLZ2g+vjCIeIOh6IidGheuDTaPw==" Feb 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:28 volumio volumio-remote-updater[643]: [2026-02-09 04:13:28] [connect] Successful connection Feb 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13:28+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13:28+07:00" level=debug msg="completed challenge" Feb 09 04:13:28 volumio volumio[9531]: info: Loading plugin "outputs"... Feb 09 04:13:28 volumio go-librespot[9620]: time="2026-02-09T04:13:28+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 09 04:13:28 volumio volumio[9531]: info: Loading plugin "albumart"... Feb 09 04:13:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:28 volumio volumio[9531]: info: Plugin example_plugin is not enabled Feb 09 04:13:28 volumio volumio[9531]: info: Loading plugin "inputs"... Feb 09 04:13:28 volumio volumio[9531]: info: Loading plugin "updater_comm"... Feb 09 04:13:28 volumio volumio[9531]: info: Plugin mpdemulation is not enabled Feb 09 04:13:28 volumio volumio[9531]: info: Loading plugin "rest_api"... Feb 09 04:13:29 volumio volumio[9531]: info: Loading plugin "websocket"... Feb 09 04:13:29 volumio volumio[9531]: info: Starting Socket.io Server version 1.7.4 Feb 09 04:13:29 volumio volumio[9531]: info: Loading plugin "RoonBridge"... Feb 09 04:13:29 volumio volumio[9531]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 04:13:29 volumio volumio[9531]: info: Loading i18n strings for locale en Feb 09 04:13:29 volumio volumio[9531]: Updating browse sources language Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::initPlayerControls Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:13:29 volumio volumio[9531]: Express server listening on port 3000 Feb 09 04:13:29 volumio volumio[9531]: [Metrics] WebUI: 15s 962.61ms Feb 09 04:13:29 volumio volumio[9643]: Forking 3 albumart workers Feb 09 04:13:29 volumio volumio[9531]: info: CoreStateMachine::resetVolumioState Feb 09 04:13:29 volumio volumio[9531]: info: CoreStateMachine::getcurrentVolume Feb 09 04:13:29 volumio volumio[9531]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:13:30 volumio sudo[9661]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:13:30 volumio sudo[9661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:30 volumio sudo[9661]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:30 volumio sudo[9670]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:13:30 volumio sudo[9670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:30 volumio sudo[9670]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:30 volumio volumio[9531]: info: Volumio Network Manager: Network status updated: 1 Feb 09 04:13:30 volumio volumio[9531]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::pushState Feb 09 04:13:30 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::volumioPushState Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::updateTrackBlock Feb 09 04:13:30 volumio volumio[9531]: info: CorePlayQueue::getTrackBlock Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:13:30 volumio volumio-remote-updater[643]: [2026-02-09 04:13:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770585208 101 Feb 09 04:13:30 volumio volumio[9531]: 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 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:30 volumio volumio[9531]: info: Reloading queue from file Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::setRepeat null single undefined Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::pushState Feb 09 04:13:30 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::volumioPushState Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::setRandom null Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::pushState Feb 09 04:13:30 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::volumioPushState Feb 09 04:13:30 volumio volumio[9531]: info: Setting Device type: Raspberry PI Feb 09 04:13:30 volumio volumio[9531]: info: Completed loading Core Plugins Feb 09 04:13:30 volumio volumio[9531]: info: Preparing to generate the ALSA configuration file Feb 09 04:13:30 volumio volumio[9531]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:13:30 volumio volumio[9531]: info: CoreStateMachine::pushState Feb 09 04:13:30 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::volumioPushState Feb 09 04:13:30 volumio volumio[9531]: info: Asound.conf file unchanged, so no further update is needed Feb 09 04:13:30 volumio volumio[9531]: info: Output device has changed, restarting MPD Feb 09 04:13:30 volumio volumio[9531]: info: Output device has changed, restarting Shairport Sync Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:30 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:31 volumio sudo[9704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 04:13:31 volumio sudo[9704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:31 volumio sudo[9708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:13:31 volumio sudo[9708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:31 volumio sudo[9706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:13:31 volumio sudo[9706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:31 volumio sudo[9706]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:31 volumio volumio[9531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:13:31 volumio volumio[9531]: info: ___________ START PLUGINS ___________ Feb 09 04:13:31 volumio volumio[9531]: info: ControllerMpd::onStart: Initializing MPD Feb 09 04:13:31 volumio volumio[9531]: info: Creating MPD Configuration file Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:13:31 volumio volumio[9531]: info: [1770585211196] CoreMusicLibrary::Adding element Media Servers Feb 09 04:13:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 04:13:31 volumio sudo[9704]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:13:31 volumio sudo[9717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:13:31 volumio sudo[9717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:31 volumio volumio[9531]: info: UPNP Browser: Client initialized successfully Feb 09 04:13:31 volumio sudo[9717]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:31 volumio sudo[9719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:13:31 volumio sudo[9719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:13:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:13:31 volumio systemd[1]: mpd.service: Consumed 7.173s CPU time. Feb 09 04:13:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:13:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:13:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:31 volumio volumio[9531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:13:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:13:31 volumio volumio[9531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:13:31 volumio volumio[9531]: info: [1770585211514] CoreMusicLibrary::Adding element Last_100 Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:13:31 volumio volumio[9531]: info: [1770585211526] CoreMusicLibrary::Adding element Webradio Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:13:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:13:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:13:31 volumio volumio[9531]: info: Initializing BBC Radios Feb 09 04:13:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:13:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:13:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:13:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:13:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:31 volumio volumio[9531]: info: Creating Spotify config file Feb 09 04:13:31 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 09 04:13:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:31 volumio go-librespot[9747]: go-librespot daemon starting... Feb 09 04:13:32 volumio go-librespot[9748]: time="2026-02-09T04:13:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:32 volumio sudo[9736]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 04:13:32 volumio sudo[9736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 04:13:32 volumio sudo[9736]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:32 volumio go-librespot[9748]: time="2026-02-09T04:13:32+07:00" level=info msg="zeroconf server listening on port 45737" Feb 09 04:13:33 volumio volumio[9531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:13:33 volumio volumio[9531]: info: [1770585213192] CoreMusicLibrary::Adding element YouTube Music Feb 09 04:13:33 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:13:33 volumio volumio[9531]: Cannot find translation for source YouTube Music Feb 09 04:13:33 volumio volumio[9531]: info: Volumio Calling Home Feb 09 04:13:33 volumio sudo[9759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 04:13:33 volumio sudo[9759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:33 volumio sudo[9759]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:33 volumio volumio[9659]: Starting albumart workers Feb 09 04:13:33 volumio volumio[9657]: Starting albumart workers Feb 09 04:13:33 volumio volumio[9658]: Starting albumart workers Feb 09 04:13:33 volumio volumio[9531]: info: MPD Permissions set Feb 09 04:13:33 volumio volumio[9531]: info: MPD Permissions set Feb 09 04:13:33 volumio volumio[9531]: info: Upmpdcli Daemon Started Feb 09 04:13:33 volumio volumio[9531]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:13:33 volumio volumio[9531]: info: Discovery: Found device Volumio Feb 09 04:13:33 volumio volumio[9531]: info: CoreCommandRouter::volumioGetState Feb 09 04:13:33 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:33 volumio volumio[9531]: info: Spotify config file written Feb 09 04:13:34 volumio volumio[9531]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:13:34 volumio volumio[9531]: info: Discovery: Found device Volumio Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::volumioGetState Feb 09 04:13:34 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:34 volumio sudo[9765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 04:13:34 volumio sudo[9765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:34 volumio volumio[9531]: 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 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 04:13:34 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 04:13:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:34 volumio go-librespot[9772]: go-librespot daemon starting... Feb 09 04:13:34 volumio sudo[9765]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:13:34 volumio volumio[9531]: info: No need to fix Spotify hosts Feb 09 04:13:34 volumio go-librespot[9775]: time="2026-02-09T04:13:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:34 volumio go-librespot[9775]: time="2026-02-09T04:13:34+07:00" level=debug msg="app state loaded" Feb 09 04:13:34 volumio go-librespot[9775]: time="2026-02-09T04:13:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+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 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+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 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+07:00" level=info msg="zeroconf server listening on port 46739" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+07:00" level=debug msg="obtained new client token: AAB9HjcLIhxQHBlj/DqgvJrK5qmRaGPNeBZtAqjg00gC5VOqBQ1FhRQ26H6bF+gABtXASd/sq54MVxKLvqQ8j8oNnTW9+R38erKHJw8+VSqFgLgwPUNTOGDIc4q70ko3LoyBOwJDA5JjkxRh/gMINy/9PGTbP/lUZBbK1FV2hUU1ChHqFeULd3VmtnLHUJxmvqVcmB6mJF8Jsz6wdYqI/+j79X2oWGctgOE8fnFy0qsUjxLUAiNEd4mRMQ==" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13:35+07:00" level=debug msg="completed challenge" Feb 09 04:13:35 volumio go-librespot[9775]: time="2026-02-09T04:13: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 09 04:13:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:36 volumio volumio[9531]: info: Volumio called home Feb 09 04:13:36 volumio volumio[9531]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:13:36 volumio volumio[9531]: SPOTIFY: BQB2a80Ezb0CP4OPSZG6xdqTeH6YfmTMU-GxsKIVqvA4DS7T7BUHepDrKPopdGD3G0jJUwO9KZgkxyzDSZ8mWwQA-NrnKdD8KODrdeQRvlbhDEltVZQDVPrgRMOPcy93W9G9I_1oPj6mYxqaArWr0_I2njVdc3vIp9lacQsx7_Apxt_zj9HOc2JhkKHSMxUS6GQFZOzKqylAjkcO_ZZSGLcZ0d30Rq-5IUl7KS331spgLUPm_GQ9M1RrJlzDVvrrj8kZaxMVj__COcDq4MjEUxtpDj_8pmpJXt7O191FOGzhLVfAYVtdJg9b Feb 09 04:13:36 volumio volumio[9531]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:13:36 volumio volumio[9531]: info: New Spotify access token = BQB2a80Ezb0CP4OPSZG6xdqTeH6YfmTMU-GxsKIVqvA4DS7T7BUHepDrKPopdGD3G0jJUwO9KZgkxyzDSZ8mWwQA-NrnKdD8KODrdeQRvlbhDEltVZQDVPrgRMOPcy93W9G9I_1oPj6mYxqaArWr0_I2njVdc3vIp9lacQsx7_Apxt_zj9HOc2JhkKHSMxUS6GQFZOzKqylAjkcO_ZZSGLcZ0d30Rq-5IUl7KS331spgLUPm_GQ9M1RrJlzDVvrrj8kZaxMVj__COcDq4MjEUxtpDj_8pmpJXt7O191FOGzhLVfAYVtdJg9b Feb 09 04:13:36 volumio volumio[9531]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 04:13:36 volumio volumio[9531]: info: Starting Shairport Sync Feb 09 04:13:36 volumio volumio[9531]: info: Starting Shairport Sync Feb 09 04:13:36 volumio volumio[9531]: info: Starting Shairport Sync Feb 09 04:13:36 volumio sudo[9806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:13:36 volumio sudo[9806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:36 volumio sudo[9810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:13:36 volumio sudo[9808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:13:36 volumio sudo[9808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:36 volumio sudo[9810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:13:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:13:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:13:36 volumio systemd[1]: shairport-sync.service: Consumed 2.390s CPU time. Feb 09 04:13:36 volumio volumio[9531]: info: CoreCommandRouter::volumioGetState Feb 09 04:13:36 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:13:36 volumio sudo[9810]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:36 volumio sudo[9808]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:36 volumio sudo[9806]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:36 volumio volumio[9531]: info: Shairport-Sync Started Feb 09 04:13:36 volumio volumio[9531]: Error adding Membership: Error: addMembership EINVAL Feb 09 04:13:36 volumio volumio[9531]: info: Shairport-Sync Started Feb 09 04:13:36 volumio volumio[9531]: info: Shairport-Sync Started Feb 09 04:13:36 volumio volumio[9531]: 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 09 04:13:36 volumio volumio[9531]: info: Spotify Successfully logged in Feb 09 04:13:36 volumio volumio[9531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:13:36 volumio volumio[9531]: info: [1770585216884] CoreMusicLibrary::Adding element Spotify Feb 09 04:13:36 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:13:36 volumio volumio[9531]: Cannot find translation for source YouTube Music Feb 09 04:13:36 volumio volumio[9531]: Cannot find translation for source Spotify Feb 09 04:13:37 volumio volumio[9531]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 04:13:37 volumio volumio[9531]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:13:37 volumio volumio[9531]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:13:37 volumio volumio[9531]: info: CoreCommandRouter::volumioGetState Feb 09 04:13:37 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:37 volumio volumio[9531]: info: CoreStateMachine::pushState Feb 09 04:13:37 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:37 volumio volumio[9531]: info: CoreCommandRouter::volumioPushState Feb 09 04:13:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 04:13:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:38 volumio go-librespot[9845]: go-librespot daemon starting... Feb 09 04:13:38 volumio go-librespot[9846]: time="2026-02-09T04:13:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:38 volumio go-librespot[9846]: time="2026-02-09T04:13:38+07:00" level=debug msg="app state loaded" Feb 09 04:13:38 volumio go-librespot[9846]: time="2026-02-09T04:13:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:39 volumio volumio[9531]: info: go-librespot daemon successfully initialized Feb 09 04:13:39 volumio mpd[9755]: 2026-02-09T04:13:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 04:13:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 04:13:39 volumio sudo[9719]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:39 volumio sudo[9708]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+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 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+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 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+07:00" level=info msg="zeroconf server listening on port 37867" Feb 09 04:13:39 volumio volumio[9531]: error: MPD error: The expression evaluated to a falsy value: Feb 09 04:13:39 volumio volumio[9531]: assert.ok(self.idling) Feb 09 04:13:39 volumio volumio[9531]: error: The expression evaluated to a falsy value: Feb 09 04:13:39 volumio volumio[9531]: assert.ok(self.idling) Feb 09 04:13:39 volumio volumio[9531]: error: updateQueue error: null Feb 09 04:13:39 volumio volumio[9531]: info: MPD running with PID9755 Feb 09 04:13:39 volumio volumio[9531]: ,establishing connection Feb 09 04:13:39 volumio volumio[9531]: info: Completed starting Core Plugins Feb 09 04:13:39 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:39 volumio volumio[9531]: info: ----- MyVolumio plugins startup ---- Feb 09 04:13:39 volumio volumio[9531]: info: ------------------------------------------- Feb 09 04:13:39 volumio volumio[9531]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 04:13:39 volumio volumio[9531]: error: updateQueue error: null Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+07:00" level=debug msg="obtained new client token: AADgE7hKxeqrwL9n8UK/XnkSXaXa9v16aGRaBVsRQMUgZE1J+ZnZRz/M8J6JncZqn3c9lwFML4RE6hmjXKGCAu3dwmjXyw8vzqVBkOxJ+v7TFzrBYMkUKK8wQeYlIwhqsYDeYySVphV+eI5EuDcjjEbxBISZZLXpfxUoofrBZQGRXehKSR3CnU4Ok1p+s8sByqsT0coOFriLS9Ka5Yhnj2svCk9YcHSxPxsfLSvyl3EB/cyFY1hn8wbT4A==" Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13:39+07:00" level=debug msg="completed challenge" Feb 09 04:13:39 volumio go-librespot[9846]: time="2026-02-09T04:13: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 09 04:13:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:42 volumio volumio[9531]: info: Initializing connection to go-librespot Websocket Feb 09 04:13:42 volumio volumio[9531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:13:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 04:13:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:43 volumio go-librespot[9859]: go-librespot daemon starting... Feb 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13:43+07:00" level=debug msg="app state loaded" Feb 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13: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 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13: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 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13: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 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13:43+07:00" level=info msg="zeroconf server listening on port 44669" Feb 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13:43+07:00" level=debug msg="obtained new client token: AAAp2M+bh8tZU/sh6nOwTleZrY18dKaj5AhrCfsn6351kyVyreGGTuZmtnvHxsZm+W3buMB9FzMxYgk43wIvTBAq1KyzgwNH1eEHRRFo24SsscY8fVodfo0OXcjNNR0j/xkEbHc1bhr/xMPpevTG0Z/jYaKDsWf9gGsqQuEC6xUmo7DOtDV88vMGRDowQffN6nuzbwlkTSa+3yjgZsl9I5v+GiZB8ghOembaXC2Bh6bz56KWMzSh4MgpFQ==" Feb 09 04:13:43 volumio go-librespot[9860]: time="2026-02-09T04:13:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:44 volumio go-librespot[9860]: time="2026-02-09T04:13:44+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:44 volumio go-librespot[9860]: time="2026-02-09T04:13:44+07:00" level=debug msg="completed challenge" Feb 09 04:13:44 volumio go-librespot[9860]: time="2026-02-09T04:13:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:13:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:44 volumio volumio[9531]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:13:45 volumio volumio[9531]: info: Initializing connection to go-librespot Websocket Feb 09 04:13:45 volumio volumio[9531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:13:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 04:13:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:47 volumio go-librespot[9868]: go-librespot daemon starting... Feb 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13:47+07:00" level=debug msg="app state loaded" Feb 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13:47+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 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13:47+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 09 04:13:47 volumio go-librespot[9869]: time="2026-02-09T04:13:47+07:00" level=info msg="zeroconf server listening on port 35965" Feb 09 04:13:48 volumio volumio[9531]: info: Initializing connection to go-librespot Websocket Feb 09 04:13:48 volumio go-librespot[9869]: time="2026-02-09T04:13:48+07:00" level=debug msg="new websocket client" Feb 09 04:13:48 volumio volumio[9531]: info: Connection to go-librespot Websocket established Feb 09 04:13:48 volumio go-librespot[9869]: time="2026-02-09T04:13:48+07:00" level=debug msg="obtained new client token: AABce86s0k/+jh7I4LIxMSn5Z++isFSWLdtZ4AX6ew8cPt2aUUR3bDEOTlKK7hHf2tmqlavXCzGC/v+w/2zk7ZLxHU9XTGiHyPyj8CDcWXeS+YYfGO6KdsJysl5RV9xD68gYZ5Xteb2rGociX1vGOPblPE74C17syUk7WlyANO/7t7PI0gUDdKTCk2p3Vnxt6UJh1EUEwlfRNZWZL2wD9OdxTtg6kgUDDbvex+0FT/AClyY/+ixxE44=" Feb 09 04:13:48 volumio go-librespot[9869]: time="2026-02-09T04:13:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:13:48 volumio go-librespot[9869]: time="2026-02-09T04:13:48+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:48 volumio go-librespot[9869]: time="2026-02-09T04:13:48+07:00" level=debug msg="completed challenge" Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:13:48 volumio volumio[9531]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:13:48 volumio go-librespot[9869]: time="2026-02-09T04:13:48+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 09 04:13:48 volumio volumio[9531]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:13:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:50 volumio volumio[9531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:13:50 volumio volumio[9531]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:13:50 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:50 volumio volumio[9531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:13:50 volumio volumio[9531]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:13:50 volumio volumio[9531]: info: MyVolumio login type: Token Feb 09 04:13:50 volumio volumio[9531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:13:50 volumio volumio[9531]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:13:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 04:13:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:13:51 volumio go-librespot[9890]: go-librespot daemon starting... Feb 09 04:13:51 volumio go-librespot[9891]: time="2026-02-09T04:13:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:13:51 volumio go-librespot[9891]: time="2026-02-09T04:13:51+07:00" level=debug msg="app state loaded" Feb 09 04:13:51 volumio go-librespot[9891]: time="2026-02-09T04:13:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:13:52 volumio volumio[9531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:13:52 volumio volumio[9531]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:13:52 volumio volumio[9531]: info: Streaming services startup Feb 09 04:13:52 volumio volumio[9531]: info: Starting Streaming Daemon Feb 09 04:13:52 volumio sudo[9899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:13:52 volumio volumio[9531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:13:52 volumio sudo[9899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+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 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+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 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+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 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+07:00" level=info msg="zeroconf server listening on port 34455" Feb 09 04:13:52 volumio sudo[9899]: pam_unix(sudo:session): session closed for user root Feb 09 04:13:52 volumio volumio[9531]: info: Getting Spotify volume Feb 09 04:13:52 volumio volumio[9531]: info: Connection to go-librespot Websocket closed Feb 09 04:13:52 volumio volumio[9531]: error: Cannot start Volumio Streaming Daemon Feb 09 04:13:52 volumio volumio[9531]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:13:52 volumio volumio[9531]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:13:52 volumio volumio[9531]: 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 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+07:00" level=debug msg="obtained new client token: AACFdm6QElX6rU8uBwwXdZmgbe+f6bvR5V4h6oBbqP6seoyuKsw+195o2KUDBX3u/vaz5381eg8wmOAWvnBqe7huJ6k4bvwdY0PbZXgJk5TyB2AIyZ2FXX1dG7oKfkqrdLGxmBhkyQt5deIIPslnxVAq+1XftN0I1saqIQOQt0ng6Wr9fvpeGjSEg8ZH13lLoO9Qyk+jFM2OHEee+vl1jdrhrpdR2lbpq5PYYFIwmhKhns4aAXnOYwSWvA==" Feb 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+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 09 04:13:52 volumio volumio[9531]: info: CoreCommandRouter::volumioGetState Feb 09 04:13:52 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:52 volumio volumio[9531]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 09 04:13:52 volumio volumio[9531]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 04:13:52 volumio volumio[9531]: SPOTIFY: VOLUMIO VOLUME 100 Feb 09 04:13:52 volumio volumio[9531]: info: Aligning Spotify Volume to Volumio Volume Feb 09 04:13:52 volumio volumio[9531]: info: CoreCommandRouter::volumioGetState Feb 09 04:13:52 volumio volumio[9531]: info: CorePlayQueue::getTrack 0 Feb 09 04:13:52 volumio volumio[9531]: info: Setting Spotify Volume from Volumio: 100 Feb 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+07:00" level=debug msg="completed keyexchange" Feb 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13:52+07:00" level=debug msg="completed challenge" Feb 09 04:13:52 volumio go-librespot[9891]: time="2026-02-09T04:13: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 09 04:13:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:13:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:13:52 volumio volumio[9531]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:13:52 volumio volumio[9531]: Error: socket hang up Feb 09 04:13:52 volumio volumio[9531]: at connResetException (node:internal/errors:720:14) Feb 09 04:13:52 volumio volumio[9531]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 04:13:52 volumio volumio[9531]: at Socket.emit (node:events:526:35) Feb 09 04:13:52 volumio volumio[9531]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 04:13:52 volumio volumio[9531]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 04:13:52 volumio volumio[9531]: code: 'ECONNRESET', Feb 09 04:13:52 volumio volumio[9531]: response: undefined Feb 09 04:13:52 volumio volumio[9531]: } Feb 09 04:13:52 volumio volumio[9531]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:13:54 volumio sudo[9919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:12' Feb 09 04:13:54 volumio sudo[9919]: 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"