Jan 26 00:09:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:01 volumio volumio[11858]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 00:09:01 volumio volumio[11858]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 00:09:01 volumio volumio[11858]: info: Streaming services startup Jan 26 00:09:01 volumio volumio[11858]: info: Starting Streaming Daemon Jan 26 00:09:01 volumio sudo[12210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 00:09:01 volumio volumio[11858]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 00:09:01 volumio sudo[12210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:01 volumio sudo[12210]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:01 volumio volumio[11858]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:01 volumio volumio[11858]: error: Cannot start Volumio Streaming Daemon Jan 26 00:09:01 volumio volumio[11858]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 00:09:01 volumio volumio[11858]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 00:09:01 volumio volumio[11858]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:02 volumio volumio[11858]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 00:09:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 00:09:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:02 volumio go-librespot[12216]: go-librespot daemon starting... Jan 26 00:09:02 volumio go-librespot[12217]: time="2026-01-26T00:09:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:02 volumio go-librespot[12217]: time="2026-01-26T00:09:02+07:00" level=debug msg="app state loaded" Jan 26 00:09:02 volumio go-librespot[12217]: time="2026-01-26T00:09:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+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]" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+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]" Jan 26 00:09:03 volumio volumio[11858]: info: MyVolumio token set successfully Jan 26 00:09:03 volumio volumio[11858]: info: MYVOLUMIO: Adding device Jan 26 00:09:03 volumio volumio[11858]: info: MYVOLUMIO: Evaluating Server Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=info msg="zeroconf server listening on port 34517" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=debug msg="obtained new client token: AABI8MZIsWM1jx62Qb8NmDmDHfBSHo7+M5DxsYW2zpTZNuRd8wBUO2g2o+ZgGE+Xs+VrKcPhCB4yeBnbnczhvqcFHL9X7MrOph/bnpXqRp1L0F7/5SQdR9nGSBcvb9xO9ZqjmEad+2DlgvASnSwpGuNQuMBhh1iKix4lbRqlIJ8FblHrgtmvpe+Tmg+8aQwXmI6Lnrt+qGd9H3jjR8ghgmBsEN62j1TOFoG25r6cOqLyEvfXDvTpZLXgdJ8=" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=debug msg="completed challenge" Jan 26 00:09:03 volumio go-librespot[12217]: time="2026-01-26T00:09:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:03 volumio volumio[11858]: info: MyVolumio status changed Jan 26 00:09:03 volumio volumio[11858]: info: Streaming services startup Jan 26 00:09:03 volumio volumio[11858]: info: Starting Streaming Daemon Jan 26 00:09:03 volumio volumio[11858]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 00:09:03 volumio volumio[11858]: info: Removing audio output: Jan 26 00:09:03 volumio volumio[11858]: info: Stoppping Tunnel 1 Jan 26 00:09:03 volumio sudo[12246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 00:09:03 volumio sudo[12246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:04 volumio sudo[12246]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:04 volumio sudo[12249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 26 00:09:04 volumio sudo[12249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:04 volumio volumio[11858]: error: Cannot start Volumio Streaming Daemon Jan 26 00:09:04 volumio volumio[11858]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 00:09:04 volumio volumio[11858]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 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. Jan 26 00:09:04 volumio sudo[12249]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:04 volumio volumio[11858]: info: Remote SSH Stopped Jan 26 00:09:04 volumio volumio[11858]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:04 volumio volumio[11858]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:04 volumio volumio[11858]: info: Setting Geolocation for MyVolumio to as1 Jan 26 00:09:04 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:04 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:04 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:05 volumio volumio[11858]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 00:09:05 volumio volumio[11858]: info: Updating MyVolumio device info Jan 26 00:09:05 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:05 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:05 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:06 volumio volumio[11858]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 00:09:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 00:09:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:07 volumio go-librespot[12251]: go-librespot daemon starting... Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=debug msg="app state loaded" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:07 volumio volumio[11858]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=debug msg="new websocket client" Jan 26 00:09:07 volumio volumio[11858]: info: Connection to go-librespot Websocket established Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=info msg="zeroconf server listening on port 33959" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+07:00" level=debug msg="obtained new client token: AAByb46jpp62q4bCnyTX/Xv6ASC1Z+jkuB7srAbWbnCOgd6D0XuSSX87HmrOCAE58/eG5+OBF2R7nDYlZFE7rCm0zvK+AoJ9+Gc61QXqeiO6LFJPtIikWOBky7ACd1JL2ZkDoA9HZHe9k2naV1srfAvfXby5+GjiPEV0iSoDT/haRSM0qQ22NFca+EfRorHvi4e0TOW2K2QkZPbYZIM0joTeHcz9ZUFnkWazXmlEWJR+iCwiM47h2aGNh8Y=" Jan 26 00:09:07 volumio go-librespot[12252]: time="2026-01-26T00:09:07+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" Jan 26 00:09:08 volumio go-librespot[12252]: time="2026-01-26T00:09:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 00:09:08 volumio go-librespot[12252]: time="2026-01-26T00:09:08+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:08 volumio go-librespot[12252]: time="2026-01-26T00:09:08+07:00" level=debug msg="completed challenge" Jan 26 00:09:08 volumio go-librespot[12252]: time="2026-01-26T00:09:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:08 volumio volumio[11858]: info: Connection to go-librespot Websocket closed Jan 26 00:09:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:09 volumio volumio[11858]: info: MYVOLUMIO: Adding device Jan 26 00:09:09 volumio volumio[11858]: info: MYVOLUMIO: Evaluating Server Jan 26 00:09:10 volumio volumio[11858]: info: Setting Geolocation for MyVolumio to as1 Jan 26 00:09:10 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:10 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:10 volumio volumio[11858]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:10 volumio volumio[11858]: info: Getting Spotify volume Jan 26 00:09:10 volumio volumio[11858]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 00:09:10 volumio volumio[11858]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:10 volumio volumio[11858]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 00:09:10 volumio volumio[11858]: errno: -111, Jan 26 00:09:10 volumio volumio[11858]: code: 'ECONNREFUSED', Jan 26 00:09:10 volumio volumio[11858]: syscall: 'connect', Jan 26 00:09:10 volumio volumio[11858]: address: '127.0.0.1', Jan 26 00:09:10 volumio volumio[11858]: port: 9879, Jan 26 00:09:10 volumio volumio[11858]: response: undefined Jan 26 00:09:10 volumio volumio[11858]: } Jan 26 00:09:10 volumio volumio[11858]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 00:09:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 00:09:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:11 volumio go-librespot[12306]: go-librespot daemon starting... Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+07:00" level=debug msg="app state loaded" Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+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]" Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+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]" Jan 26 00:09:11 volumio sudo[12316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 00:08' Jan 26 00:09:11 volumio sudo[12316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:11 volumio go-librespot[12307]: time="2026-01-26T00:09:11+07:00" level=info msg="zeroconf server listening on port 32947" Jan 26 00:09:12 volumio go-librespot[12307]: time="2026-01-26T00:09:12+07:00" level=debug msg="obtained new client token: AAADr3EHuryR6xHJ0VQMGKtpg2AKmvAuqVk4kdWGr6uTY5g0APHx+AdfHMYY0n6AA3sbVH4vDgTPTrS/nUgEzQauT9uU5tEFCZk/yYIfBMpzcTrY6857bLRarg0rlfl1h63ukL1MfwSm7c6kblDjy34WH1l2HyQvh1di+ZIJaiHMY9eEW6ggYfAlkIaFO38W6Wn6I5bpnYW6QCl+JQCHNLmyA/mDtNoxxcj2n3SjtNopZQZ9GeSxz3WD" Jan 26 00:09:12 volumio sudo[12316]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:12 volumio go-librespot[12307]: time="2026-01-26T00:09:12+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" Jan 26 00:09:12 volumio go-librespot[12307]: time="2026-01-26T00:09:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 00:09:12 volumio go-librespot[12307]: time="2026-01-26T00:09:12+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:12 volumio go-librespot[12307]: time="2026-01-26T00:09:12+07:00" level=debug msg="completed challenge" Jan 26 00:09:12 volumio go-librespot[12307]: time="2026-01-26T00:09:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:12 volumio volumio-remote-updater[628]: [2026-01-26 00:09:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 26 00:09:12 volumio volumio-remote-updater[628]: [2026-01-26 00:09:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 26 00:09:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 00:09:12 volumio systemd[1]: volumio.service: Consumed 1min 5.732s CPU time. Jan 26 00:09:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 00:09:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 00:09:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6201. Jan 26 00:09:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 00:09:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 00:09:12 volumio systemd[1]: volumio.service: Consumed 1min 5.732s CPU time. Jan 26 00:09:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 00:09:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 00:09:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 00:09:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:15 volumio go-librespot[12346]: go-librespot daemon starting... Jan 26 00:09:15 volumio go-librespot[12347]: time="2026-01-26T00:09:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:15 volumio go-librespot[12347]: time="2026-01-26T00:09:15+07:00" level=debug msg="app state loaded" Jan 26 00:09:15 volumio go-librespot[12347]: time="2026-01-26T00:09:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+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]" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+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]" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=info msg="zeroconf server listening on port 35031" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=debug msg="obtained new client token: AABPxt58DzEQTKPXb7+3b7ZmVmMR3io7hbwBkLFAGR3SAMOPKrdpInDG9fWvcjDymdYPX2MBFLxoscqonECc1nzG6A8j7u3vIQwbFewlFnn7FfXAtv0Xq2nvmma+5AC88LwgyW5cTsRQJGW4nsN3yukuJFmd4H9XYuMc4mLBQz2tXPM/GqM+dmrxK6VMLuywPoVPwC5NkNz2PwwrN2Z/FClMyAr6zMJYv6Zt8AzU8+O4SQErArOaszx+OCk=" Jan 26 00:09:16 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:16 volumio volumio[12331]: info: ----- Volumio3 ---- Jan 26 00:09:16 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:16 volumio volumio[12331]: info: ----- System startup ---- Jan 26 00:09:16 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=debug msg="completed challenge" Jan 26 00:09:16 volumio go-librespot[12347]: time="2026-01-26T00:09:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:17 volumio volumio-remote-updater[628]: [2026-01-26 00:09:17] [connect] Successful connection Jan 26 00:09:17 volumio volumio[12331]: info: MYVOLUMIO Environment detected Jan 26 00:09:17 volumio volumio[12331]: info: Plugin folders cleanup Jan 26 00:09:17 volumio volumio[12331]: info: Scanning into folder /volumio/app/plugins/ Jan 26 00:09:17 volumio volumio[12331]: info: Scanning category audio_interface Jan 26 00:09:18 volumio volumio[12331]: info: Scanning category miscellanea Jan 26 00:09:18 volumio volumio[12331]: info: Scanning category music_service Jan 26 00:09:18 volumio volumio[12331]: info: Scanning category plugins.json Jan 26 00:09:18 volumio volumio[12331]: info: Scanning category system_controller Jan 26 00:09:18 volumio volumio[12331]: info: Scanning category user_interface Jan 26 00:09:18 volumio volumio[12331]: info: Scanning into folder /data/plugins/ Jan 26 00:09:18 volumio volumio[12331]: info: Scanning category music_service Jan 26 00:09:18 volumio volumio[12331]: info: Plugin folders cleanup completed Jan 26 00:09:18 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:18 volumio volumio[12331]: info: ----- Core plugins startup ---- Jan 26 00:09:18 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:18 volumio volumio[12331]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 00:09:18 volumio volumio[12331]: info: Adding plugin upnp to MyMusic Plugins Jan 26 00:09:18 volumio volumio[12331]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 00:09:18 volumio volumio[12331]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 00:09:18 volumio volumio[12331]: info: Loading plugins from folder /data/plugins/ Jan 26 00:09:18 volumio volumio[12331]: info: Loading plugin "system"... Jan 26 00:09:18 volumio volumio[12331]: info: Loading plugin "appearance"... Jan 26 00:09:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 00:09:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:19 volumio go-librespot[12367]: go-librespot daemon starting... Jan 26 00:09:19 volumio go-librespot[12368]: time="2026-01-26T00:09:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:19 volumio go-librespot[12368]: time="2026-01-26T00:09:19+07:00" level=debug msg="app state loaded" Jan 26 00:09:19 volumio go-librespot[12368]: time="2026-01-26T00:09:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "network"... Jan 26 00:09:20 volumio volumio[12331]: info: Refreshing Cached IP Addresses Jan 26 00:09:20 volumio sudo[12375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 00:09:20 volumio sudo[12375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:20 volumio sudo[12375]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:20 volumio sudo[12377]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 00:09:20 volumio sudo[12377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:20 volumio sudo[12377]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "services"... Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "alsa_controller"... Jan 26 00:09:20 volumio sudo[12386]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 00:09:20 volumio sudo[12386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:20 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "wizard"... Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "networkfs"... Jan 26 00:09:20 volumio volumio[12331]: info: Starting Udev Watcher for removable devices Jan 26 00:09:20 volumio volumio[12331]: info: Ignoring mount for partition: boot Jan 26 00:09:20 volumio volumio[12331]: info: Ignoring mount for partition: volumio Jan 26 00:09:20 volumio volumio[12331]: info: Ignoring mount for partition: volumio_data Jan 26 00:09:20 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "volumio_command_line_client"... Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "upnp"... Jan 26 00:09:20 volumio volumio[12331]: info: [1769360960481] Starting Upmpd Daemon Jan 26 00:09:20 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "my_music"... Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=info msg="zeroconf server listening on port 38829" Jan 26 00:09:20 volumio volumio[12331]: info: Loading plugin "mpd"... Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="obtained new client token: AAD/QauyTkHO0rVhdXeHtDwhHZ6bfbu/k4FIDk4O5Zv3DCv18eEWK7IDPF1mopdsJKsWa0YpJFxCHpXbyAlFAruLlHfinIob51vCUI1KyDwNGC9fdI69QZ5xl9i9mY2QbVhgFR0ICvos2372Owbe/ez4vl0WOdkwnFGqfae4pXGHJmdG04w8TV8WqbzQjMXRvaBYjQUe9qSHaPfNVf+FpOdz06buPxSTYTRqhApfrUPTCk28XB8jRTsXeUk=" Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:20 volumio go-librespot[12368]: time="2026-01-26T00:09:20+07:00" level=debug msg="completed challenge" Jan 26 00:09:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:21 volumio go-librespot[12368]: time="2026-01-26T00:09:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:21 volumio volumio[12331]: info: Loading plugin "upnp_browser"... Jan 26 00:09:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:23 volumio sudo[12386]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:24 volumio volumio[12331]: info: Starting UPNP Browser Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "alarm-clock"... Jan 26 00:09:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 00:09:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:24 volumio go-librespot[12411]: go-librespot daemon starting... Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=debug msg="app state loaded" Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "airplay_emulation"... Jan 26 00:09:24 volumio volumio[12331]: info: Starting Shairport Sync Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "last_100"... Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "webradio"... Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "i2s_dacs"... Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "volumiodiscovery"... Jan 26 00:09:24 volumio volumio[12331]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 00:09:24 volumio volumio[12331]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:09:24 volumio volumio[12331]: *** WARNING *** For more information see Jan 26 00:09:24 volumio volumio[12331]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 00:09:24 volumio volumio[12331]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:09:24 volumio volumio[12331]: *** WARNING *** For more information see Jan 26 00:09:24 volumio node[12331]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 00:09:24 volumio node[12331]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:09:24 volumio node[12331]: *** WARNING *** For more information see Jan 26 00:09:24 volumio node[12331]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 00:09:24 volumio node[12331]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:09:24 volumio node[12331]: *** WARNING *** For more information see Jan 26 00:09:24 volumio volumio[12331]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 00:09:24 volumio volumio[12331]: info: Discovery: Started advertising with name: Volumio Jan 26 00:09:24 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 00:09:24 volumio volumio[12331]: info: Loading plugin "spop"... Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:09:24 volumio go-librespot[12412]: time="2026-01-26T00:09:24+07:00" level=info msg="zeroconf server listening on port 41921" Jan 26 00:09:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:25 volumio go-librespot[12412]: time="2026-01-26T00:09:25+07:00" level=debug msg="obtained new client token: AACNBYXYKyK3VxX4r5A8wAt1U1XCZ5B9UOJfBXA4+0Vy7Oc9xuWQNqFr6LurIqBdazGNJdfnaQ45P56aedJytSoNOhs+1eqOwSFwUZar1espBYGszb0o/soc0qGZuO95jXeZwh3b9qEwlz0B8v9ZFZdsiDoeGxw8GuHsVbODfrVzpE0qPd7BbzP6ga+now2UAxvZtdv29681RAchgG1fWyY7ioSfUyRP2oWRYX8PC+0ZLU0gdHnGqVPx" Jan 26 00:09:25 volumio go-librespot[12412]: time="2026-01-26T00:09:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:25 volumio go-librespot[12412]: time="2026-01-26T00:09:25+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:25 volumio go-librespot[12412]: time="2026-01-26T00:09:25+07:00" level=debug msg="completed challenge" Jan 26 00:09:25 volumio go-librespot[12412]: time="2026-01-26T00:09:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:26 volumio volumio[12331]: info: Loading plugin "ytcr"... Jan 26 00:09:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 00:09:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:28 volumio go-librespot[12421]: go-librespot daemon starting... Jan 26 00:09:28 volumio go-librespot[12422]: time="2026-01-26T00:09:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:28 volumio go-librespot[12422]: time="2026-01-26T00:09:28+07:00" level=debug msg="app state loaded" Jan 26 00:09:28 volumio go-librespot[12422]: time="2026-01-26T00:09:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+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]" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+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]" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+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]" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=info msg="zeroconf server listening on port 40329" Jan 26 00:09:29 volumio volumio[12331]: info: Loading plugin "ytmusic"... Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=debug msg="obtained new client token: AACQ9Wh3iuF8lFJHOp5sL/m9LQD/iOTsOgqfYqx8qogKFjqdzc9Eq1AFJd/mc0Mu1UKE4+vKYtK8e35PQfHS8c+pkQV/py9cx0VFzRgiIBxTtD9vs+MPaItUq6SRGzJIKC1gtehdfzawnC9q4Jt4u00GqM4G4XXT5qeBUqvoEtPv5ekMc1nPmPu3Ct+y8iZuIetz+IMRSaiJDylrSgTAEJ6jKYsRwCuFPQRem3DhZErWyuMM4776T9w0qyw=" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=debug msg="completed challenge" Jan 26 00:09:29 volumio go-librespot[12422]: time="2026-01-26T00:09:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:30 volumio volumio-remote-updater[628]: [2026-01-26 00:09:30] [connect] Successful connection Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "outputs"... Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "albumart"... Jan 26 00:09:30 volumio volumio[12331]: info: Plugin example_plugin is not enabled Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "inputs"... Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "updater_comm"... Jan 26 00:09:30 volumio volumio[12331]: info: Plugin mpdemulation is not enabled Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "rest_api"... Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "websocket"... Jan 26 00:09:30 volumio volumio[12331]: info: Starting Socket.io Server version 1.7.4 Jan 26 00:09:30 volumio volumio[12331]: info: Loading plugin "RoonBridge"... Jan 26 00:09:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:31 volumio volumio[12331]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 00:09:31 volumio volumio[12331]: info: Loading i18n strings for locale en Jan 26 00:09:31 volumio volumio[12331]: Updating browse sources language Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:09:31 volumio volumio[12443]: Forking 3 albumart workers Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::initPlayerControls Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 00:09:31 volumio volumio[12331]: Express server listening on port 3000 Jan 26 00:09:31 volumio volumio[12331]: [Metrics] WebUI: 16s 143.30ms Jan 26 00:09:31 volumio volumio[12331]: info: CoreStateMachine::resetVolumioState Jan 26 00:09:31 volumio volumio[12331]: info: CoreStateMachine::getcurrentVolume Jan 26 00:09:31 volumio volumio[12331]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 00:09:31 volumio sudo[12486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 00:09:31 volumio sudo[12486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:31 volumio sudo[12486]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:31 volumio sudo[12489]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 00:09:31 volumio sudo[12489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:31 volumio sudo[12489]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:32 volumio volumio[12331]: info: Volumio Network Manager: Network status updated: 1 Jan 26 00:09:32 volumio volumio[12331]: info: VolumeController:: Volume=100 Mute =false Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::pushState Jan 26 00:09:32 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::volumioPushState Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::updateTrackBlock Jan 26 00:09:32 volumio volumio[12331]: info: CorePlayQueue::getTrackBlock Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 00:09:32 volumio volumio-remote-updater[628]: [2026-01-26 00:09:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769360970 101 Jan 26 00:09:32 volumio volumio[12331]: 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 Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:32 volumio volumio[12331]: info: Reloading queue from file Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::setRepeat null single undefined Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::pushState Jan 26 00:09:32 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::volumioPushState Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::setRandom null Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::pushState Jan 26 00:09:32 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::volumioPushState Jan 26 00:09:32 volumio volumio[12331]: info: Setting Device type: Raspberry PI Jan 26 00:09:32 volumio volumio[12331]: info: Completed loading Core Plugins Jan 26 00:09:32 volumio volumio[12331]: info: Preparing to generate the ALSA configuration file Jan 26 00:09:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 26 00:09:32 volumio volumio[12331]: info: VolumeController:: Volume=100 Mute =false Jan 26 00:09:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:32 volumio volumio[12331]: info: CoreStateMachine::pushState Jan 26 00:09:32 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::volumioPushState Jan 26 00:09:32 volumio volumio[12331]: info: Asound.conf file unchanged, so no further update is needed Jan 26 00:09:32 volumio volumio[12331]: info: Output device has changed, restarting MPD Jan 26 00:09:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:32 volumio go-librespot[12502]: go-librespot daemon starting... Jan 26 00:09:32 volumio sudo[12504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 00:09:32 volumio sudo[12504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:32 volumio go-librespot[12505]: time="2026-01-26T00:09:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:32 volumio go-librespot[12505]: time="2026-01-26T00:09:32+07:00" level=debug msg="app state loaded" Jan 26 00:09:32 volumio go-librespot[12505]: time="2026-01-26T00:09:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:32 volumio volumio[12331]: info: Output device has changed, restarting Shairport Sync Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:32 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:33 volumio sudo[12512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 00:09:33 volumio sudo[12512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:33 volumio sudo[12516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 00:09:33 volumio sudo[12512]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:33 volumio sudo[12516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:33 volumio sudo[12504]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:33 volumio volumio[12331]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 00:09:33 volumio volumio[12331]: info: ___________ START PLUGINS ___________ Jan 26 00:09:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 00:09:33 volumio volumio[12331]: info: ControllerMpd::onStart: Initializing MPD Jan 26 00:09:33 volumio volumio[12331]: info: Creating MPD Configuration file Jan 26 00:09:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 00:09:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 00:09:33 volumio systemd[1]: mpd.service: Consumed 7.379s CPU time. Jan 26 00:09:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 00:09:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 00:09:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:09:33 volumio volumio[12331]: info: [1769360973339] CoreMusicLibrary::Adding element Media Servers Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:09:33 volumio sudo[12524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 00:09:33 volumio sudo[12524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:33 volumio sudo[12524]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:33 volumio sudo[12526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 00:09:33 volumio sudo[12526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 00:09:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 00:09:33 volumio volumio[12331]: info: UPNP Browser: Client initialized successfully Jan 26 00:09:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 00:09:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 00:09:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 00:09:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 00:09:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 00:09:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 00:09:33 volumio volumio[12331]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:33 volumio go-librespot[12505]: time="2026-01-26T00:09:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:33 volumio go-librespot[12505]: time="2026-01-26T00:09:33+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]" Jan 26 00:09:33 volumio go-librespot[12505]: time="2026-01-26T00:09:33+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]" Jan 26 00:09:33 volumio volumio[12331]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:09:33 volumio volumio[12331]: info: [1769360973725] CoreMusicLibrary::Adding element Last_100 Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:09:33 volumio volumio[12331]: info: [1769360973735] CoreMusicLibrary::Adding element Webradio Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:09:33 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:09:33 volumio volumio[12331]: info: Initializing BBC Radios Jan 26 00:09:33 volumio go-librespot[12505]: time="2026-01-26T00:09:33+07:00" level=info msg="zeroconf server listening on port 33467" Jan 26 00:09:34 volumio go-librespot[12505]: time="2026-01-26T00:09:34+07:00" level=debug msg="obtained new client token: AAA0ejShTE5Ct/TMI2Q4nx+ruBaWbxVUDZgbZd7c9Ccx2gL9CYwb3Zl4TEn9y+RL0jPxvnptIF62glLQu0JhVnwXtayp0jtsD1xTAlIHN2mU5Mz/YkzYqzP3vA9UTSm+k4Yn2cTRNFugS/fAkyUck3QdAYKpoU7tiZggNBVQdHapR0tDodecismqCAHjpE3c20Hva93yN4/6EQf6UuAvnzlxgA0gmPdu7GRFU9ukmZqCMP6Qm/5bFtE3OkY=" Jan 26 00:09:34 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:09:34 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:34 volumio go-librespot[12505]: time="2026-01-26T00:09:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:34 volumio volumio[12331]: info: Creating Spotify config file Jan 26 00:09:34 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:34 volumio sudo[12536]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 00:09:34 volumio sudo[12536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 00:09:34 volumio sudo[12536]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:34 volumio go-librespot[12505]: time="2026-01-26T00:09:34+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:34 volumio go-librespot[12505]: time="2026-01-26T00:09:34+07:00" level=debug msg="completed challenge" Jan 26 00:09:34 volumio go-librespot[12505]: time="2026-01-26T00:09:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:34 volumio volumio[12454]: Starting albumart workers Jan 26 00:09:34 volumio volumio[12453]: Starting albumart workers Jan 26 00:09:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:35 volumio volumio[12455]: Starting albumart workers Jan 26 00:09:35 volumio volumio[12331]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:09:35 volumio volumio[12331]: info: [1769360975422] CoreMusicLibrary::Adding element YouTube Music Jan 26 00:09:35 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:09:35 volumio volumio[12331]: Cannot find translation for source YouTube Music Jan 26 00:09:35 volumio volumio[12331]: info: Volumio Calling Home Jan 26 00:09:35 volumio sudo[12559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 00:09:35 volumio sudo[12559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:35 volumio sudo[12559]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:36 volumio volumio[12331]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 00:09:36 volumio volumio[12331]: info: Discovery: Found device Volumio Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::volumioGetState Jan 26 00:09:36 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:36 volumio volumio[12331]: info: MPD Permissions set Jan 26 00:09:36 volumio volumio[12331]: info: MPD Permissions set Jan 26 00:09:36 volumio volumio[12331]: info: Upmpdcli Daemon Started Jan 26 00:09:36 volumio volumio[12331]: info: Spotify config file written Jan 26 00:09:36 volumio sudo[12566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 00:09:36 volumio sudo[12566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:36 volumio volumio[12331]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 00:09:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:36 volumio go-librespot[12568]: go-librespot daemon starting... Jan 26 00:09:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio sudo[12566]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:36 volumio go-librespot[12569]: time="2026-01-26T00:09:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:36 volumio go-librespot[12569]: time="2026-01-26T00:09:36+07:00" level=debug msg="app state loaded" Jan 26 00:09:36 volumio go-librespot[12569]: time="2026-01-26T00:09:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:09:36 volumio volumio[12331]: info: No need to fix Spotify hosts Jan 26 00:09:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:37 volumio volumio[12331]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 00:09:37 volumio volumio[12331]: info: Discovery: Found device Volumio Jan 26 00:09:37 volumio volumio[12331]: info: CoreCommandRouter::volumioGetState Jan 26 00:09:37 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+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]" Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+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]" Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+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]" Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+07:00" level=info msg="zeroconf server listening on port 34047" Jan 26 00:09:37 volumio volumio[12331]: info: Volumio called home Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+07:00" level=debug msg="obtained new client token: AAAVkKmROQLDS3LUfDSBmONCiiLvo5iDOCsPzPaEP3YmB98gk2BfmR3FoR3KeAW59ijlj3D7SiEu6dAjwlB9TpNx0Fj95/AWWyyonx3zwhqMbBQlK633u7RreDWbxIurkRUY3e5FZJr1xpn1l3wVx5btG/vbJ0Y/kxeN7PI5v0SolPheKqBL2FTQMrbX8TASt/g1kcBR/+qyvXTjTCcES1LLWJUieNTYjwmDtpqtcR7//S6U0x0CH0IZV3s=" Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:37 volumio volumio[12331]: info: Starting Shairport Sync Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:37 volumio volumio[12331]: info: Starting Shairport Sync Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+07:00" level=debug msg="completed challenge" Jan 26 00:09:37 volumio volumio[12331]: info: Starting Shairport Sync Jan 26 00:09:37 volumio sudo[12606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 00:09:37 volumio sudo[12608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 00:09:37 volumio sudo[12608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:37 volumio sudo[12606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:37 volumio go-librespot[12569]: time="2026-01-26T00:09:37+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 " Jan 26 00:09:37 volumio volumio[12331]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 00:09:37 volumio volumio[12331]: SPOTIFY: BQBtUDExJxJVfoMOV__edKeFTq2fMSlnA0yt3iq2wPel6bernas61QYJGx6gJ0XK3r_K3sWm53biadZ8II22ca180pLohX4jD3SsFYS7RG5BlZqdmdz0DBw-vVIPiR28LInayGpjtRxAfVdVjxok46uxNtPzTWSY9s2ks_ZUYCG424PAnEUkAvWhM0P5aZJp1CR8YnsxmczbOUj01nk-3bXpheNE76iUuWPzpgjUzjnthVKGFQkFNV0bZI7Xbl9HUSc4BFohCQ0CFxoc2_9MIeCfssrdj1Op0yzS-R2tjyzTTZcjRUavDgGi Jan 26 00:09:37 volumio volumio[12331]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 00:09:37 volumio volumio[12331]: info: New Spotify access token = BQBtUDExJxJVfoMOV__edKeFTq2fMSlnA0yt3iq2wPel6bernas61QYJGx6gJ0XK3r_K3sWm53biadZ8II22ca180pLohX4jD3SsFYS7RG5BlZqdmdz0DBw-vVIPiR28LInayGpjtRxAfVdVjxok46uxNtPzTWSY9s2ks_ZUYCG424PAnEUkAvWhM0P5aZJp1CR8YnsxmczbOUj01nk-3bXpheNE76iUuWPzpgjUzjnthVKGFQkFNV0bZI7Xbl9HUSc4BFohCQ0CFxoc2_9MIeCfssrdj1Op0yzS-R2tjyzTTZcjRUavDgGi Jan 26 00:09:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:37 volumio volumio[12331]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 00:09:37 volumio sudo[12610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 00:09:38 volumio sudo[12610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 00:09:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 00:09:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 00:09:38 volumio systemd[1]: shairport-sync.service: Consumed 2.447s CPU time. Jan 26 00:09:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 00:09:38 volumio sudo[12606]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:38 volumio sudo[12608]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 00:09:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 00:09:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 00:09:38 volumio volumio[12331]: info: Shairport-Sync Started Jan 26 00:09:38 volumio volumio[12331]: Error adding Membership: Error: addMembership EINVAL Jan 26 00:09:38 volumio volumio[12331]: info: Shairport-Sync Started Jan 26 00:09:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 00:09:38 volumio sudo[12610]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:38 volumio volumio[12331]: info: Shairport-Sync Started Jan 26 00:09:38 volumio volumio[12331]: info: CoreCommandRouter::volumioGetState Jan 26 00:09:38 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:38 volumio volumio[12331]: 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"} Jan 26 00:09:38 volumio volumio[12331]: info: Spotify Successfully logged in Jan 26 00:09:38 volumio volumio[12331]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:09:38 volumio volumio[12331]: info: [1769360978974] CoreMusicLibrary::Adding element Spotify Jan 26 00:09:38 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:09:38 volumio volumio[12331]: Cannot find translation for source YouTube Music Jan 26 00:09:38 volumio volumio[12331]: Cannot find translation for source Spotify Jan 26 00:09:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:39 volumio volumio[12331]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 00:09:39 volumio volumio[12331]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 00:09:39 volumio volumio[12331]: info: VolumeController:: Volume=100 Mute =false Jan 26 00:09:39 volumio volumio[12331]: info: CoreCommandRouter::volumioGetState Jan 26 00:09:39 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:39 volumio volumio[12331]: info: CoreStateMachine::pushState Jan 26 00:09:39 volumio volumio[12331]: info: CorePlayQueue::getTrack 0 Jan 26 00:09:39 volumio volumio[12331]: info: CoreCommandRouter::volumioPushState Jan 26 00:09:40 volumio volumio[12331]: info: go-librespot daemon successfully initialized Jan 26 00:09:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 26 00:09:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:41 volumio go-librespot[12648]: go-librespot daemon starting... Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+07:00" level=debug msg="app state loaded" Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:41 volumio mpd[12557]: 2026-01-26T00:09:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 00:09:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 00:09:41 volumio sudo[12526]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:41 volumio sudo[12516]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:41 volumio volumio[12331]: error: MPD error: The expression evaluated to a falsy value: Jan 26 00:09:41 volumio volumio[12331]: assert.ok(self.idling) Jan 26 00:09:41 volumio volumio[12331]: error: The expression evaluated to a falsy value: Jan 26 00:09:41 volumio volumio[12331]: assert.ok(self.idling) Jan 26 00:09:41 volumio volumio[12331]: info: MPD running with PID12557 Jan 26 00:09:41 volumio volumio[12331]: ,establishing connection Jan 26 00:09:41 volumio volumio[12331]: error: updateQueue error: null Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+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]" Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+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]" Jan 26 00:09:41 volumio volumio[12331]: info: Completed starting Core Plugins Jan 26 00:09:41 volumio go-librespot[12649]: time="2026-01-26T00:09:41+07:00" level=info msg="zeroconf server listening on port 44939" Jan 26 00:09:41 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:41 volumio volumio[12331]: info: ----- MyVolumio plugins startup ---- Jan 26 00:09:41 volumio volumio[12331]: info: ------------------------------------------- Jan 26 00:09:41 volumio volumio[12331]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 00:09:41 volumio volumio[12331]: error: updateQueue error: null Jan 26 00:09:42 volumio go-librespot[12649]: time="2026-01-26T00:09:42+07:00" level=debug msg="obtained new client token: AABSSD4J/e0pKSYdcwt5uVgXJzgwyS4LFx5dpvefGPeSE1gMux8e9j295Ju6dZz63igrX2OI3iMknlbS8GyU88xuOoXzENerlQHecjqScuEilcxrOdEB1EYzzPtsu/nCVDXy8jSXG3OEgmxD0sUDMtT/U+Y2JzmV/ihcF+jM7U63b54vg3AVHv1IMvxOzYuZhMX4PcZ41SjdUmNn4SJdLMwgJIHC24uzyaHQx3TocwVQaek5ds/ioVfJWX4=" Jan 26 00:09:42 volumio go-librespot[12649]: time="2026-01-26T00:09:42+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" Jan 26 00:09:42 volumio go-librespot[12649]: time="2026-01-26T00:09:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 00:09:42 volumio go-librespot[12649]: time="2026-01-26T00:09:42+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:42 volumio go-librespot[12649]: time="2026-01-26T00:09:42+07:00" level=debug msg="completed challenge" Jan 26 00:09:42 volumio go-librespot[12649]: time="2026-01-26T00:09:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:43 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:43 volumio volumio[12331]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 26 00:09:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:45 volumio go-librespot[12660]: go-librespot daemon starting... Jan 26 00:09:45 volumio go-librespot[12661]: time="2026-01-26T00:09:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:45 volumio go-librespot[12661]: time="2026-01-26T00:09:45+07:00" level=debug msg="app state loaded" Jan 26 00:09:45 volumio go-librespot[12661]: time="2026-01-26T00:09:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+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]" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+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]" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+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]" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+07:00" level=info msg="zeroconf server listening on port 36005" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+07:00" level=debug msg="obtained new client token: AADUAuxZWF10akP1XdeAi3EcAWMsPGM8hOMOWXP5bg5gIDQ8UtBpizpy7pS4XdIjtpIfgfiWx30K6/RWCOg91Wl9v2tf+Zbp17tfGZOPd6KKDg8QOs2oK8VeJjZ5F5bfqoGEUZ/46EBKTi/zBkmf1BXzKxUc7SWfun3sr7JQltvdFFVCStDoAKU5otnQ/2g0r8dR0jDuXXTQm4R8PWimvByEbQV4tguh4DKWxj7h6Z21U4QQ2+n5JHKfnQ4=" Jan 26 00:09:46 volumio volumio[12331]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+07:00" level=debug msg="completed challenge" Jan 26 00:09:46 volumio go-librespot[12661]: time="2026-01-26T00:09:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:46 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:46 volumio volumio[12331]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:49 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:49 volumio volumio[12331]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 26 00:09:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:50 volumio go-librespot[12670]: go-librespot daemon starting... Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=debug msg="app state loaded" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 00:09:50 volumio volumio[12331]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=info msg="zeroconf server listening on port 38573" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=debug msg="obtained new client token: AAAXjR9iOhnopSx5JYjVSJnoMfrGsbZ6BZUl8x7xkgO0sAOFxH1P+C38ZVVV1cyhG6CNEddbKebF7kxTFFyX7u+oMRlPaPiaCtaQHD0ezNdSwp90ZhU8jWpsb9uPdtXxmdysP3XzSZ29cHGNg5vGDoobFTQExcG6y9utBYXtdobrHQv/e15USTfiyBsUtU0QolPk7O3xvX0TDh3y01fX5YQLDi+sjYdf2TtLxdrA1GlYOsppmKMy6dzlrYA=" Jan 26 00:09:50 volumio go-librespot[12671]: time="2026-01-26T00:09:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:51 volumio go-librespot[12671]: time="2026-01-26T00:09:51+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:51 volumio go-librespot[12671]: time="2026-01-26T00:09:51+07:00" level=debug msg="completed challenge" Jan 26 00:09:51 volumio go-librespot[12671]: time="2026-01-26T00:09:51+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 " Jan 26 00:09:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:52 volumio volumio[12331]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 00:09:52 volumio volumio[12331]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 00:09:52 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:52 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:52 volumio volumio[12331]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 00:09:52 volumio volumio[12331]: info: MyVolumio login type: Token Jan 26 00:09:52 volumio volumio[12331]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 00:09:52 volumio volumio[12331]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 00:09:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:53 volumio volumio[12331]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 00:09:53 volumio volumio[12331]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 00:09:53 volumio volumio[12331]: info: Streaming services startup Jan 26 00:09:53 volumio volumio[12331]: info: Starting Streaming Daemon Jan 26 00:09:53 volumio sudo[12693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 00:09:53 volumio sudo[12693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:53 volumio volumio[12331]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 00:09:53 volumio sudo[12693]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:53 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:53 volumio volumio[12331]: error: Cannot start Volumio Streaming Daemon Jan 26 00:09:53 volumio volumio[12331]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 00:09:53 volumio volumio[12331]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 00:09:53 volumio volumio[12331]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 26 00:09:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:54 volumio go-librespot[12699]: go-librespot daemon starting... Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=debug msg="app state loaded" Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 00:09:54 volumio go-librespot[12700]: time="2026-01-26T00:09:54+07:00" level=info msg="zeroconf server listening on port 42741" Jan 26 00:09:54 volumio volumio[12331]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 00:09:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:55 volumio go-librespot[12700]: time="2026-01-26T00:09:55+07:00" level=debug msg="obtained new client token: AACAvSRsnjXaegX7ffhUJgKYrbtE8bCLqG4PuLWpA4+obSMlKBYhW8a+FHf+ch5hFRf5l5TU49fhjvBKF0iSH6d7isXrzoRYlyRLuvhfpux/NUASShjVrXDXCdPfdj0SqpqSMff1kK8m7Dfxb1oOs23pd+ACxQMF14qU0M80H3oiN930riLoKBb6TpMVrt6z/VssCmtopZO0Rqc0yaMFrqz9F1f7ft+CdOQhwY2Sly4KEZsGCUM7iVmK" Jan 26 00:09:55 volumio go-librespot[12700]: time="2026-01-26T00:09:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:55 volumio go-librespot[12700]: time="2026-01-26T00:09:55+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:55 volumio go-librespot[12700]: time="2026-01-26T00:09:55+07:00" level=debug msg="completed challenge" Jan 26 00:09:55 volumio go-librespot[12700]: time="2026-01-26T00:09:55+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 " Jan 26 00:09:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:09:55 volumio volumio[12331]: info: MyVolumio token set successfully Jan 26 00:09:55 volumio volumio[12331]: info: MYVOLUMIO: Adding device Jan 26 00:09:55 volumio volumio[12331]: info: MYVOLUMIO: Evaluating Server Jan 26 00:09:56 volumio volumio[12331]: info: MyVolumio status changed Jan 26 00:09:56 volumio volumio[12331]: info: Streaming services startup Jan 26 00:09:56 volumio volumio[12331]: info: Starting Streaming Daemon Jan 26 00:09:56 volumio volumio[12331]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 00:09:56 volumio volumio[12331]: info: Removing audio output: Jan 26 00:09:56 volumio volumio[12331]: info: Stoppping Tunnel 1 Jan 26 00:09:56 volumio sudo[12729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 00:09:56 volumio sudo[12729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:56 volumio sudo[12732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 26 00:09:56 volumio sudo[12732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:09:56 volumio sudo[12729]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:56 volumio volumio[12331]: error: Cannot start Volumio Streaming Daemon Jan 26 00:09:56 volumio volumio[12331]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 00:09:56 volumio volumio[12331]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 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. Jan 26 00:09:56 volumio sudo[12732]: pam_unix(sudo:session): session closed for user root Jan 26 00:09:56 volumio volumio[12331]: info: Remote SSH Stopped Jan 26 00:09:56 volumio volumio[12331]: info: Setting Geolocation for MyVolumio to as1 Jan 26 00:09:56 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:56 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:56 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:56 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:09:57 volumio volumio[12331]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:09:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:57 volumio volumio[12331]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 00:09:57 volumio volumio[12331]: info: Updating MyVolumio device info Jan 26 00:09:57 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:57 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:57 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:09:58 volumio volumio[12331]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 00:09:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 26 00:09:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:09:58 volumio go-librespot[12734]: go-librespot daemon starting... Jan 26 00:09:58 volumio go-librespot[12735]: time="2026-01-26T00:09:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:09:58 volumio go-librespot[12735]: time="2026-01-26T00:09:58+07:00" level=debug msg="app state loaded" Jan 26 00:09:58 volumio go-librespot[12735]: time="2026-01-26T00:09:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:09:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:09:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:09:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+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]" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+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]" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+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]" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+07:00" level=info msg="zeroconf server listening on port 40329" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+07:00" level=debug msg="obtained new client token: AABw37qMzvUynh7MyWd0kS/oRRtNwvy5L4Vrkf+NYWut+cDkFHnDFKKaOt5dUF12uBSO/Pqp3KMNTcgKHF0xwuG7sAxYX+545XQlUvYZ1eAPYk86KhKo/mhyAQEXV3i+X67F+0+asmJ+Aoa11aDYvKb96n+VCvXaW0o5+u5SWWK+UKdbIUyVPhJY8BKVZFetfCXWxuJq+BEGS0RPphuJzmemVSdoyo+Cf9H/rtZr52WsKylaSiM+fIADyOk=" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+07:00" level=debug msg="completed keyexchange" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+07:00" level=debug msg="completed challenge" Jan 26 00:09:59 volumio go-librespot[12735]: time="2026-01-26T00:09:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:09:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:09:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:00 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:10:00 volumio volumio[12331]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:10:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:01 volumio volumio[12331]: info: MYVOLUMIO: Adding device Jan 26 00:10:01 volumio volumio[12331]: info: MYVOLUMIO: Evaluating Server Jan 26 00:10:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 26 00:10:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:02 volumio go-librespot[12774]: go-librespot daemon starting... Jan 26 00:10:02 volumio go-librespot[12775]: time="2026-01-26T00:10:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:02 volumio go-librespot[12775]: time="2026-01-26T00:10:02+07:00" level=debug msg="app state loaded" Jan 26 00:10:02 volumio go-librespot[12775]: time="2026-01-26T00:10:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:03 volumio volumio[12331]: info: Initializing connection to go-librespot Websocket Jan 26 00:10:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="new websocket client" Jan 26 00:10:03 volumio volumio[12331]: info: Connection to go-librespot Websocket established Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=info msg="zeroconf server listening on port 43693" Jan 26 00:10:03 volumio volumio[12331]: info: Setting Geolocation for MyVolumio to as1 Jan 26 00:10:03 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:03 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:03 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="obtained new client token: AAA5J/7nvDLr4HyTcuY1l8SG7Uz74/XgAyWxHJxCFbOUNlQcbebNfOwWmUdYhg3ktyqYNK2SIKnmpkwknJmV+M2wkVcaNTCgz0ATLK//jiZecsPIvqgCFCh60fvX0qK9uJpCn03tYgv8BTa3CH4CUdRLJ6WwkDNvv+7+6WsFZRPLi1OoaLIsuo+MYsL6RnBmMhWIdYbqHYvY3PW68gFT2MGVsPvtKpZH9dWG4VcSofqqMfLq9wBpk5SThRA=" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=debug msg="completed challenge" Jan 26 00:10:03 volumio go-librespot[12775]: time="2026-01-26T00:10:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:03 volumio volumio[12331]: info: Connection to go-librespot Websocket closed Jan 26 00:10:04 volumio volumio[12331]: info: Updating MyVolumio device info Jan 26 00:10:04 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:04 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:04 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:04 volumio volumio[12331]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 26 00:10:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:05 volumio volumio[12331]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 26 00:10:05 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:10:05 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:05 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 00:10:05 volumio volumio-remote-updater[628]: Test mode disabled Jan 26 00:10:05 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 26 00:10:05 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 26 00:10:05 volumio volumio[12331]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 26 00:10:06 volumio volumio[12331]: info: Getting Spotify volume Jan 26 00:10:06 volumio volumio[12331]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 00:10:06 volumio volumio[12331]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:10:06 volumio volumio[12331]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 00:10:06 volumio volumio[12331]: errno: -111, Jan 26 00:10:06 volumio volumio[12331]: code: 'ECONNREFUSED', Jan 26 00:10:06 volumio volumio[12331]: syscall: 'connect', Jan 26 00:10:06 volumio volumio[12331]: address: '127.0.0.1', Jan 26 00:10:06 volumio volumio[12331]: port: 9879, Jan 26 00:10:06 volumio volumio[12331]: response: undefined Jan 26 00:10:06 volumio volumio[12331]: } Jan 26 00:10:06 volumio volumio[12331]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 00:10:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 26 00:10:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:07 volumio go-librespot[12799]: go-librespot daemon starting... Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=debug msg="app state loaded" Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:07 volumio sudo[12809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 00:09' Jan 26 00:10:07 volumio sudo[12809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=info msg="zeroconf server listening on port 35231" Jan 26 00:10:07 volumio sudo[12809]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:07 volumio go-librespot[12800]: time="2026-01-26T00:10:07+07:00" level=debug msg="obtained new client token: AAACJRT2QgkHk78URcZMM0O8YFMplLaXiEDY2eTxXdeL5027fa/bRO7/Qf+b8Dl/wPGhMrdBU3X/Jwcz5Gx8g/6pInSzVTfa7x31f+CinDBAZzgL5w7yC02qfT2yALB+n7S4CSD0MS6Jc9MAUE3nLqzvjlidAsjmkJPvJXP1uNJMrmCymc2qoG2upl6MgIf+5bLLw42201bpzya4VySrOfEMmwqOtKme5Snq6ZfXVvcOw2OVvc4YTuGQfns=" Jan 26 00:10:08 volumio go-librespot[12800]: time="2026-01-26T00:10:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:08 volumio go-librespot[12800]: time="2026-01-26T00:10:08+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:08 volumio go-librespot[12800]: time="2026-01-26T00:10:08+07:00" level=debug msg="completed challenge" Jan 26 00:10:08 volumio go-librespot[12800]: time="2026-01-26T00:10:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:09 volumio volumio-remote-updater[628]: [2026-01-26 00:10:09] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 26 00:10:09 volumio volumio-remote-updater[628]: [2026-01-26 00:10:09] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 26 00:10:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 00:10:09 volumio systemd[1]: volumio.service: Consumed 1min 5.921s CPU time. Jan 26 00:10:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 00:10:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 00:10:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6202. Jan 26 00:10:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 00:10:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 00:10:09 volumio systemd[1]: volumio.service: Consumed 1min 5.921s CPU time. Jan 26 00:10:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 00:10:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 00:10:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 26 00:10:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:11 volumio go-librespot[12841]: go-librespot daemon starting... Jan 26 00:10:11 volumio go-librespot[12842]: time="2026-01-26T00:10:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:11 volumio go-librespot[12842]: time="2026-01-26T00:10:11+07:00" level=debug msg="app state loaded" Jan 26 00:10:11 volumio go-librespot[12842]: time="2026-01-26T00:10:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=info msg="zeroconf server listening on port 39239" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="obtained new client token: AACxwqNeJM3wDO97vdPP2QszGv3/133lcJL0aM7AZfVZjEKLZOHYkOoNdQngmbsD6iw5ZSpYT9a21nfJc+FnB3KD+1pn7tgdmp/b+ut/at45hinszPtGfzjE30YesrUBJu7kR5rGwMvEZz101Ism9Di4BnHqstmyx2CO0wsncPCYRdvjvLMZHWzTp6Zy+dS3qJUdmK/OeAd5KSoem+MjagCMeXlzhhnZhAXkAUgxnZj37a4AlcEQLQlKY/M=" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=debug msg="completed challenge" Jan 26 00:10:12 volumio go-librespot[12842]: time="2026-01-26T00:10:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:13 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:13 volumio volumio[12826]: info: ----- Volumio3 ---- Jan 26 00:10:13 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:13 volumio volumio[12826]: info: ----- System startup ---- Jan 26 00:10:13 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:14 volumio volumio-remote-updater[628]: [2026-01-26 00:10:14] [connect] Successful connection Jan 26 00:10:14 volumio volumio[12826]: info: MYVOLUMIO Environment detected Jan 26 00:10:14 volumio volumio[12826]: info: Plugin folders cleanup Jan 26 00:10:14 volumio volumio[12826]: info: Scanning into folder /volumio/app/plugins/ Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category audio_interface Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category miscellanea Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category music_service Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category plugins.json Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category system_controller Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category user_interface Jan 26 00:10:14 volumio volumio[12826]: info: Scanning into folder /data/plugins/ Jan 26 00:10:14 volumio volumio[12826]: info: Scanning category music_service Jan 26 00:10:14 volumio volumio[12826]: info: Plugin folders cleanup completed Jan 26 00:10:14 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:14 volumio volumio[12826]: info: ----- Core plugins startup ---- Jan 26 00:10:14 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:14 volumio volumio[12826]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 00:10:14 volumio volumio[12826]: info: Adding plugin upnp to MyMusic Plugins Jan 26 00:10:14 volumio volumio[12826]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 00:10:14 volumio volumio[12826]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 00:10:14 volumio volumio[12826]: info: Loading plugins from folder /data/plugins/ Jan 26 00:10:14 volumio volumio[12826]: info: Loading plugin "system"... Jan 26 00:10:14 volumio volumio[12826]: info: Loading plugin "appearance"... Jan 26 00:10:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 26 00:10:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:15 volumio go-librespot[12861]: go-librespot daemon starting... Jan 26 00:10:15 volumio go-librespot[12862]: time="2026-01-26T00:10:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:15 volumio go-librespot[12862]: time="2026-01-26T00:10:15+07:00" level=debug msg="app state loaded" Jan 26 00:10:15 volumio go-librespot[12862]: time="2026-01-26T00:10:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:16 volumio go-librespot[12862]: time="2026-01-26T00:10:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:16 volumio go-librespot[12862]: time="2026-01-26T00:10:16+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]" Jan 26 00:10:16 volumio go-librespot[12862]: time="2026-01-26T00:10:16+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]" Jan 26 00:10:16 volumio go-librespot[12862]: time="2026-01-26T00:10:16+07:00" level=info msg="zeroconf server listening on port 45125" Jan 26 00:10:16 volumio volumio[12826]: info: Loading plugin "network"... Jan 26 00:10:16 volumio volumio[12826]: info: Refreshing Cached IP Addresses Jan 26 00:10:16 volumio go-librespot[12862]: time="2026-01-26T00:10:16+07:00" level=debug msg="obtained new client token: AACp16TldXyfdn8PLbmj4mVhMpFlg2m1tgb63emGGaDWmyKEMmVPGh5xhvZ4XrYGb34cQzpb/qp/WcFob+5Ai0xsPNxSpJ9N6xlhsQTQtJN8mbdC8u31ZC7IyUzz1D19IEO1xdf0pGKgLN8qfl0FiKXZBVbNd+OWyX5tXLVQNqBjyOs7XQrpMlqo0Nbm9jf2Gcszy1C6P0m8/GxKHTCy/tshzdjm9xeFbF+aDmI4tz414B1oyYW94s3TB4Y=" Jan 26 00:10:16 volumio sudo[12870]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 00:10:16 volumio sudo[12870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:16 volumio sudo[12872]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 00:10:16 volumio sudo[12872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:16 volumio volumio[12826]: info: Loading plugin "services"... Jan 26 00:10:16 volumio sudo[12870]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:16 volumio sudo[12872]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:16 volumio volumio[12826]: info: Loading plugin "alsa_controller"... Jan 26 00:10:16 volumio sudo[12881]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 00:10:16 volumio sudo[12881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:16 volumio go-librespot[12862]: time="2026-01-26T00:10:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:16 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "wizard"... Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "networkfs"... Jan 26 00:10:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:17 volumio go-librespot[12862]: time="2026-01-26T00:10:17+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:17 volumio go-librespot[12862]: time="2026-01-26T00:10:17+07:00" level=debug msg="completed challenge" Jan 26 00:10:17 volumio volumio[12826]: info: Starting Udev Watcher for removable devices Jan 26 00:10:17 volumio volumio[12826]: info: Ignoring mount for partition: boot Jan 26 00:10:17 volumio volumio[12826]: info: Ignoring mount for partition: volumio Jan 26 00:10:17 volumio volumio[12826]: info: Ignoring mount for partition: volumio_data Jan 26 00:10:17 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "volumio_command_line_client"... Jan 26 00:10:17 volumio go-librespot[12862]: time="2026-01-26T00:10:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "upnp"... Jan 26 00:10:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:17 volumio volumio[12826]: info: [1769361017170] Starting Upmpd Daemon Jan 26 00:10:17 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "my_music"... Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "mpd"... Jan 26 00:10:17 volumio volumio[12826]: info: Loading plugin "upnp_browser"... Jan 26 00:10:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:19 volumio sudo[12881]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 26 00:10:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:20 volumio go-librespot[12906]: go-librespot daemon starting... Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=debug msg="app state loaded" Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:20 volumio volumio[12826]: info: Starting UPNP Browser Jan 26 00:10:20 volumio volumio[12826]: info: Loading plugin "alarm-clock"... Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:10:20 volumio go-librespot[12907]: time="2026-01-26T00:10:20+07:00" level=info msg="zeroconf server listening on port 37499" Jan 26 00:10:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:21 volumio go-librespot[12907]: time="2026-01-26T00:10:21+07:00" level=debug msg="obtained new client token: AADxPMOz6RGWlm+8qKCcKHtPKFK9ucrm5cqHRlTBs0moQp5//R5dqRIrMXG/XKx8drn6TxE4Ix3VPhE+R5EXyGxJrmZ2wK/M3kDbXoI9jILIyyPBRG8yzEjg+Lf+en3DUBVwOQjItgjkM6jIr+Nq0UMqcJib28r3xPOBmKhOxxyrxuHBnsajuZc+yBtTDadYnaghGWukXwKaXDyz+810AiDzl4kJYifVgtstmIlAdftTX7egA50oRZlD" Jan 26 00:10:21 volumio volumio[12826]: info: Loading plugin "airplay_emulation"... Jan 26 00:10:21 volumio volumio[12826]: info: Starting Shairport Sync Jan 26 00:10:21 volumio volumio[12826]: info: Loading plugin "last_100"... Jan 26 00:10:21 volumio volumio[12826]: info: Loading plugin "webradio"... Jan 26 00:10:21 volumio go-librespot[12907]: time="2026-01-26T00:10:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:21 volumio go-librespot[12907]: time="2026-01-26T00:10:21+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:21 volumio go-librespot[12907]: time="2026-01-26T00:10:21+07:00" level=debug msg="completed challenge" Jan 26 00:10:21 volumio volumio[12826]: info: Loading plugin "i2s_dacs"... Jan 26 00:10:21 volumio volumio[12826]: info: Loading plugin "volumiodiscovery"... Jan 26 00:10:21 volumio go-librespot[12907]: time="2026-01-26T00:10:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:21 volumio volumio[12826]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 00:10:21 volumio volumio[12826]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:10:21 volumio volumio[12826]: *** WARNING *** For more information see Jan 26 00:10:21 volumio volumio[12826]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 00:10:21 volumio volumio[12826]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:10:21 volumio volumio[12826]: *** WARNING *** For more information see Jan 26 00:10:21 volumio node[12826]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 00:10:21 volumio node[12826]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:10:21 volumio node[12826]: *** WARNING *** For more information see Jan 26 00:10:21 volumio node[12826]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 00:10:21 volumio node[12826]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 00:10:21 volumio node[12826]: *** WARNING *** For more information see Jan 26 00:10:21 volumio volumio[12826]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 00:10:21 volumio volumio[12826]: info: Discovery: Started advertising with name: Volumio Jan 26 00:10:21 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 00:10:21 volumio volumio[12826]: info: Loading plugin "spop"... Jan 26 00:10:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:23 volumio volumio[12826]: info: Loading plugin "ytcr"... Jan 26 00:10:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 26 00:10:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:24 volumio go-librespot[12917]: go-librespot daemon starting... Jan 26 00:10:24 volumio go-librespot[12918]: time="2026-01-26T00:10:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:24 volumio go-librespot[12918]: time="2026-01-26T00:10:24+07:00" level=debug msg="app state loaded" Jan 26 00:10:24 volumio go-librespot[12918]: time="2026-01-26T00:10:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+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]" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+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]" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=info msg="zeroconf server listening on port 43365" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=debug msg="obtained new client token: AADeE0PWiwcnlOAuZV0KdDoYW5UV1wNuvFsksSEXjMkEoADZp1qBnImmeJ64AQ4uL65aq9Yt2X4MCuqRyJUE3GlPVMNlB0HUAdMVzeqBKGnLRu2g4eHth9d+sBmlbIxr4FmpbS8+oOPqMc/gsWVyTwETQdjOjnR79JVo2POGHfK/mEzdsMGmtKSlU+kw/ylkZaDBs1W8jGu7j7tulAY0+fBl5o1t8Ih1tUw+4B1AOaqyEUbNfg7aeYiNtFs=" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=debug msg="completed challenge" Jan 26 00:10:25 volumio go-librespot[12918]: time="2026-01-26T00:10:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:25 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 26 00:10:26 volumio volumio[12826]: info: Loading plugin "ytmusic"... Jan 26 00:10:26 volumio volumio-remote-updater[628]: [2026-01-26 00:10:26] [connect] Successful connection Jan 26 00:10:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "outputs"... Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "albumart"... Jan 26 00:10:27 volumio volumio[12826]: info: Plugin example_plugin is not enabled Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "inputs"... Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "updater_comm"... Jan 26 00:10:27 volumio volumio[12826]: info: Plugin mpdemulation is not enabled Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "rest_api"... Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "websocket"... Jan 26 00:10:27 volumio volumio[12826]: info: Starting Socket.io Server version 1.7.4 Jan 26 00:10:27 volumio volumio[12826]: info: Loading plugin "RoonBridge"... Jan 26 00:10:28 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 26 00:10:28 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 26 00:10:28 volumio systemd[1]: setdatetime-helper.service: Consumed 1.959s CPU time. Jan 26 00:10:28 volumio volumio[12826]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 00:10:28 volumio volumio[12826]: info: Loading i18n strings for locale en Jan 26 00:10:28 volumio volumio[12826]: Updating browse sources language Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:10:28 volumio volumio[12960]: Forking 3 albumart workers Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::initPlayerControls Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 00:10:28 volumio volumio[12826]: Express server listening on port 3000 Jan 26 00:10:28 volumio volumio[12826]: [Metrics] WebUI: 16s 428.86ms Jan 26 00:10:28 volumio volumio[12826]: info: CoreStateMachine::resetVolumioState Jan 26 00:10:28 volumio volumio[12826]: info: CoreStateMachine::getcurrentVolume Jan 26 00:10:28 volumio volumio[12826]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 00:10:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 26 00:10:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:28 volumio go-librespot[13005]: go-librespot daemon starting... Jan 26 00:10:28 volumio go-librespot[13009]: time="2026-01-26T00:10:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:28 volumio go-librespot[13009]: time="2026-01-26T00:10:28+07:00" level=debug msg="app state loaded" Jan 26 00:10:28 volumio go-librespot[13009]: time="2026-01-26T00:10:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:28 volumio sudo[13010]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 00:10:28 volumio sudo[13010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:28 volumio sudo[13010]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:28 volumio volumio[12826]: info: Volumio Network Manager: Network status updated: 1 Jan 26 00:10:29 volumio sudo[13019]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 00:10:29 volumio sudo[13019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:29 volumio sudo[13019]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:29 volumio volumio[12826]: info: VolumeController:: Volume=100 Mute =false Jan 26 00:10:29 volumio volumio[12826]: info: CoreStateMachine::pushState Jan 26 00:10:29 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::volumioPushState Jan 26 00:10:29 volumio volumio[12826]: info: CoreStateMachine::updateTrackBlock Jan 26 00:10:29 volumio volumio[12826]: info: CorePlayQueue::getTrackBlock Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 00:10:29 volumio go-librespot[13009]: time="2026-01-26T00:10:29+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]" Jan 26 00:10:29 volumio go-librespot[13009]: time="2026-01-26T00:10:29+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]" Jan 26 00:10:29 volumio go-librespot[13009]: time="2026-01-26T00:10:29+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]" Jan 26 00:10:29 volumio go-librespot[13009]: time="2026-01-26T00:10:29+07:00" level=info msg="zeroconf server listening on port 37649" Jan 26 00:10:29 volumio volumio-remote-updater[628]: [2026-01-26 00:10:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769361026 101 Jan 26 00:10:29 volumio volumio[12826]: 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 Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:29 volumio volumio[12826]: info: Reloading queue from file Jan 26 00:10:29 volumio volumio[12826]: info: CoreStateMachine::setRepeat null single undefined Jan 26 00:10:29 volumio go-librespot[13009]: time="2026-01-26T00:10:29+07:00" level=debug msg="obtained new client token: AABuREQbkNPx/86/IEfK7gBJliHrErnR+nUK00fiJl9ahZO2OWkbXlR8CAmgS5q6+/2nTNrFTnwvmR+seJwTyd+yM72AS+Uw8MLknnXU/hxPdZC4JV4isyeY+dKjj+S696UCprs2rDTX6xJO+MqmPLlcZDj713CUG61zIbHIHBkQCdLazX6PcPTOcrG86/d5Ct2CNNQkrw5UuwZ0ROK7CoovGYqDwTFIbQGjZMwpWNNwOJCf7Y3vlB4olKs=" Jan 26 00:10:29 volumio volumio[12826]: info: CoreStateMachine::pushState Jan 26 00:10:29 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::volumioPushState Jan 26 00:10:29 volumio volumio[12826]: info: CoreStateMachine::setRandom null Jan 26 00:10:29 volumio volumio[12826]: info: CoreStateMachine::pushState Jan 26 00:10:29 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:29 volumio volumio[12826]: info: CoreCommandRouter::volumioPushState Jan 26 00:10:29 volumio volumio[12826]: info: Setting Device type: Raspberry PI Jan 26 00:10:29 volumio go-librespot[13009]: time="2026-01-26T00:10:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:29 volumio volumio[12826]: info: Completed loading Core Plugins Jan 26 00:10:29 volumio volumio[12826]: info: Preparing to generate the ALSA configuration file Jan 26 00:10:30 volumio go-librespot[13009]: time="2026-01-26T00:10:30+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:30 volumio go-librespot[13009]: time="2026-01-26T00:10:30+07:00" level=debug msg="completed challenge" Jan 26 00:10:30 volumio volumio[12826]: info: VolumeController:: Volume=100 Mute =false Jan 26 00:10:30 volumio volumio[12826]: info: CoreStateMachine::pushState Jan 26 00:10:30 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::volumioPushState Jan 26 00:10:30 volumio go-librespot[13009]: time="2026-01-26T00:10:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:30 volumio volumio[12826]: info: Asound.conf file unchanged, so no further update is needed Jan 26 00:10:30 volumio volumio[12826]: info: Output device has changed, restarting MPD Jan 26 00:10:30 volumio volumio[12826]: info: Output device has changed, restarting Shairport Sync Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:30 volumio sudo[13033]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 00:10:30 volumio sudo[13033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:30 volumio sudo[13035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 00:10:30 volumio sudo[13038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 00:10:30 volumio sudo[13035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:30 volumio sudo[13038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:30 volumio sudo[13035]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:30 volumio volumio[12826]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 00:10:30 volumio volumio[12826]: info: ___________ START PLUGINS ___________ Jan 26 00:10:30 volumio sudo[13033]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:30 volumio volumio[12826]: info: ControllerMpd::onStart: Initializing MPD Jan 26 00:10:30 volumio volumio[12826]: info: Creating MPD Configuration file Jan 26 00:10:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:10:30 volumio volumio[12826]: info: [1769361030500] CoreMusicLibrary::Adding element Media Servers Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:10:30 volumio sudo[13046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 00:10:30 volumio sudo[13046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:30 volumio sudo[13046]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:30 volumio volumio[12826]: info: UPNP Browser: Client initialized successfully Jan 26 00:10:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 00:10:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 00:10:30 volumio systemd[1]: mpd.service: Consumed 7.331s CPU time. Jan 26 00:10:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 00:10:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 00:10:30 volumio sudo[13048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 00:10:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 00:10:30 volumio sudo[13048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 00:10:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 00:10:30 volumio volumio[12826]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 00:10:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 00:10:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 00:10:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 00:10:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 00:10:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 00:10:30 volumio volumio[12826]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 00:10:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:10:30 volumio volumio[12826]: info: [1769361030830] CoreMusicLibrary::Adding element Last_100 Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:10:30 volumio volumio[12826]: info: [1769361030858] CoreMusicLibrary::Adding element Webradio Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:10:30 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:10:30 volumio volumio[12826]: info: Initializing BBC Radios Jan 26 00:10:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:31 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 00:10:31 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:31 volumio volumio[12826]: info: Creating Spotify config file Jan 26 00:10:31 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:31 volumio sudo[13062]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 00:10:31 volumio sudo[13062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 00:10:31 volumio sudo[13062]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:31 volumio volumio[12975]: Starting albumart workers Jan 26 00:10:31 volumio volumio[12974]: Starting albumart workers Jan 26 00:10:32 volumio volumio[12976]: Starting albumart workers Jan 26 00:10:32 volumio volumio[12826]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:10:32 volumio volumio[12826]: info: [1769361032103] CoreMusicLibrary::Adding element YouTube Music Jan 26 00:10:32 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:10:32 volumio volumio[12826]: Cannot find translation for source YouTube Music Jan 26 00:10:32 volumio volumio[12826]: info: Volumio Calling Home Jan 26 00:10:32 volumio sudo[13079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 00:10:32 volumio sudo[13079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:32 volumio sudo[13079]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:32 volumio volumio[12826]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 00:10:32 volumio volumio[12826]: info: Discovery: Found device Volumio Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::volumioGetState Jan 26 00:10:33 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:33 volumio volumio[12826]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 00:10:33 volumio volumio[12826]: info: Discovery: Found device Volumio Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::volumioGetState Jan 26 00:10:33 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:33 volumio volumio[12826]: info: MPD Permissions set Jan 26 00:10:33 volumio volumio[12826]: info: MPD Permissions set Jan 26 00:10:33 volumio volumio[12826]: info: Upmpdcli Daemon Started Jan 26 00:10:33 volumio volumio[12826]: info: Spotify config file written Jan 26 00:10:33 volumio sudo[13085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 00:10:33 volumio sudo[13085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 26 00:10:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:33 volumio volumio[12826]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 00:10:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:33 volumio go-librespot[13087]: go-librespot daemon starting... Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 00:10:33 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 00:10:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:33 volumio go-librespot[13100]: go-librespot daemon starting... Jan 26 00:10:33 volumio sudo[13085]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:33 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 00:10:33 volumio go-librespot[13103]: time="2026-01-26T00:10:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:33 volumio go-librespot[13103]: time="2026-01-26T00:10:33+07:00" level=debug msg="app state loaded" Jan 26 00:10:33 volumio go-librespot[13103]: time="2026-01-26T00:10:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:33 volumio volumio[12826]: info: No need to fix Spotify hosts Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=info msg="zeroconf server listening on port 37407" Jan 26 00:10:34 volumio volumio[12826]: info: Volumio called home Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="obtained new client token: AADttzXeeCNMowvyoIepqcXQ3PageYf9FRzpFMa1eSWLzbwKXi86p9S7F8OPoj2UzAevMKcsoBXZxxKcZXSbEhFADHSFTyh9IqlAd7upzXJAAIhIt0nyJX90+iZCOJkltOwsb5s38UwjitScNTQdkpR3Ljv/FTYKOfbZ6PSqruejVThLXeJI99CubUFSvmwZeQkwu4eaQRlZmLVjGTt93LqA9Cs9TaZOQesVvXZsrrMss/oQCDv0QGTqcDI=" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=debug msg="completed challenge" Jan 26 00:10:34 volumio go-librespot[13103]: time="2026-01-26T00:10:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:35 volumio volumio[12826]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 00:10:35 volumio volumio[12826]: SPOTIFY: BQB-dinizEothDzuzBvPyV99QsYa7cXc-JGuVeP19iPDrRjUoCHAeLFWubEDgGBe0g-yCqLg_g-pxhpCQL4oIoQB6JPpF3I5fcaylRhnlD0-pN0cK6wQCavDBbmskXdjtPbHn5zaJCxW-nHk9ahFO9jM_-ATDeZ38vdpuBM-K8Q6gh8rHn1Yg31mVsZGjTKCeYnwQqvV0UjM5iOtOT2YhfimAxJ5wb2Vfp8QlFP8JEjGTHfQeR0O-JnVsVvEHJe6i_vdAwn_gGaRy3SCWuI-mZskkHxr1svGlgGW63hXGWTQ6Az-GrKqtlzT Jan 26 00:10:35 volumio volumio[12826]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 00:10:35 volumio volumio[12826]: info: New Spotify access token = BQB-dinizEothDzuzBvPyV99QsYa7cXc-JGuVeP19iPDrRjUoCHAeLFWubEDgGBe0g-yCqLg_g-pxhpCQL4oIoQB6JPpF3I5fcaylRhnlD0-pN0cK6wQCavDBbmskXdjtPbHn5zaJCxW-nHk9ahFO9jM_-ATDeZ38vdpuBM-K8Q6gh8rHn1Yg31mVsZGjTKCeYnwQqvV0UjM5iOtOT2YhfimAxJ5wb2Vfp8QlFP8JEjGTHfQeR0O-JnVsVvEHJe6i_vdAwn_gGaRy3SCWuI-mZskkHxr1svGlgGW63hXGWTQ6Az-GrKqtlzT Jan 26 00:10:35 volumio volumio[12826]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 00:10:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:35 volumio volumio[12826]: info: Starting Shairport Sync Jan 26 00:10:35 volumio volumio[12826]: info: Starting Shairport Sync Jan 26 00:10:35 volumio volumio[12826]: info: Starting Shairport Sync Jan 26 00:10:35 volumio sudo[13134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 00:10:35 volumio sudo[13134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:35 volumio sudo[13139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 00:10:35 volumio sudo[13139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:35 volumio sudo[13136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 00:10:35 volumio sudo[13136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 00:10:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 00:10:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 00:10:35 volumio systemd[1]: shairport-sync.service: Consumed 2.542s CPU time. Jan 26 00:10:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 00:10:35 volumio sudo[13134]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:35 volumio sudo[13136]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:35 volumio sudo[13139]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:35 volumio volumio[12826]: info: Shairport-Sync Started Jan 26 00:10:35 volumio volumio[12826]: Error adding Membership: Error: addMembership EINVAL Jan 26 00:10:35 volumio volumio[12826]: info: CoreCommandRouter::volumioGetState Jan 26 00:10:35 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:35 volumio volumio[12826]: info: Shairport-Sync Started Jan 26 00:10:35 volumio volumio[12826]: info: Shairport-Sync Started Jan 26 00:10:35 volumio volumio[12826]: 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"} Jan 26 00:10:35 volumio volumio[12826]: info: Spotify Successfully logged in Jan 26 00:10:35 volumio volumio[12826]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 00:10:35 volumio volumio[12826]: info: [1769361035862] CoreMusicLibrary::Adding element Spotify Jan 26 00:10:35 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 00:10:35 volumio volumio[12826]: Cannot find translation for source YouTube Music Jan 26 00:10:35 volumio volumio[12826]: Cannot find translation for source Spotify Jan 26 00:10:36 volumio volumio[12826]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 00:10:36 volumio volumio[12826]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 00:10:36 volumio volumio[12826]: info: VolumeController:: Volume=100 Mute =false Jan 26 00:10:36 volumio volumio[12826]: info: CoreCommandRouter::volumioGetState Jan 26 00:10:36 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:36 volumio volumio[12826]: info: CoreStateMachine::pushState Jan 26 00:10:36 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:36 volumio volumio[12826]: info: CoreCommandRouter::volumioPushState Jan 26 00:10:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 00:10:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:38 volumio volumio[12826]: info: go-librespot daemon successfully initialized Jan 26 00:10:38 volumio go-librespot[13174]: go-librespot daemon starting... Jan 26 00:10:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+07:00" level=debug msg="app state loaded" Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:38 volumio mpd[13077]: 2026-01-26T00:10:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 00:10:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 00:10:38 volumio sudo[13038]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:38 volumio sudo[13048]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+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]" Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+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]" Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+07:00" level=info msg="zeroconf server listening on port 42457" Jan 26 00:10:38 volumio volumio[12826]: error: MPD error: The expression evaluated to a falsy value: Jan 26 00:10:38 volumio volumio[12826]: assert.ok(self.idling) Jan 26 00:10:38 volumio volumio[12826]: error: The expression evaluated to a falsy value: Jan 26 00:10:38 volumio volumio[12826]: assert.ok(self.idling) Jan 26 00:10:38 volumio volumio[12826]: error: updateQueue error: null Jan 26 00:10:38 volumio volumio[12826]: info: MPD running with PID13077 Jan 26 00:10:38 volumio volumio[12826]: ,establishing connection Jan 26 00:10:38 volumio go-librespot[13175]: time="2026-01-26T00:10:38+07:00" level=debug msg="obtained new client token: AACuoSYVGgEAfjzmOvxIuw+pbONY6ACW2809+Il+VyCNkuYW8JSC7qvDi/ITNebBeaZeb2fFqSqA11twpww4XpLXRZGJbVCGlwb3RT/OZg5VM+G1jL9QMFn9l5iQxBz8+0l7zGJatoIrF6CRqspMPNYaR/ypc3ksTksM4WXDKgRK92UJbYwly+0aPzTt1zOPuaKTJyng/qwXgOYm4hLuDtjGLhB/ioujPx8k6ZGBKra7YZ5/UTa/8Scs5jA=" Jan 26 00:10:39 volumio volumio[12826]: info: Completed starting Core Plugins Jan 26 00:10:39 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:39 volumio volumio[12826]: info: ----- MyVolumio plugins startup ---- Jan 26 00:10:39 volumio volumio[12826]: info: ------------------------------------------- Jan 26 00:10:39 volumio volumio[12826]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 00:10:39 volumio volumio[12826]: error: updateQueue error: null Jan 26 00:10:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:39 volumio go-librespot[13175]: time="2026-01-26T00:10:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:39 volumio go-librespot[13175]: time="2026-01-26T00:10:39+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:39 volumio go-librespot[13175]: time="2026-01-26T00:10:39+07:00" level=debug msg="completed challenge" Jan 26 00:10:39 volumio go-librespot[13175]: time="2026-01-26T00:10: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 " Jan 26 00:10:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:41 volumio volumio[12826]: info: Initializing connection to go-librespot Websocket Jan 26 00:10:41 volumio volumio[12826]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:10:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 00:10:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:42 volumio go-librespot[13188]: go-librespot daemon starting... Jan 26 00:10:42 volumio go-librespot[13189]: time="2026-01-26T00:10:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:42 volumio go-librespot[13189]: time="2026-01-26T00:10:42+07:00" level=debug msg="app state loaded" Jan 26 00:10:42 volumio go-librespot[13189]: time="2026-01-26T00:10:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+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]" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+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]" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+07:00" level=info msg="zeroconf server listening on port 43263" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+07:00" level=debug msg="obtained new client token: AADL7StIysArfaAyxdwPGnuzp8FEntS1nKaS1QWsA7qL/4peDbOrLMlXtFF8/LTYj/RXxkzFYDQ4/7/HfoSUIrmu94T7dvWA065LMvB0nLYnkiX1Dsv8WEhSXq5B7atbWxPBk03lvBONPuMl4l7uWn70lAuLh/byBrLLyoBmoqeZv8QuwLtUbsejXCEK0Mkf6sgiuWeBttex+a+1opQV81qTa5I5beVm3R4OxMxmnniMdkY9ybPjjiZzw/4=" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+07:00" level=debug msg="completed challenge" Jan 26 00:10:43 volumio go-librespot[13189]: time="2026-01-26T00:10:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 00:10:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:43 volumio volumio[12826]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 00:10:44 volumio volumio[12826]: info: Initializing connection to go-librespot Websocket Jan 26 00:10:44 volumio volumio[12826]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 00:10:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 00:10:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:46 volumio go-librespot[13198]: go-librespot daemon starting... Jan 26 00:10:46 volumio go-librespot[13199]: time="2026-01-26T00:10:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:46 volumio go-librespot[13199]: time="2026-01-26T00:10:46+07:00" level=debug msg="app state loaded" Jan 26 00:10:46 volumio go-librespot[13199]: time="2026-01-26T00:10:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:47 volumio volumio[12826]: info: Initializing connection to go-librespot Websocket Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=debug msg="new websocket client" Jan 26 00:10:47 volumio volumio[12826]: info: Connection to go-librespot Websocket established Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+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]" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+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]" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=info msg="zeroconf server listening on port 41605" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=debug msg="obtained new client token: AABHmMH1aLUZdIiZqOWi/69xJTClf84D+NE9rz4nYsBEb14PLaRr1sM2/1IFiTnHpO++3dM7FlPhNs4YxtOhaxOb254xv400QIMKC0ICSWPBivuaPlUi1z5htDF0vQDXUc2SY9sswHrw1GmKiIlayN+17AeLqTGeDr1Ad4XIVVKGUPLUNux3ebsJO6k8J2KjC/hEEV2rGoiKN6D4psw6qqcyjZz8+xykpTbCCgjNYHXE76OruFWYvCVidOk=" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 00:10:47 volumio volumio[12826]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:47 volumio go-librespot[13199]: time="2026-01-26T00:10:47+07:00" level=debug msg="completed challenge" Jan 26 00:10:48 volumio go-librespot[13199]: time="2026-01-26T00:10: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 " Jan 26 00:10:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:49 volumio volumio[12826]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 00:10:49 volumio volumio[12826]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 00:10:49 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:49 volumio volumio[12826]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 00:10:49 volumio volumio[12826]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 00:10:49 volumio volumio[12826]: info: MyVolumio login type: Token Jan 26 00:10:49 volumio volumio[12826]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 00:10:49 volumio volumio[12826]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 00:10:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:51 volumio volumio[12826]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 00:10:51 volumio volumio[12826]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 00:10:51 volumio volumio[12826]: info: Streaming services startup Jan 26 00:10:51 volumio volumio[12826]: info: Starting Streaming Daemon Jan 26 00:10:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 00:10:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:51 volumio sudo[13225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 00:10:51 volumio sudo[13225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 00:10:51 volumio volumio[12826]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 00:10:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 00:10:51 volumio go-librespot[13224]: go-librespot daemon starting... Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 00:10:51 volumio sudo[13225]: pam_unix(sudo:session): session closed for user root Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=debug msg="app state loaded" Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 00:10:51 volumio volumio[12826]: info: Getting Spotify volume Jan 26 00:10:51 volumio volumio[12826]: info: Connection to go-librespot Websocket closed Jan 26 00:10:51 volumio volumio[12826]: error: Cannot start Volumio Streaming Daemon Jan 26 00:10:51 volumio volumio[12826]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 00:10:51 volumio volumio[12826]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 00:10:51 volumio volumio[12826]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 00:10:51 volumio volumio[12826]: info: CoreCommandRouter::volumioGetState Jan 26 00:10:51 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:51 volumio volumio[12826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 00:10:51 volumio volumio[12826]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 00:10:51 volumio volumio[12826]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 00:10:51 volumio volumio[12826]: info: Aligning Spotify Volume to Volumio Volume Jan 26 00:10:51 volumio volumio[12826]: info: CoreCommandRouter::volumioGetState Jan 26 00:10:51 volumio volumio[12826]: info: CorePlayQueue::getTrack 0 Jan 26 00:10:51 volumio volumio[12826]: info: Setting Spotify Volume from Volumio: 100 Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 00:10:51 volumio go-librespot[13231]: time="2026-01-26T00:10:51+07:00" level=info msg="zeroconf server listening on port 45337" Jan 26 00:10:52 volumio go-librespot[13231]: time="2026-01-26T00:10:52+07:00" level=debug msg="obtained new client token: AACCjqhAiJzR1XTi/AiHeqZNXgXB9Qd1FpIMomxhu98Rconve9Vhu4UkUzotQdlRfsT8R7FU4rcUG+s4T8RZtt6hCaW87QlEIkApbKH+KzpBFgG2B9iwl5YZiVukZEJW+hhmFizAP0yq9a8DtlRLTBVR31LULQZYWYdjKhu+yy1gScxOAoV6O0MYrSzcBO3Nf2qg43d0UZaONfznO90vW+pMJg07RhrEWN4HPhQPb6/pIBeaiZwqzmLR" Jan 26 00:10:52 volumio go-librespot[13231]: time="2026-01-26T00:10:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 00:10:52 volumio go-librespot[13231]: time="2026-01-26T00:10:52+07:00" level=debug msg="completed keyexchange" Jan 26 00:10:52 volumio go-librespot[13231]: time="2026-01-26T00:10:52+07:00" level=debug msg="completed challenge" Jan 26 00:10:52 volumio go-librespot[13231]: time="2026-01-26T00:10: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 " Jan 26 00:10:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 00:10:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 00:10:52 volumio volumio[12826]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 00:10:52 volumio volumio[12826]: Error: socket hang up Jan 26 00:10:52 volumio volumio[12826]: at connResetException (node:internal/errors:720:14) Jan 26 00:10:52 volumio volumio[12826]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 00:10:52 volumio volumio[12826]: at Socket.emit (node:events:526:35) Jan 26 00:10:52 volumio volumio[12826]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 00:10:52 volumio volumio[12826]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 00:10:52 volumio volumio[12826]: code: 'ECONNRESET', Jan 26 00:10:52 volumio volumio[12826]: response: undefined Jan 26 00:10:52 volumio volumio[12826]: } Jan 26 00:10:52 volumio volumio[12826]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 00:10:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 00:10:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 00:10:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 00:10:53 volumio sudo[13254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 00:09' Jan 26 00:10:53 volumio sudo[13254]: 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"