Jan 25 22:05:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:00 volumio volumio[11731]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 22:05:00 volumio volumio[11731]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:05:00 volumio volumio[11731]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:05:00 volumio volumio[11731]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:00 volumio volumio[11731]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:00 volumio volumio[11731]: info: CoreStateMachine::pushState Jan 25 22:05:00 volumio volumio[11731]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:00 volumio volumio[11731]: info: CoreCommandRouter::volumioPushState Jan 25 22:05:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 22:05:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:01 volumio go-librespot[12039]: go-librespot daemon starting... Jan 25 22:05:01 volumio go-librespot[12046]: time="2026-01-25T22:05:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:01 volumio go-librespot[12046]: time="2026-01-25T22:05:01+07:00" level=debug msg="app state loaded" Jan 25 22:05:01 volumio go-librespot[12046]: time="2026-01-25T22:05:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:01 volumio volumio[11731]: info: go-librespot daemon successfully initialized Jan 25 22:05:01 volumio mpd[11955]: 2026-01-25T22:05:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 22:05:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 22:05:01 volumio sudo[11908]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:01 volumio sudo[11919]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=info msg="zeroconf server listening on port 32893" Jan 25 22:05:02 volumio volumio[11731]: error: MPD error: The expression evaluated to a falsy value: Jan 25 22:05:02 volumio volumio[11731]: assert.ok(self.idling) Jan 25 22:05:02 volumio volumio[11731]: error: The expression evaluated to a falsy value: Jan 25 22:05:02 volumio volumio[11731]: assert.ok(self.idling) Jan 25 22:05:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:02 volumio volumio[11731]: info: MPD running with PID11955 Jan 25 22:05:02 volumio volumio[11731]: ,establishing connection Jan 25 22:05:02 volumio volumio[11731]: error: updateQueue error: null Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="obtained new client token: AADHiS0ndeGUm/ulmYA1lRwfd3YuWQ64yHW5cCg/dJPGllQiof3b5JdpukairnbB66cGGttHRejcR0WtCyVh2/jwZrSEJA+0mTguXtYm+cpw1P0pqxA/xzddhxIDSEFRoU85A9zByyVjP2+8UJbTpWnnQEHNcG3mb/PBwz26IGD58xWGx6BB22eOGMnuYQZuAFYX0gYhupTdUb9feJzWBpfgMNwFEnyZvtIJK+RiGyZUXupyIQf4muX6" Jan 25 22:05:02 volumio volumio[11731]: info: Completed starting Core Plugins Jan 25 22:05:02 volumio volumio[11731]: info: ------------------------------------------- Jan 25 22:05:02 volumio volumio[11731]: info: ----- MyVolumio plugins startup ---- Jan 25 22:05:02 volumio volumio[11731]: info: ------------------------------------------- Jan 25 22:05:02 volumio volumio[11731]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 22:05:02 volumio volumio[11731]: error: updateQueue error: null Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=debug msg="completed challenge" Jan 25 22:05:02 volumio go-librespot[12046]: time="2026-01-25T22:05:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:05:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:04 volumio volumio[11731]: info: Initializing connection to go-librespot Websocket Jan 25 22:05:04 volumio volumio[11731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:05:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 22:05:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:05 volumio go-librespot[12057]: go-librespot daemon starting... Jan 25 22:05:05 volumio go-librespot[12058]: time="2026-01-25T22:05:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:05 volumio go-librespot[12058]: time="2026-01-25T22:05:05+07:00" level=debug msg="app state loaded" Jan 25 22:05:05 volumio go-librespot[12058]: time="2026-01-25T22:05:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+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 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+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 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=info msg="zeroconf server listening on port 46599" Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=debug msg="obtained new client token: AAA7iNwlpUGL2o+c3v8MhgASysUBSFAbDC2u66l02C0/GXfDv8u/ScyRC0E+rcbPFCyR6rSSilAN5TZTZZj0t0w0U12AmObzntl16NGUGHn5YUK5A5xPViiV7lQviIxLMawpB+e80cZGMHyvzfq5ZIPNYeVU7JQMIzlWUb7+TQVkn1mzBBqzNg89noL/3ba1KuTIj5F97WdQOoLIz2O2URcUYLy3B51NE0/J5qhK10zn88/WSI92kdRMWcM=" Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=debug msg="completed challenge" Jan 25 22:05:06 volumio go-librespot[12058]: time="2026-01-25T22:05:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:05:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:07 volumio volumio[11731]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 22:05:07 volumio volumio[11731]: info: Initializing connection to go-librespot Websocket Jan 25 22:05:07 volumio volumio[11731]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:05:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 22:05:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:10 volumio go-librespot[12065]: go-librespot daemon starting... Jan 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+07:00" level=debug msg="app state loaded" Jan 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:10 volumio volumio[11731]: info: Initializing connection to go-librespot Websocket Jan 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+07:00" level=debug msg="new websocket client" Jan 25 22:05:10 volumio volumio[11731]: info: Connection to go-librespot Websocket established Jan 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+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 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+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 25 22:05:10 volumio go-librespot[12066]: time="2026-01-25T22:05:10+07:00" level=info msg="zeroconf server listening on port 34039" Jan 25 22:05:11 volumio go-librespot[12066]: time="2026-01-25T22:05:11+07:00" level=debug msg="obtained new client token: AACLboGswJ0nKsakllzTQPoapl+t8VeZ8pwGqOBzn230MPyPfv79mmKnh+2CtNY52H+cQfff5JyV6REXd3xUUo2UOBQLm/Neua1UALRasLWPGS3qGJ2D8czel93WJSaQEpA8F7Ugd8sV6QNg5sSQxe5C+P8euh1OqtRyhYHBgF9xNNFt7btNB7P66YDFpABbZv2DXjbhGZtKfAV5/Vq0vQUJRdqy5idb+vQA1kjwBRvETj0nuj2xJGyg" Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 22:05:11 volumio go-librespot[12066]: time="2026-01-25T22:05:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:11 volumio volumio[11731]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 22:05:11 volumio volumio[11731]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 22:05:11 volumio go-librespot[12066]: time="2026-01-25T22:05:11+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:11 volumio go-librespot[12066]: time="2026-01-25T22:05:11+07:00" level=debug msg="completed challenge" Jan 25 22:05:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:12 volumio go-librespot[12066]: time="2026-01-25T22:05: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 25 22:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:13 volumio volumio[11731]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 22:05:13 volumio volumio[11731]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 22:05:13 volumio volumio[11731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:13 volumio volumio[11731]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:13 volumio volumio[11731]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 22:05:13 volumio volumio[11731]: info: MyVolumio login type: Token Jan 25 22:05:13 volumio volumio[11731]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 22:05:13 volumio volumio[11731]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 22:05:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:14 volumio volumio[11731]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 22:05:14 volumio volumio[11731]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 22:05:14 volumio volumio[11731]: info: Streaming services startup Jan 25 22:05:14 volumio volumio[11731]: info: Starting Streaming Daemon Jan 25 22:05:14 volumio sudo[12088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 22:05:14 volumio sudo[12088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:14 volumio volumio[11731]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 22:05:15 volumio sudo[12088]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:15 volumio volumio[11731]: info: Getting Spotify volume Jan 25 22:05:15 volumio volumio[11731]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:05:15 volumio volumio[11731]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:05:15 volumio volumio[11731]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 22:05:15 volumio volumio[11731]: errno: -111, Jan 25 22:05:15 volumio volumio[11731]: code: 'ECONNREFUSED', Jan 25 22:05:15 volumio volumio[11731]: syscall: 'connect', Jan 25 22:05:15 volumio volumio[11731]: address: '127.0.0.1', Jan 25 22:05:15 volumio volumio[11731]: port: 9879, Jan 25 22:05:15 volumio volumio[11731]: response: undefined Jan 25 22:05:15 volumio volumio[11731]: } Jan 25 22:05:15 volumio volumio[11731]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:05:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 25 22:05:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:16 volumio go-librespot[12106]: go-librespot daemon starting... Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=debug msg="app state loaded" Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:16 volumio sudo[12116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 22:04' Jan 25 22:05:16 volumio sudo[12116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=info msg="zeroconf server listening on port 45885" Jan 25 22:05:16 volumio sudo[12116]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:16 volumio go-librespot[12107]: time="2026-01-25T22:05:16+07:00" level=debug msg="obtained new client token: AABiqvq2iLbm6DlC24v2kXNSjnjUxZgG8g0oIYCQkKc6sMtICc2AptBSm1Y+YQQRn+oHajabArTBI7Oc/Z5zArevElVJBLbQZyz9NLVAosE8asVAt6g9BWAK/pl2mWvr7E5GMfwymA6hC4lgX4tq5e49pEVQilkHTb560x+htDolGhP9YWGrTO8h02LC4BFtuaWbH8BSvDSQfnpMCD7fzDlkffHLUF71oFbV6JBBE1zRDpXCWrWt1Bj0OHQ=" Jan 25 22:05:17 volumio go-librespot[12107]: time="2026-01-25T22:05:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:17 volumio volumio-remote-updater[628]: [2026-01-25 22:05:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 22:05:17 volumio volumio-remote-updater[628]: [2026-01-25 22:05:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 22:05:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:17 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 22:05:17 volumio systemd[1]: volumio.service: Consumed 1min 759ms CPU time. Jan 25 22:05:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 22:05:17 volumio go-librespot[12107]: time="2026-01-25T22:05:17+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:17 volumio go-librespot[12107]: time="2026-01-25T22:05:17+07:00" level=debug msg="completed challenge" Jan 25 22:05:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 22:05:17 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6051. Jan 25 22:05:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 22:05:17 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 22:05:17 volumio systemd[1]: volumio.service: Consumed 1min 759ms CPU time. Jan 25 22:05:17 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 22:05:17 volumio go-librespot[12107]: time="2026-01-25T22:05: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 25 22:05:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 22:05:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 25 22:05:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:20 volumio go-librespot[12146]: go-librespot daemon starting... Jan 25 22:05:20 volumio go-librespot[12147]: time="2026-01-25T22:05:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:20 volumio go-librespot[12147]: time="2026-01-25T22:05:20+07:00" level=debug msg="app state loaded" Jan 25 22:05:20 volumio go-librespot[12147]: time="2026-01-25T22:05:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:20 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:20 volumio volumio[12128]: info: ----- Volumio3 ---- Jan 25 22:05:20 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:20 volumio volumio[12128]: info: ----- System startup ---- Jan 25 22:05:20 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=info msg="zeroconf server listening on port 41793" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="obtained new client token: AAAMhMEJgMFSlHR17/rAl/MLkPc+GeCMR7pSImHQVJ9Ujdxh0n0qRAQiCvfKrHb1Kx2R7v1OiM1joyC7EnOLMei6edvbts9++vzu4XtmoWZpo3NosWtr5COG6w5uvxFTODfcWQGqOjzuku2xJJz5ilLZQT21InwztN79PshKkoTdao/CATzFZISPx1EUEGwtfe/9ReYQRKKjJUQeVzLb3DdEt0m8IpGS6rGrvvEqyi6nqAPCFkEDxiwiZBQ=" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05:21+07:00" level=debug msg="completed challenge" Jan 25 22:05:21 volumio go-librespot[12147]: time="2026-01-25T22:05: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 25 22:05:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:22 volumio volumio-remote-updater[628]: [2026-01-25 22:05:22] [connect] Successful connection Jan 25 22:05:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:22 volumio volumio[12128]: info: MYVOLUMIO Environment detected Jan 25 22:05:22 volumio volumio[12128]: info: Plugin folders cleanup Jan 25 22:05:22 volumio volumio[12128]: info: Scanning into folder /volumio/app/plugins/ Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category audio_interface Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category miscellanea Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category music_service Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category plugins.json Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category system_controller Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category user_interface Jan 25 22:05:22 volumio volumio[12128]: info: Scanning into folder /data/plugins/ Jan 25 22:05:22 volumio volumio[12128]: info: Scanning category music_service Jan 25 22:05:22 volumio volumio[12128]: info: Plugin folders cleanup completed Jan 25 22:05:22 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:22 volumio volumio[12128]: info: ----- Core plugins startup ---- Jan 25 22:05:22 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:22 volumio volumio[12128]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 22:05:22 volumio volumio[12128]: info: Adding plugin upnp to MyMusic Plugins Jan 25 22:05:22 volumio volumio[12128]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 22:05:22 volumio volumio[12128]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 22:05:22 volumio volumio[12128]: info: Loading plugins from folder /data/plugins/ Jan 25 22:05:22 volumio volumio[12128]: info: Loading plugin "system"... Jan 25 22:05:22 volumio volumio[12128]: info: Loading plugin "appearance"... Jan 25 22:05:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "network"... Jan 25 22:05:24 volumio volumio[12128]: info: Refreshing Cached IP Addresses Jan 25 22:05:24 volumio sudo[12169]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 22:05:24 volumio sudo[12169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:24 volumio sudo[12171]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "services"... Jan 25 22:05:24 volumio sudo[12171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:24 volumio sudo[12169]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "alsa_controller"... Jan 25 22:05:24 volumio sudo[12171]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:24 volumio sudo[12180]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 22:05:24 volumio sudo[12180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:24 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "wizard"... Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "networkfs"... Jan 25 22:05:24 volumio volumio[12128]: info: Starting Udev Watcher for removable devices Jan 25 22:05:24 volumio volumio[12128]: info: Ignoring mount for partition: boot Jan 25 22:05:24 volumio volumio[12128]: info: Ignoring mount for partition: volumio Jan 25 22:05:24 volumio volumio[12128]: info: Ignoring mount for partition: volumio_data Jan 25 22:05:24 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "volumio_command_line_client"... Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "upnp"... Jan 25 22:05:24 volumio volumio[12128]: info: [1769353524760] Starting Upmpd Daemon Jan 25 22:05:24 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "my_music"... Jan 25 22:05:24 volumio volumio[12128]: info: Loading plugin "mpd"... Jan 25 22:05:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 25 22:05:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:25 volumio go-librespot[12202]: go-librespot daemon starting... Jan 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+07:00" level=debug msg="app state loaded" Jan 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:25 volumio volumio[12128]: info: Loading plugin "upnp_browser"... Jan 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+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 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+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 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+07:00" level=info msg="zeroconf server listening on port 38895" Jan 25 22:05:25 volumio go-librespot[12203]: time="2026-01-25T22:05:25+07:00" level=debug msg="obtained new client token: AACmeI2vzE3HeCae0ouKwYbsVmtqpCTKIvwN6HkWduJ/VrLRZNVulCq3z4sdlUgASDuyfJKXRp6DEx+k1oX01pQBYa3ndjCio5Zfio3qt7AO9Haf6zKUf7TXRDnqJkIikvMNYArbSjePc6FWQEqFAJ/LhrgkwxXUILl1Ah850DBd7WaPLkrLoDY/Gxu+6Y6XCIoWTuyg2VXDjaaYPfQTiz6KnOVAd+pYO3xMFi251TzmKym2rnPAbYzcRzk=" Jan 25 22:05:26 volumio go-librespot[12203]: time="2026-01-25T22:05:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:26 volumio go-librespot[12203]: time="2026-01-25T22:05:26+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:26 volumio go-librespot[12203]: time="2026-01-25T22:05:26+07:00" level=debug msg="completed challenge" Jan 25 22:05:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:26 volumio go-librespot[12203]: time="2026-01-25T22:05:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:05:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:27 volumio sudo[12180]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:28 volumio volumio[12128]: info: Starting UPNP Browser Jan 25 22:05:28 volumio volumio[12128]: info: Loading plugin "alarm-clock"... Jan 25 22:05:28 volumio volumio[12128]: info: Loading plugin "airplay_emulation"... Jan 25 22:05:28 volumio volumio[12128]: info: Starting Shairport Sync Jan 25 22:05:28 volumio volumio[12128]: info: Loading plugin "last_100"... Jan 25 22:05:28 volumio volumio[12128]: info: Loading plugin "webradio"... Jan 25 22:05:28 volumio volumio[12128]: info: Loading plugin "i2s_dacs"... Jan 25 22:05:28 volumio volumio[12128]: info: Loading plugin "volumiodiscovery"... Jan 25 22:05:28 volumio volumio[12128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 22:05:28 volumio volumio[12128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:05:28 volumio volumio[12128]: *** WARNING *** For more information see Jan 25 22:05:28 volumio volumio[12128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 22:05:28 volumio volumio[12128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:05:28 volumio volumio[12128]: *** WARNING *** For more information see Jan 25 22:05:28 volumio node[12128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 22:05:28 volumio node[12128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:05:28 volumio node[12128]: *** WARNING *** For more information see Jan 25 22:05:28 volumio node[12128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 22:05:28 volumio node[12128]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:05:28 volumio node[12128]: *** WARNING *** For more information see Jan 25 22:05:29 volumio volumio[12128]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 22:05:29 volumio volumio[12128]: info: Discovery: Started advertising with name: Volumio Jan 25 22:05:29 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 22:05:29 volumio volumio[12128]: info: Loading plugin "spop"... Jan 25 22:05:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 25 22:05:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:29 volumio go-librespot[12212]: go-librespot daemon starting... Jan 25 22:05:29 volumio go-librespot[12213]: time="2026-01-25T22:05:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:29 volumio go-librespot[12213]: time="2026-01-25T22:05:29+07:00" level=debug msg="app state loaded" Jan 25 22:05:29 volumio go-librespot[12213]: time="2026-01-25T22:05:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+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 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+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 25 22:05:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+07:00" level=info msg="zeroconf server listening on port 32973" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+07:00" level=debug msg="obtained new client token: AADweMZ5ZXGUiIhds1t8EktMhbHDwUPCHkddy6ro+FAtFB1wa0N0UZqvHLv/uI+aoDAXiVkIU09xxUtFuOzzd8bZ9PdI4QTAvIpNyo5oWxF8q1VR1oQKnYvBN1rb8oy1hQguB441kwds4ttLkrI1TVndWtT5z9/9xcZn9qhoJ55I8yQHt1sz9rr4yYZHtre26neFvrFgdSoxtHwdevPkwbyMuQGPRSdaA6JJWCgdvCdKummsFSyCyRQ0yno=" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05:30+07:00" level=debug msg="completed challenge" Jan 25 22:05:30 volumio go-librespot[12213]: time="2026-01-25T22:05: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 25 22:05:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:31 volumio volumio[12128]: info: Loading plugin "ytcr"... Jan 25 22:05:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:33 volumio volumio[12128]: info: Loading plugin "ytmusic"... Jan 25 22:05:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 25 22:05:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:34 volumio go-librespot[12221]: go-librespot daemon starting... Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05:34+07:00" level=debug msg="app state loaded" Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05: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 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05: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 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05: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 25 22:05:34 volumio volumio-remote-updater[628]: [2026-01-25 22:05:34] [connect] Successful connection Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05:34+07:00" level=info msg="zeroconf server listening on port 33649" Jan 25 22:05:34 volumio volumio[12128]: info: Loading plugin "outputs"... Jan 25 22:05:34 volumio volumio[12128]: info: Loading plugin "albumart"... Jan 25 22:05:34 volumio volumio[12128]: info: Plugin example_plugin is not enabled Jan 25 22:05:34 volumio volumio[12128]: info: Loading plugin "inputs"... Jan 25 22:05:34 volumio volumio[12128]: info: Loading plugin "updater_comm"... Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05:34+07:00" level=debug msg="obtained new client token: AACnmdeT3sjpPI5/icycgMxgrtMxV6g2DViYBB/XImfipJREHBvBLeA/EdMPX6VHzU8mdFCYimDZE3HrpjabgRMg3niS7lETKAT2ZtDpf862VcNSak4vhfN6VC+ds/PiCMgKToFYh+BAVu6CSPPavTzI4+5xk5WA3i9+p4tj9hh5jky86ohmdUJoimsRTKH4pAr/nkAPmkalD98oiFiNRNXX1c5AdmAvEXOYAvLmGSHjYrExPe4azU9ZNXw=" Jan 25 22:05:34 volumio volumio[12128]: info: Plugin mpdemulation is not enabled Jan 25 22:05:34 volumio volumio[12128]: info: Loading plugin "rest_api"... Jan 25 22:05:34 volumio go-librespot[12222]: time="2026-01-25T22:05:34+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 25 22:05:35 volumio go-librespot[12222]: time="2026-01-25T22:05:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 22:05:35 volumio volumio[12128]: info: Loading plugin "websocket"... Jan 25 22:05:35 volumio volumio[12128]: info: Starting Socket.io Server version 1.7.4 Jan 25 22:05:35 volumio volumio[12128]: info: Loading plugin "RoonBridge"... Jan 25 22:05:35 volumio go-librespot[12222]: time="2026-01-25T22:05:35+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:35 volumio go-librespot[12222]: time="2026-01-25T22:05:35+07:00" level=debug msg="completed challenge" Jan 25 22:05:35 volumio go-librespot[12222]: time="2026-01-25T22:05:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:05:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:35 volumio volumio[12128]: info: Applying required configuration parameters for plugin RoonBridge Jan 25 22:05:35 volumio volumio[12128]: info: Loading i18n strings for locale en Jan 25 22:05:35 volumio volumio[12128]: Updating browse sources language Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:05:35 volumio volumio[12243]: Forking 3 albumart workers Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::initPlayerControls Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 22:05:35 volumio volumio[12128]: Express server listening on port 3000 Jan 25 22:05:35 volumio volumio[12128]: [Metrics] WebUI: 16s 90.74ms Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::resetVolumioState Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::getcurrentVolume Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:05:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:36 volumio sudo[12285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 22:05:36 volumio sudo[12285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:36 volumio sudo[12288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 22:05:36 volumio sudo[12285]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:36 volumio sudo[12288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:36 volumio volumio[12128]: info: Volumio Network Manager: Network status updated: 1 Jan 25 22:05:36 volumio sudo[12288]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:36 volumio volumio[12128]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::pushState Jan 25 22:05:36 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::volumioPushState Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::updateTrackBlock Jan 25 22:05:36 volumio volumio[12128]: info: CorePlayQueue::getTrackBlock Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:05:36 volumio volumio-remote-updater[628]: [2026-01-25 22:05:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769353534 101 Jan 25 22:05:36 volumio volumio[12128]: 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 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:36 volumio volumio[12128]: info: Reloading queue from file Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::setRepeat null single undefined Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::pushState Jan 25 22:05:36 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::volumioPushState Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::setRandom null Jan 25 22:05:36 volumio volumio[12128]: info: CoreStateMachine::pushState Jan 25 22:05:36 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:36 volumio volumio[12128]: info: CoreCommandRouter::volumioPushState Jan 25 22:05:36 volumio volumio[12128]: info: Setting Device type: Raspberry PI Jan 25 22:05:36 volumio volumio[12128]: info: Completed loading Core Plugins Jan 25 22:05:36 volumio volumio[12128]: info: Preparing to generate the ALSA configuration file Jan 25 22:05:37 volumio volumio[12128]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:05:37 volumio volumio[12128]: info: CoreStateMachine::pushState Jan 25 22:05:37 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::volumioPushState Jan 25 22:05:37 volumio volumio[12128]: info: Asound.conf file unchanged, so no further update is needed Jan 25 22:05:37 volumio volumio[12128]: info: Output device has changed, restarting MPD Jan 25 22:05:37 volumio volumio[12128]: info: Output device has changed, restarting Shairport Sync Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:37 volumio sudo[12304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 22:05:37 volumio sudo[12304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:37 volumio sudo[12306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 22:05:37 volumio sudo[12306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:37 volumio volumio[12128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 22:05:37 volumio volumio[12128]: info: ___________ START PLUGINS ___________ Jan 25 22:05:37 volumio sudo[12306]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:37 volumio sudo[12308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 22:05:37 volumio sudo[12308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:37 volumio volumio[12128]: info: ControllerMpd::onStart: Initializing MPD Jan 25 22:05:37 volumio volumio[12128]: info: Creating MPD Configuration file Jan 25 22:05:37 volumio sudo[12304]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:05:37 volumio volumio[12128]: info: [1769353537406] CoreMusicLibrary::Adding element Media Servers Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:05:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 22:05:37 volumio sudo[12319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 22:05:37 volumio sudo[12319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:37 volumio sudo[12317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 22:05:37 volumio sudo[12317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:37 volumio volumio[12128]: info: UPNP Browser: Client initialized successfully Jan 25 22:05:37 volumio sudo[12317]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:37 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 22:05:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 22:05:37 volumio systemd[1]: mpd.service: Consumed 7.514s CPU time. Jan 25 22:05:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 22:05:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 22:05:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:37 volumio volumio[12128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 22:05:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 22:05:37 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 22:05:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 22:05:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 22:05:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 22:05:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 22:05:37 volumio volumio[12128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:05:37 volumio volumio[12128]: info: [1769353537771] CoreMusicLibrary::Adding element Last_100 Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:05:37 volumio volumio[12128]: info: [1769353537781] CoreMusicLibrary::Adding element Webradio Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 22:05:37 volumio volumio[12128]: info: Initializing BBC Radios Jan 25 22:05:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 22:05:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 22:05:37 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:38 volumio volumio[12128]: info: Creating Spotify config file Jan 25 22:05:38 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:38 volumio sudo[12335]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 22:05:38 volumio sudo[12335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 22:05:38 volumio sudo[12335]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 25 22:05:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:38 volumio go-librespot[12349]: go-librespot daemon starting... Jan 25 22:05:38 volumio go-librespot[12350]: time="2026-01-25T22:05:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:39 volumio volumio[12128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:05:39 volumio volumio[12128]: info: [1769353539253] CoreMusicLibrary::Adding element YouTube Music Jan 25 22:05:39 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:05:39 volumio volumio[12128]: Cannot find translation for source YouTube Music Jan 25 22:05:39 volumio volumio[12128]: info: Volumio Calling Home Jan 25 22:05:39 volumio go-librespot[12350]: time="2026-01-25T22:05:39+07:00" level=info msg="zeroconf server listening on port 36449" Jan 25 22:05:39 volumio sudo[12358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 25 22:05:39 volumio volumio[12254]: Starting albumart workers Jan 25 22:05:39 volumio sudo[12358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:39 volumio sudo[12358]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:39 volumio volumio[12255]: Starting albumart workers Jan 25 22:05:39 volumio volumio[12253]: Starting albumart workers Jan 25 22:05:39 volumio volumio[12128]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 22:05:39 volumio volumio[12128]: info: Discovery: Found device Volumio Jan 25 22:05:39 volumio volumio[12128]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:39 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:40 volumio volumio[12128]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 22:05:40 volumio volumio[12128]: info: Discovery: Found device Volumio Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:40 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:40 volumio volumio[12128]: info: MPD Permissions set Jan 25 22:05:40 volumio volumio[12128]: info: MPD Permissions set Jan 25 22:05:40 volumio volumio[12128]: info: Upmpdcli Daemon Started Jan 25 22:05:40 volumio volumio[12128]: info: Spotify config file written Jan 25 22:05:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:40 volumio sudo[12364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 22:05:40 volumio sudo[12364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:40 volumio volumio[12128]: 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 25 22:05:40 volumio volumio[12128]: info: Volumio called home Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 22:05:40 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 22:05:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:40 volumio go-librespot[12371]: go-librespot daemon starting... Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:40 volumio sudo[12364]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:40 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:05:40 volumio volumio[12128]: info: No need to fix Spotify hosts Jan 25 22:05:40 volumio go-librespot[12377]: time="2026-01-25T22:05:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:40 volumio go-librespot[12377]: time="2026-01-25T22:05:40+07:00" level=debug msg="app state loaded" Jan 25 22:05:40 volumio go-librespot[12377]: time="2026-01-25T22:05:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05: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-gew1.spotify.com:80]" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+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 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+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 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+07:00" level=info msg="zeroconf server listening on port 41565" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+07:00" level=debug msg="obtained new client token: AAAeqW2ChMpyOJsQPLNnSnmMcS8//Qtzb9+Yarnfk+fMnwTf1Gx02EkNk1l/ubtb7qTWZas1R2uIoYvzLoTfsL/DOU/hWa9C45puNBbl9BW9uJ55T8r+dTScxP/gVpYk0eIpJRzSSp0s6yt3f1d86iqdMC9Xk3AjTibf5DcIwVJkv65ZRBFO9bK9gL0/U1tD/KodCHBlGqEQOQy2jgcAnl/cG1ZjTvA5rC+CYfK4+KQ6P75hppipu3KiUZE=" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+07:00" level=debug msg="completed challenge" Jan 25 22:05:41 volumio go-librespot[12377]: time="2026-01-25T22:05:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:05:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:42 volumio volumio[12128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 22:05:42 volumio volumio[12128]: SPOTIFY: BQARp1VlXXUjKX5fKBUDbemh3AeZWZWGiLLEfO10uQccS9FZCyrqYsTWfZ0RWaadGe81c09QiUEWXGUvMoATYeblbBgxEGjve83u804GqwlZ-Rp4Adok-KoSLuLGJVrOJkOYUa8msR3d2VgYVA0_WVkhUxMHm9kc-XuJXvbztG88rLuclg2WIcC1ek2xAInSX8_UXlRAaldoHB9KbS6Z48V-4-TY_srYiS2NlacQ1YzNdXJhPXCKG25DWVBdaBatqg33x-EtCQRsbI02UJqA51Mc1UHtXAJtn9bREUNuhKjXcPtE0sFVXybR Jan 25 22:05:42 volumio volumio[12128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 22:05:42 volumio volumio[12128]: info: New Spotify access token = BQARp1VlXXUjKX5fKBUDbemh3AeZWZWGiLLEfO10uQccS9FZCyrqYsTWfZ0RWaadGe81c09QiUEWXGUvMoATYeblbBgxEGjve83u804GqwlZ-Rp4Adok-KoSLuLGJVrOJkOYUa8msR3d2VgYVA0_WVkhUxMHm9kc-XuJXvbztG88rLuclg2WIcC1ek2xAInSX8_UXlRAaldoHB9KbS6Z48V-4-TY_srYiS2NlacQ1YzNdXJhPXCKG25DWVBdaBatqg33x-EtCQRsbI02UJqA51Mc1UHtXAJtn9bREUNuhKjXcPtE0sFVXybR Jan 25 22:05:42 volumio volumio[12128]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 22:05:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:42 volumio volumio[12128]: info: Starting Shairport Sync Jan 25 22:05:42 volumio volumio[12128]: info: Starting Shairport Sync Jan 25 22:05:42 volumio volumio[12128]: info: Starting Shairport Sync Jan 25 22:05:42 volumio sudo[12405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 22:05:42 volumio sudo[12405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:42 volumio sudo[12409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 22:05:42 volumio sudo[12409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:42 volumio sudo[12407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 22:05:42 volumio sudo[12407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 22:05:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 22:05:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 22:05:42 volumio systemd[1]: shairport-sync.service: Consumed 2.377s CPU time. Jan 25 22:05:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 22:05:42 volumio volumio[12128]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:42 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:42 volumio sudo[12407]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:42 volumio sudo[12409]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:42 volumio sudo[12405]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:42 volumio volumio[12128]: info: Shairport-Sync Started Jan 25 22:05:42 volumio volumio[12128]: Error adding Membership: Error: addMembership EINVAL Jan 25 22:05:42 volumio volumio[12128]: info: Shairport-Sync Started Jan 25 22:05:42 volumio volumio[12128]: info: Shairport-Sync Started Jan 25 22:05:42 volumio volumio[12128]: 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 25 22:05:42 volumio volumio[12128]: info: Spotify Successfully logged in Jan 25 22:05:42 volumio volumio[12128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:05:42 volumio volumio[12128]: info: [1769353542952] CoreMusicLibrary::Adding element Spotify Jan 25 22:05:42 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:05:42 volumio volumio[12128]: Cannot find translation for source YouTube Music Jan 25 22:05:42 volumio volumio[12128]: Cannot find translation for source Spotify Jan 25 22:05:43 volumio volumio[12128]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 22:05:43 volumio volumio[12128]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:05:43 volumio volumio[12128]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:05:43 volumio volumio[12128]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:43 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:43 volumio volumio[12128]: info: CoreStateMachine::pushState Jan 25 22:05:43 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:43 volumio volumio[12128]: info: CoreCommandRouter::volumioPushState Jan 25 22:05:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:45 volumio volumio[12128]: info: go-librespot daemon successfully initialized Jan 25 22:05:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 22:05:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:45 volumio go-librespot[12444]: go-librespot daemon starting... Jan 25 22:05:45 volumio go-librespot[12445]: time="2026-01-25T22:05:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:45 volumio go-librespot[12445]: time="2026-01-25T22:05:45+07:00" level=debug msg="app state loaded" Jan 25 22:05:45 volumio go-librespot[12445]: time="2026-01-25T22:05:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:45 volumio mpd[12348]: 2026-01-25T22:05:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 22:05:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 22:05:45 volumio sudo[12308]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:45 volumio sudo[12319]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+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 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+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 25 22:05:46 volumio volumio[12128]: error: MPD error: The expression evaluated to a falsy value: Jan 25 22:05:46 volumio volumio[12128]: assert.ok(self.idling) Jan 25 22:05:46 volumio volumio[12128]: error: The expression evaluated to a falsy value: Jan 25 22:05:46 volumio volumio[12128]: assert.ok(self.idling) Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+07:00" level=info msg="zeroconf server listening on port 33695" Jan 25 22:05:46 volumio volumio[12128]: error: updateQueue error: null Jan 25 22:05:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:46 volumio volumio[12128]: info: Completed starting Core Plugins Jan 25 22:05:46 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:46 volumio volumio[12128]: info: ----- MyVolumio plugins startup ---- Jan 25 22:05:46 volumio volumio[12128]: info: ------------------------------------------- Jan 25 22:05:46 volumio volumio[12128]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 22:05:46 volumio volumio[12128]: info: MPD running with PID12348 Jan 25 22:05:46 volumio volumio[12128]: ,establishing connection Jan 25 22:05:46 volumio volumio[12128]: error: updateQueue error: null Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+07:00" level=debug msg="obtained new client token: AAAWUBHDdSyw/k0Xluneg2RH4ipDlUO0Ol1/vQmFQjY9aEs4oTwJrCIMEKnGxwZZFsr49E3K5gvX/3Q7ES4+G0tq9SzA3G6PHRMGacyLRDFCclOZyY69FMbejkzNab2SV8tLifEMv9eif4feOH4Ar/X+IzITLp5uk8/1QqbEOtckHB1oZZTVrE01uOA6p0gj2Lc7hEQd4mjRc1g4XXe6KQHmS5x5W/LPBRx6rW5vkQKEdCW0YdKyToe4XXg=" Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05:46+07:00" level=debug msg="completed challenge" Jan 25 22:05:46 volumio go-librespot[12445]: time="2026-01-25T22:05: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 25 22:05:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:48 volumio volumio[12128]: info: Initializing connection to go-librespot Websocket Jan 25 22:05:48 volumio volumio[12128]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:05:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 22:05:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:49 volumio go-librespot[12458]: go-librespot daemon starting... Jan 25 22:05:49 volumio go-librespot[12459]: time="2026-01-25T22:05:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:49 volumio go-librespot[12459]: time="2026-01-25T22:05:49+07:00" level=debug msg="app state loaded" Jan 25 22:05:49 volumio go-librespot[12459]: time="2026-01-25T22:05:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+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 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+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 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+07:00" level=info msg="zeroconf server listening on port 43501" Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+07:00" level=debug msg="obtained new client token: AABU8ea7T1CpEzzIehdWgWAxGejCgSiG1DTUmftc3KwFfr64u4tC32f0L35QZLMOC5+QxEWN4fGZcdBwpdvRWbCqxxMNPsW2s3GQ6lju3OBmCfvieAHRF5UxcXkGM2DuN0AsgM0hgeGfbI8TwQS9GJLEGouzYTAQgCDB92ePunT62XAe7fakzNmmuQqfqYSRaanNoshiz2a/k0J0PE8q/A2va4lKP8/qW6VFguvMn9BZ/bR/v7Aiqo2f5Q0=" Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+07:00" level=debug msg="completed challenge" Jan 25 22:05:50 volumio go-librespot[12459]: time="2026-01-25T22:05:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:05:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:50 volumio volumio[12128]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 22:05:51 volumio volumio[12128]: info: Initializing connection to go-librespot Websocket Jan 25 22:05:51 volumio volumio[12128]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:05:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 22:05:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:54 volumio go-librespot[12466]: go-librespot daemon starting... Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=debug msg="app state loaded" Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:54 volumio volumio[12128]: info: Initializing connection to go-librespot Websocket Jan 25 22:05:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=debug msg="new websocket client" Jan 25 22:05:54 volumio volumio[12128]: info: Connection to go-librespot Websocket established Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+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 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+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 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=info msg="zeroconf server listening on port 33127" Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=debug msg="obtained new client token: AACcgvz2yQ+w7rPrZ/yJFWZheuV7VAeqLEcfBizwY7PaBcjQ2XpCE8fh4djuOOA+bsB8DgTU2/0GkX+R1lepRCiE5StpaIfe17fnbRnxCUl0HYVA9B0URKx0JZ4Z4OkFTWuPPibdRaAoj75aaN6SBmkhcUujGTTV/xkqDopEtcAjVNSA6S6RSrRH3oMzIy0UcQQg5/+HEq+AHwZ8Hj9vsh4CpXFCHxzb9g31LVZ4lRbNrpvz4N5zgHihnBI=" Jan 25 22:05:54 volumio go-librespot[12467]: time="2026-01-25T22:05:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 22:05:55 volumio go-librespot[12467]: time="2026-01-25T22:05:55+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 22:05:55 volumio go-librespot[12467]: time="2026-01-25T22:05:55+07:00" level=debug msg="completed challenge" Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 22:05:55 volumio volumio[12128]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 22:05:55 volumio volumio[12128]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 22:05:55 volumio go-librespot[12467]: time="2026-01-25T22:05: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 25 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:56 volumio volumio[12128]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 22:05:56 volumio volumio[12128]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 22:05:56 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:56 volumio volumio[12128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:05:56 volumio volumio[12128]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 22:05:57 volumio volumio[12128]: info: MyVolumio login type: Token Jan 25 22:05:57 volumio volumio[12128]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 22:05:57 volumio volumio[12128]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 22:05:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 25 22:05:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:05:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:05:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:05:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:05:58 volumio go-librespot[12488]: go-librespot daemon starting... Jan 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+07:00" level=debug msg="app state loaded" Jan 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:05:58 volumio volumio[12128]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 22:05:58 volumio volumio[12128]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 22:05:58 volumio volumio[12128]: info: Streaming services startup Jan 25 22:05:58 volumio volumio[12128]: info: Starting Streaming Daemon Jan 25 22:05:58 volumio sudo[12497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 22:05:58 volumio sudo[12497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:05:58 volumio volumio[12128]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 22:05:58 volumio sudo[12497]: pam_unix(sudo:session): session closed for user root Jan 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+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 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+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 25 22:05:58 volumio volumio[12128]: info: Getting Spotify volume Jan 25 22:05:58 volumio go-librespot[12489]: time="2026-01-25T22:05:58+07:00" level=info msg="zeroconf server listening on port 46329" Jan 25 22:05:58 volumio volumio[12128]: info: Connection to go-librespot Websocket closed Jan 25 22:05:58 volumio volumio[12128]: error: Cannot start Volumio Streaming Daemon Jan 25 22:05:58 volumio volumio[12128]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 22:05:58 volumio volumio[12128]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 22:05:59 volumio volumio[12128]: 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 25 22:05:59 volumio go-librespot[12489]: time="2026-01-25T22:05:59+07:00" level=debug msg="obtained new client token: AABbhOXxw8cTuhpykz3C58D8nHCQk6yolWLyv3RoRdRjADdBCZ5coCHqrmBO0krVg2FezadyKt0dHZDrxhTvKrtG8dRRMIu0zNRQSEmvP6gj422VmvNqmcl/8HjV2P3o4rBqu4M0RLMwgD+rXa23jqg2vHDs9wsD59drq6HhYin2N+a19iJXiiNL4dOu6Zt3EspAaCDZsmulHx4YHY9YPCTSlI202ZNwunfosej2KKT7wwNPLP57BUSg" Jan 25 22:05:59 volumio volumio[12128]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:59 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:59 volumio volumio[12128]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 25 22:05:59 volumio volumio[12128]: SPOTIFY: SPOTIFY VOLUME undefined Jan 25 22:05:59 volumio volumio[12128]: SPOTIFY: VOLUMIO VOLUME 100 Jan 25 22:05:59 volumio volumio[12128]: info: Aligning Spotify Volume to Volumio Volume Jan 25 22:05:59 volumio volumio[12128]: info: CoreCommandRouter::volumioGetState Jan 25 22:05:59 volumio volumio[12128]: info: CorePlayQueue::getTrack 0 Jan 25 22:05:59 volumio volumio[12128]: info: Setting Spotify Volume from Volumio: 100 Jan 25 22:05:59 volumio go-librespot[12489]: time="2026-01-25T22:05:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:05:59 volumio go-librespot[12489]: time="2026-01-25T22:05:59+07:00" level=debug msg="completed keyexchange" Jan 25 22:05:59 volumio go-librespot[12489]: time="2026-01-25T22:05:59+07:00" level=debug msg="completed challenge" Jan 25 22:05:59 volumio go-librespot[12489]: time="2026-01-25T22:05: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 25 22:05:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:05:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:05:59 volumio volumio[12128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:05:59 volumio volumio[12128]: Error: socket hang up Jan 25 22:05:59 volumio volumio[12128]: at connResetException (node:internal/errors:720:14) Jan 25 22:05:59 volumio volumio[12128]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 25 22:05:59 volumio volumio[12128]: at Socket.emit (node:events:526:35) Jan 25 22:05:59 volumio volumio[12128]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 25 22:05:59 volumio volumio[12128]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 25 22:05:59 volumio volumio[12128]: code: 'ECONNRESET', Jan 25 22:05:59 volumio volumio[12128]: response: undefined Jan 25 22:05:59 volumio volumio[12128]: } Jan 25 22:05:59 volumio volumio[12128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:00 volumio sudo[12517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 22:05' Jan 25 22:06:00 volumio sudo[12517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:01 volumio sudo[12517]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 25 22:06:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:02 volumio go-librespot[12525]: go-librespot daemon starting... Jan 25 22:06:02 volumio go-librespot[12526]: time="2026-01-25T22:06:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:02 volumio go-librespot[12526]: time="2026-01-25T22:06:02+07:00" level=debug msg="app state loaded" Jan 25 22:06:02 volumio go-librespot[12526]: time="2026-01-25T22:06:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:02 volumio volumio-remote-updater[628]: [2026-01-25 22:06:02] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 25 22:06:02 volumio volumio-remote-updater[628]: [2026-01-25 22:06:02] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 25 22:06:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 22:06:02 volumio systemd[1]: volumio.service: Consumed 1min 1.414s CPU time. Jan 25 22:06:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 22:06:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 22:06:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6052. Jan 25 22:06:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 22:06:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 22:06:02 volumio systemd[1]: volumio.service: Consumed 1min 1.414s CPU time. Jan 25 22:06:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 22:06:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=info msg="zeroconf server listening on port 44533" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="obtained new client token: AABOVGecRGa61isb5qaXp99tDYgVxBblJDYm3qjp9hjmm/MlgFA3OlCWyTnvSY5m7PwV34UqhHX0////HKaOx9mVBaIQn1zU2GxOa0JloJQ/fB3/HtrbsMdukqVRfnwpnozGKBvKol0bigAenn+gSvdUAxJsVS8TZEPwbIiVeWkKQo5gObD/chrisKB6qdoppXVF/TnSBm+Ld1lr/7KCuZarEBnCqpyjUgWVHCMoF+FFD4OiIIygAnuvR4A=" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06:03+07:00" level=debug msg="completed challenge" Jan 25 22:06:03 volumio go-librespot[12526]: time="2026-01-25T22:06: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 25 22:06:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:06 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:06 volumio volumio[12545]: info: ----- Volumio3 ---- Jan 25 22:06:06 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:06 volumio volumio[12545]: info: ----- System startup ---- Jan 25 22:06:06 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 25 22:06:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:07 volumio go-librespot[12566]: go-librespot daemon starting... Jan 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06:07+07:00" level=debug msg="app state loaded" Jan 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06: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 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06: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 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06: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 25 22:06:07 volumio go-librespot[12567]: time="2026-01-25T22:06:07+07:00" level=info msg="zeroconf server listening on port 34471" Jan 25 22:06:07 volumio volumio-remote-updater[628]: [2026-01-25 22:06:07] [connect] Successful connection Jan 25 22:06:08 volumio volumio[12545]: info: MYVOLUMIO Environment detected Jan 25 22:06:08 volumio go-librespot[12567]: time="2026-01-25T22:06:08+07:00" level=debug msg="obtained new client token: AABPFmaT0BJ5Xajut4idK9COG+wR2k3qanyV/Oi84dJGnvS1CNIMwIhQOrFoYIJc/ky2JJ8wTDzYq3JeIqdIirvOLpUX+Ai60v9MWKM6POXmGTXbYeLVwNdArrQAVgLUUAbHNm+AhkPuX9J+W9NvQsDAk46ZiyoMmiDpA2yqIF+3e+mmVBnBMvRruoXjlOveDEot8BICcOUUuDULvmY/I+1CA+Dsv02dKOZrch9e+KgenS7AQ9LzhBL0Plk=" Jan 25 22:06:08 volumio go-librespot[12567]: time="2026-01-25T22:06:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:08 volumio volumio[12545]: info: Plugin folders cleanup Jan 25 22:06:08 volumio volumio[12545]: info: Scanning into folder /volumio/app/plugins/ Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category audio_interface Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category miscellanea Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category music_service Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category plugins.json Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category system_controller Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category user_interface Jan 25 22:06:08 volumio volumio[12545]: info: Scanning into folder /data/plugins/ Jan 25 22:06:08 volumio volumio[12545]: info: Scanning category music_service Jan 25 22:06:08 volumio volumio[12545]: info: Plugin folders cleanup completed Jan 25 22:06:08 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:08 volumio volumio[12545]: info: ----- Core plugins startup ---- Jan 25 22:06:08 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:08 volumio volumio[12545]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 22:06:08 volumio volumio[12545]: info: Adding plugin upnp to MyMusic Plugins Jan 25 22:06:08 volumio volumio[12545]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 22:06:08 volumio volumio[12545]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 22:06:08 volumio volumio[12545]: info: Loading plugins from folder /data/plugins/ Jan 25 22:06:08 volumio volumio[12545]: info: Loading plugin "system"... Jan 25 22:06:08 volumio go-librespot[12567]: time="2026-01-25T22:06:08+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:08 volumio go-librespot[12567]: time="2026-01-25T22:06:08+07:00" level=debug msg="completed challenge" Jan 25 22:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:08 volumio volumio[12545]: info: Loading plugin "appearance"... Jan 25 22:06:08 volumio go-librespot[12567]: time="2026-01-25T22:06:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:06:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "network"... Jan 25 22:06:10 volumio volumio[12545]: info: Refreshing Cached IP Addresses Jan 25 22:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:10 volumio sudo[12583]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 22:06:10 volumio sudo[12583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:10 volumio sudo[12585]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 22:06:10 volumio sudo[12585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "services"... Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "alsa_controller"... Jan 25 22:06:10 volumio sudo[12583]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:10 volumio sudo[12585]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:10 volumio sudo[12597]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 22:06:10 volumio sudo[12597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:10 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "wizard"... Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "networkfs"... Jan 25 22:06:10 volumio volumio[12545]: info: Starting Udev Watcher for removable devices Jan 25 22:06:10 volumio volumio[12545]: info: Ignoring mount for partition: boot Jan 25 22:06:10 volumio volumio[12545]: info: Ignoring mount for partition: volumio Jan 25 22:06:10 volumio volumio[12545]: info: Ignoring mount for partition: volumio_data Jan 25 22:06:10 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "volumio_command_line_client"... Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "upnp"... Jan 25 22:06:10 volumio volumio[12545]: info: [1769353570612] Starting Upmpd Daemon Jan 25 22:06:10 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "my_music"... Jan 25 22:06:10 volumio volumio[12545]: info: Loading plugin "mpd"... Jan 25 22:06:11 volumio volumio[12545]: info: Loading plugin "upnp_browser"... Jan 25 22:06:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 25 22:06:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:11 volumio go-librespot[12616]: go-librespot daemon starting... Jan 25 22:06:11 volumio go-librespot[12617]: time="2026-01-25T22:06:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:11 volumio go-librespot[12617]: time="2026-01-25T22:06:11+07:00" level=debug msg="app state loaded" Jan 25 22:06:11 volumio go-librespot[12617]: time="2026-01-25T22:06:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=info msg="zeroconf server listening on port 44417" Jan 25 22:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="obtained new client token: AACZXQJgQ8ngnehObd4LDGBupQ6aDdjpMD/HRULGRDqSce6dZmOlQ/kVYXalpQcTc8SZcK19CSyRxCCNPHWbZ0VIhhkiMYtfcn+U7SRkiGugaN/MngsfJwOcedziyoFEcPAJea0u2khHSCTokZQ+yuSD91XDrqPR9bmTyn31XIt8/xCr8XW9uMvBq8Ha2fBs19BlKFZ+eK7vR5zrtRLGGUoe9cmhgvJanE8jGIf3cjcq+LZ1+3pLRbP49Mw=" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06:12+07:00" level=debug msg="completed challenge" Jan 25 22:06:12 volumio go-librespot[12617]: time="2026-01-25T22:06: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 25 22:06:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:13 volumio sudo[12597]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:14 volumio volumio[12545]: info: Starting UPNP Browser Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "alarm-clock"... Jan 25 22:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "airplay_emulation"... Jan 25 22:06:14 volumio volumio[12545]: info: Starting Shairport Sync Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "last_100"... Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "webradio"... Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "i2s_dacs"... Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "volumiodiscovery"... Jan 25 22:06:14 volumio volumio[12545]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 22:06:14 volumio volumio[12545]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:06:14 volumio node[12545]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 22:06:14 volumio volumio[12545]: *** WARNING *** For more information see Jan 25 22:06:14 volumio volumio[12545]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 22:06:14 volumio volumio[12545]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:06:14 volumio volumio[12545]: *** WARNING *** For more information see Jan 25 22:06:14 volumio node[12545]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:06:14 volumio node[12545]: *** WARNING *** For more information see Jan 25 22:06:14 volumio node[12545]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 22:06:14 volumio node[12545]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 22:06:14 volumio node[12545]: *** WARNING *** For more information see Jan 25 22:06:14 volumio volumio[12545]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 22:06:14 volumio volumio[12545]: info: Discovery: Started advertising with name: Volumio Jan 25 22:06:14 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 22:06:14 volumio volumio[12545]: info: Loading plugin "spop"... Jan 25 22:06:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 25 22:06:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:16 volumio go-librespot[12627]: go-librespot daemon starting... Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=debug msg="app state loaded" Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=info msg="zeroconf server listening on port 46247" Jan 25 22:06:16 volumio volumio[12545]: info: Loading plugin "ytcr"... Jan 25 22:06:16 volumio go-librespot[12628]: time="2026-01-25T22:06:16+07:00" level=debug msg="obtained new client token: AADTff73j+G2spsn54V2CtpoU6cWCxYzNemyWhTnUJl0h+BpktkOLp5VpJjFNX9Le2W+uW+GPzU7kOLHXcV8av9DWKt89oDInfw9MJwjxWCv24pQrDSBISyaoICoOUX9q7PBfLYxxy5ES7WT+sRPbWpXNxVQX0XRoMBLoJ+Ys6RsP3mrhs089wjc/BdW5ipIbdW23mAhLpb1tHQxBK7OCA9CDy6nOb5lsFT0Trla1C6Ajqre/aZMWe+4I8g=" Jan 25 22:06:17 volumio go-librespot[12628]: time="2026-01-25T22:06:17+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 25 22:06:17 volumio go-librespot[12628]: time="2026-01-25T22:06:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 22:06:17 volumio go-librespot[12628]: time="2026-01-25T22:06:17+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:17 volumio go-librespot[12628]: time="2026-01-25T22:06:17+07:00" level=debug msg="completed challenge" Jan 25 22:06:17 volumio go-librespot[12628]: time="2026-01-25T22:06:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:06:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:19 volumio volumio[12545]: info: Loading plugin "ytmusic"... Jan 25 22:06:20 volumio volumio-remote-updater[628]: [2026-01-25 22:06:20] [connect] Successful connection Jan 25 22:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 25 22:06:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:20 volumio volumio[12545]: info: Loading plugin "outputs"... Jan 25 22:06:20 volumio volumio[12545]: info: Loading plugin "albumart"... Jan 25 22:06:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:20 volumio go-librespot[12650]: go-librespot daemon starting... Jan 25 22:06:20 volumio volumio[12545]: info: Plugin example_plugin is not enabled Jan 25 22:06:20 volumio volumio[12545]: info: Loading plugin "inputs"... Jan 25 22:06:20 volumio volumio[12545]: info: Loading plugin "updater_comm"... Jan 25 22:06:20 volumio go-librespot[12652]: time="2026-01-25T22:06:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:20 volumio go-librespot[12652]: time="2026-01-25T22:06:20+07:00" level=debug msg="app state loaded" Jan 25 22:06:20 volumio go-librespot[12652]: time="2026-01-25T22:06:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:21 volumio volumio[12545]: info: Plugin mpdemulation is not enabled Jan 25 22:06:21 volumio volumio[12545]: info: Loading plugin "rest_api"... Jan 25 22:06:21 volumio volumio[12545]: info: Loading plugin "websocket"... Jan 25 22:06:21 volumio volumio[12545]: info: Starting Socket.io Server version 1.7.4 Jan 25 22:06:21 volumio volumio[12545]: info: Loading plugin "RoonBridge"... Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=info msg="zeroconf server listening on port 39821" Jan 25 22:06:21 volumio volumio[12545]: info: Applying required configuration parameters for plugin RoonBridge Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="obtained new client token: AADWY2SwUvaS3+1W0Wd4yofTTikBf7+5IHtve0ck5qACj3gNQu1kz4o7NkFxhzSKK2bNu4eG2FAV2bG94+TCETeF3ShGjAk2xMlDXJg49NSPL49ilSlAxwtT1HXTJAeBGqHFtCmHstQpG5p9wU0q43OD89zhJUeS9GHWlmYuWtwG0QLDyzVsJoLpv8v/pzZd+0iXyVXjR97PTuOHu56pZJTgDMrFHjCgcTiC5tN9xTsa5D0nIXnasiCwqdg=" Jan 25 22:06:21 volumio volumio[12545]: info: Loading i18n strings for locale en Jan 25 22:06:21 volumio volumio[12545]: Updating browse sources language Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:21 volumio volumio[12651]: Forking 3 albumart workers Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06:21+07:00" level=debug msg="completed challenge" Jan 25 22:06:21 volumio go-librespot[12652]: time="2026-01-25T22:06: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 25 22:06:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 22:06:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::initPlayerControls Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 22:06:21 volumio volumio[12545]: Express server listening on port 3000 Jan 25 22:06:21 volumio volumio[12545]: [Metrics] WebUI: 16s 314.10ms Jan 25 22:06:21 volumio volumio[12545]: info: CoreStateMachine::resetVolumioState Jan 25 22:06:21 volumio volumio[12545]: info: CoreStateMachine::getcurrentVolume Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:06:22 volumio sudo[12704]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 22:06:22 volumio sudo[12704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:22 volumio volumio[12545]: info: Volumio Network Manager: Network status updated: 1 Jan 25 22:06:22 volumio sudo[12707]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 22:06:22 volumio sudo[12707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:22 volumio sudo[12704]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:22 volumio sudo[12707]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:22 volumio volumio-remote-updater[628]: [2026-01-25 22:06:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769353580 101 Jan 25 22:06:22 volumio volumio[12545]: 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 25 22:06:22 volumio volumio[12545]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::pushState Jan 25 22:06:22 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::volumioPushState Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::updateTrackBlock Jan 25 22:06:22 volumio volumio[12545]: info: CorePlayQueue::getTrackBlock Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:22 volumio volumio[12545]: info: Reloading queue from file Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::setRepeat null single undefined Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::pushState Jan 25 22:06:22 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::volumioPushState Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::setRandom null Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::pushState Jan 25 22:06:22 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::volumioPushState Jan 25 22:06:22 volumio volumio[12545]: info: Setting Device type: Raspberry PI Jan 25 22:06:22 volumio volumio[12545]: info: Completed loading Core Plugins Jan 25 22:06:22 volumio volumio[12545]: info: Preparing to generate the ALSA configuration file Jan 25 22:06:22 volumio volumio[12545]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:06:22 volumio volumio[12545]: info: CoreStateMachine::pushState Jan 25 22:06:22 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:22 volumio volumio[12545]: info: CoreCommandRouter::volumioPushState Jan 25 22:06:22 volumio volumio[12545]: info: Asound.conf file unchanged, so no further update is needed Jan 25 22:06:22 volumio volumio[12545]: info: Output device has changed, restarting MPD Jan 25 22:06:23 volumio volumio[12545]: info: Output device has changed, restarting Shairport Sync Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:23 volumio sudo[12721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 22:06:23 volumio sudo[12721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:23 volumio sudo[12723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 22:06:23 volumio sudo[12723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:23 volumio sudo[12726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 22:06:23 volumio sudo[12726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:23 volumio sudo[12723]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:23 volumio volumio[12545]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 22:06:23 volumio volumio[12545]: info: ___________ START PLUGINS ___________ Jan 25 22:06:23 volumio volumio[12545]: info: ControllerMpd::onStart: Initializing MPD Jan 25 22:06:23 volumio volumio[12545]: info: Creating MPD Configuration file Jan 25 22:06:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 22:06:23 volumio sudo[12721]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:06:23 volumio volumio[12545]: info: [1769353583347] CoreMusicLibrary::Adding element Media Servers Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:06:23 volumio sudo[12734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 22:06:23 volumio sudo[12734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:23 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 22:06:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 22:06:23 volumio systemd[1]: mpd.service: Consumed 7.530s CPU time. Jan 25 22:06:23 volumio sudo[12734]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 22:06:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 22:06:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 22:06:23 volumio sudo[12736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 22:06:23 volumio sudo[12736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:23 volumio volumio[12545]: info: UPNP Browser: Client initialized successfully Jan 25 22:06:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 22:06:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:23 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 22:06:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 22:06:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 22:06:23 volumio volumio[12545]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 22:06:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 22:06:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 22:06:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 22:06:23 volumio volumio[12545]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:06:23 volumio volumio[12545]: info: [1769353583663] CoreMusicLibrary::Adding element Last_100 Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:06:23 volumio volumio[12545]: info: [1769353583681] CoreMusicLibrary::Adding element Webradio Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 22:06:23 volumio volumio[12545]: info: Initializing BBC Radios Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:23 volumio volumio[12545]: info: Creating Spotify config file Jan 25 22:06:23 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:24 volumio sudo[12750]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 22:06:24 volumio sudo[12750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 22:06:24 volumio sudo[12750]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:24 volumio volumio[12672]: Starting albumart workers Jan 25 22:06:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 25 22:06:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:25 volumio volumio[12670]: Starting albumart workers Jan 25 22:06:25 volumio go-librespot[12766]: go-librespot daemon starting... Jan 25 22:06:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:25 volumio volumio[12671]: Starting albumart workers Jan 25 22:06:25 volumio go-librespot[12767]: time="2026-01-25T22:06:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:25 volumio volumio[12545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:06:25 volumio volumio[12545]: info: [1769353585522] CoreMusicLibrary::Adding element YouTube Music Jan 25 22:06:25 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:06:25 volumio volumio[12545]: Cannot find translation for source YouTube Music Jan 25 22:06:25 volumio volumio[12545]: info: Volumio Calling Home Jan 25 22:06:25 volumio sudo[12774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 25 22:06:25 volumio sudo[12774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:25 volumio go-librespot[12767]: time="2026-01-25T22:06:25+07:00" level=info msg="zeroconf server listening on port 38831" Jan 25 22:06:25 volumio sudo[12774]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:26 volumio volumio[12545]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 22:06:26 volumio volumio[12545]: info: Discovery: Found device Volumio Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::volumioGetState Jan 25 22:06:26 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:26 volumio volumio[12545]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 22:06:26 volumio volumio[12545]: info: Discovery: Found device Volumio Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::volumioGetState Jan 25 22:06:26 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:26 volumio volumio[12545]: info: MPD Permissions set Jan 25 22:06:26 volumio volumio[12545]: info: MPD Permissions set Jan 25 22:06:26 volumio volumio[12545]: info: Upmpdcli Daemon Started Jan 25 22:06:26 volumio volumio[12545]: info: Volumio called home Jan 25 22:06:26 volumio volumio[12545]: info: Spotify config file written Jan 25 22:06:26 volumio volumio[12545]: 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 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio sudo[12781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 22:06:26 volumio sudo[12781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:26 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 22:06:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 22:06:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:27 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 22:06:27 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 22:06:27 volumio volumio[12545]: info: No need to fix Spotify hosts Jan 25 22:06:27 volumio go-librespot[12800]: go-librespot daemon starting... Jan 25 22:06:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+07:00" level=debug msg="app state loaded" Jan 25 22:06:27 volumio sudo[12781]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+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 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+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 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+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 25 22:06:27 volumio go-librespot[12806]: time="2026-01-25T22:06:27+07:00" level=info msg="zeroconf server listening on port 41233" Jan 25 22:06:28 volumio go-librespot[12806]: time="2026-01-25T22:06:28+07:00" level=debug msg="obtained new client token: AABCmQKYZOl9Tbdxaz12yY1aOTet9mUTLWnFzeA7jdLuwcK/u/NKvU2oRnL9Ig+w+uy5yot49TM1DRpiSD90VJcB5cenbaGEeQtpoxGj0vU1JNOcnTA/bwXXyT4JF5Dnt7EnZNqhzBdTE2nV23GcEbSU9lY7LSY0NG++O6Zfov7/JwqEWCbDfk0LDDqyfuglvSMO8iDaPIPlZkf8TeZV8Yvu0qmiY3lnynIpA2B1wqg/YGgcZyODjZMi" Jan 25 22:06:28 volumio volumio[12545]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 22:06:28 volumio volumio[12545]: SPOTIFY: BQAW-w2kfXWhiOW4dyE7xitjufkzZwtXY5vRuI64nkv-J13CQgPazqlG-1gVVZRJUeZZTGC_HurWgGDJqGGMZdZS6Mdgw6OR1i4vSn83Qm7Vo-ynAcmHezZOfbFx0zEQ2X4MjAobf24NL10vsfvvN-NHGWmbfs4TwxuxtPkKGCzw0Tbx0VWdMJH6q1XnaWL3-yzE74FJnsXA8X0liWXdH93BQyrHccwDnHUxT5SWbuidG5L8sHDtC60_B_bo-IxWvnLATO-wY8jLy2inOJyGg0C97wqmvBcDDfRFi9AhK0WIkzOqiYmZKjCa Jan 25 22:06:28 volumio volumio[12545]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 22:06:28 volumio volumio[12545]: info: New Spotify access token = BQAW-w2kfXWhiOW4dyE7xitjufkzZwtXY5vRuI64nkv-J13CQgPazqlG-1gVVZRJUeZZTGC_HurWgGDJqGGMZdZS6Mdgw6OR1i4vSn83Qm7Vo-ynAcmHezZOfbFx0zEQ2X4MjAobf24NL10vsfvvN-NHGWmbfs4TwxuxtPkKGCzw0Tbx0VWdMJH6q1XnaWL3-yzE74FJnsXA8X0liWXdH93BQyrHccwDnHUxT5SWbuidG5L8sHDtC60_B_bo-IxWvnLATO-wY8jLy2inOJyGg0C97wqmvBcDDfRFi9AhK0WIkzOqiYmZKjCa Jan 25 22:06:28 volumio volumio[12545]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 22:06:28 volumio go-librespot[12806]: time="2026-01-25T22:06:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:28 volumio volumio[12545]: info: Starting Shairport Sync Jan 25 22:06:28 volumio volumio[12545]: info: Starting Shairport Sync Jan 25 22:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:28 volumio volumio[12545]: info: Starting Shairport Sync Jan 25 22:06:28 volumio sudo[12822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 22:06:28 volumio sudo[12822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:28 volumio go-librespot[12806]: time="2026-01-25T22:06:28+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:28 volumio go-librespot[12806]: time="2026-01-25T22:06:28+07:00" level=debug msg="completed challenge" Jan 25 22:06:28 volumio sudo[12824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 22:06:28 volumio sudo[12824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:28 volumio go-librespot[12806]: time="2026-01-25T22:06:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:06:28 volumio sudo[12826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 22:06:28 volumio sudo[12826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 22:06:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 22:06:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 22:06:28 volumio systemd[1]: shairport-sync.service: Consumed 2.360s CPU time. Jan 25 22:06:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 22:06:28 volumio volumio[12545]: info: CoreCommandRouter::volumioGetState Jan 25 22:06:28 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:28 volumio sudo[12822]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 22:06:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 22:06:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 22:06:28 volumio volumio[12545]: info: Shairport-Sync Started Jan 25 22:06:28 volumio volumio[12545]: Error adding Membership: Error: addMembership EINVAL Jan 25 22:06:28 volumio volumio[12545]: 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 25 22:06:28 volumio volumio[12545]: info: Spotify Successfully logged in Jan 25 22:06:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 22:06:28 volumio volumio[12545]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 22:06:28 volumio volumio[12545]: info: [1769353588863] CoreMusicLibrary::Adding element Spotify Jan 25 22:06:28 volumio volumio[12545]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 22:06:28 volumio volumio[12545]: Cannot find translation for source YouTube Music Jan 25 22:06:28 volumio volumio[12545]: Cannot find translation for source Spotify Jan 25 22:06:28 volumio sudo[12824]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:28 volumio sudo[12826]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:28 volumio volumio[12545]: info: Shairport-Sync Started Jan 25 22:06:28 volumio volumio[12545]: info: Shairport-Sync Started Jan 25 22:06:29 volumio volumio[12545]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 22:06:29 volumio volumio[12545]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 22:06:29 volumio volumio[12545]: info: VolumeController:: Volume=100 Mute =false Jan 25 22:06:29 volumio volumio[12545]: info: CoreCommandRouter::volumioGetState Jan 25 22:06:29 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:29 volumio volumio[12545]: info: CoreStateMachine::pushState Jan 25 22:06:29 volumio volumio[12545]: info: CorePlayQueue::getTrack 0 Jan 25 22:06:29 volumio volumio[12545]: info: CoreCommandRouter::volumioPushState Jan 25 22:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:31 volumio volumio[12545]: info: go-librespot daemon successfully initialized Jan 25 22:06:31 volumio mpd[12765]: 2026-01-25T22:06:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 22:06:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 22:06:31 volumio sudo[12726]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:31 volumio sudo[12736]: pam_unix(sudo:session): session closed for user root Jan 25 22:06:31 volumio volumio[12545]: error: MPD error: The expression evaluated to a falsy value: Jan 25 22:06:31 volumio volumio[12545]: assert.ok(self.idling) Jan 25 22:06:31 volumio volumio[12545]: error: The expression evaluated to a falsy value: Jan 25 22:06:31 volumio volumio[12545]: assert.ok(self.idling) Jan 25 22:06:31 volumio volumio[12545]: error: updateQueue error: null Jan 25 22:06:31 volumio volumio[12545]: info: Completed starting Core Plugins Jan 25 22:06:31 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:31 volumio volumio[12545]: info: ----- MyVolumio plugins startup ---- Jan 25 22:06:31 volumio volumio[12545]: info: ------------------------------------------- Jan 25 22:06:31 volumio volumio[12545]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 22:06:31 volumio volumio[12545]: info: MPD running with PID12765 Jan 25 22:06:31 volumio volumio[12545]: ,establishing connection Jan 25 22:06:31 volumio volumio[12545]: error: updateQueue error: null Jan 25 22:06:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 22:06:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:31 volumio go-librespot[12867]: go-librespot daemon starting... Jan 25 22:06:31 volumio go-librespot[12868]: time="2026-01-25T22:06:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:31 volumio go-librespot[12868]: time="2026-01-25T22:06:31+07:00" level=debug msg="app state loaded" Jan 25 22:06:31 volumio go-librespot[12868]: time="2026-01-25T22:06:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+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 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+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 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+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 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+07:00" level=info msg="zeroconf server listening on port 40281" Jan 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+07:00" level=debug msg="obtained new client token: AACF7GG5ZCv3BHE+GbMfFmXn+w7rjv6Sqeo6B69Vr9ldgGwAeyzDqWJqIuZwmBMO6LZKRInwz3VORZQA56mSFvvgI9Pym16Acs83bw9Vf3VwEryEAlvmVYuTURb0Bd1ZR81gm4SCz9bEnsO2OtG8RsWigHp0Ibf9lA0Ox69St86c1IP4Xqs5hezC4lksE6HvU/QBKpwjIxujdeKVZTUsK9eGZggH1nFOVweJfNs/mlqYGkhC3S5uLTxL1OA=" Jan 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:32 volumio go-librespot[12868]: time="2026-01-25T22:06:32+07:00" level=debug msg="completed challenge" Jan 25 22:06:33 volumio go-librespot[12868]: time="2026-01-25T22:06:33+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 25 22:06:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:34 volumio volumio[12545]: info: Initializing connection to go-librespot Websocket Jan 25 22:06:34 volumio volumio[12545]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 22:06:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:36 volumio go-librespot[12876]: go-librespot daemon starting... Jan 25 22:06:36 volumio volumio[12545]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+07:00" level=debug msg="app state loaded" Jan 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+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 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+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 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+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 25 22:06:36 volumio go-librespot[12877]: time="2026-01-25T22:06:36+07:00" level=info msg="zeroconf server listening on port 33567" Jan 25 22:06:37 volumio go-librespot[12877]: time="2026-01-25T22:06:37+07:00" level=debug msg="obtained new client token: AAAfj5k8/+ezs9J+ArnC1RFzQkou+5UWACUUo1NmWK6qyKAZdKvxh0z2JewSpEvz4I7Ya2Bz30TU4z6QZgYeQrTphFBXr6Tlnlm9OgaCyqeP+KyluU3CPLkQF0quhsuuyD0i8wTZYsIxtb7QjPdMNgpO+MlIMKOkkPwhKKztsgXq9AXIy5Qh1vJYku5S0zCHBNoBFQcdX9O9HjqnjtMFMhX4w/czHdAkkBRFfqprHGPcw+srr4HQDfzp" Jan 25 22:06:37 volumio go-librespot[12877]: time="2026-01-25T22:06:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 22:06:37 volumio volumio[12545]: info: Initializing connection to go-librespot Websocket Jan 25 22:06:37 volumio go-librespot[12877]: time="2026-01-25T22:06:37+07:00" level=debug msg="new websocket client" Jan 25 22:06:37 volumio volumio[12545]: info: Connection to go-librespot Websocket established Jan 25 22:06:37 volumio go-librespot[12877]: time="2026-01-25T22:06:37+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:37 volumio go-librespot[12877]: time="2026-01-25T22:06:37+07:00" level=debug msg="completed challenge" Jan 25 22:06:37 volumio go-librespot[12877]: time="2026-01-25T22:06: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 25 22:06:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 22:06:37 volumio volumio[12545]: info: Connection to go-librespot Websocket closed Jan 25 22:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:40 volumio volumio[12545]: info: Getting Spotify volume Jan 25 22:06:40 volumio volumio[12545]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 22:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 22:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 22:06:40 volumio volumio[12545]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 22:06:40 volumio volumio[12545]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 22:06:40 volumio volumio[12545]: errno: -111, Jan 25 22:06:40 volumio volumio[12545]: code: 'ECONNREFUSED', Jan 25 22:06:40 volumio volumio[12545]: syscall: 'connect', Jan 25 22:06:40 volumio volumio[12545]: address: '127.0.0.1', Jan 25 22:06:40 volumio volumio[12545]: port: 9879, Jan 25 22:06:40 volumio volumio[12545]: response: undefined Jan 25 22:06:40 volumio volumio[12545]: } Jan 25 22:06:40 volumio volumio[12545]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 22:06:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 22:06:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 22:06:40 volumio go-librespot[12896]: go-librespot daemon starting... Jan 25 22:06:40 volumio go-librespot[12911]: time="2026-01-25T22:06:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 22:06:40 volumio go-librespot[12911]: time="2026-01-25T22:06:40+07:00" level=debug msg="app state loaded" Jan 25 22:06:40 volumio go-librespot[12911]: time="2026-01-25T22:06:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06: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 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06: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 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=info msg="zeroconf server listening on port 43625" Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=debug msg="obtained new client token: AADA5fNCuezcPSADzkCQIuiYnOo7fBJtcrnRvTtGptfb/AfiHGAATShkZOs+zMHloOzJMk50DGOc6/UHKG6MbPZtkZMbAGDBZuIiPWG+j/013ufe9rmq4RtZxg/xxGb+L6tJ/HuKW6waNq8XQU2PZydZ/7d1moszxyjguZqaoAxJcSWfEuKK8i0zDlsRimP/VHMNcB326lVwm9uvSMETveiDw1FOrVJXTDlaTQZQOQVFxXoB9a2yE/vEAI0=" Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+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 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=debug msg="completed keyexchange" Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=debug msg="completed challenge" Jan 25 22:06:41 volumio sudo[12921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 22:05' Jan 25 22:06:41 volumio sudo[12921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 22:06:41 volumio go-librespot[12911]: time="2026-01-25T22:06:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 22:06:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 22:06:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"