Jan 28 11:57:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:00 volumio volumio[21591]: info: Starting Shairport Sync Jan 28 11:57:00 volumio volumio[21591]: info: Starting Shairport Sync Jan 28 11:57:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:00 volumio volumio[21591]: info: Starting Shairport Sync Jan 28 11:57:00 volumio sudo[21864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:57:00 volumio sudo[21864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:00 volumio sudo[21866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:57:00 volumio sudo[21866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:00 volumio sudo[21869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:57:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:57:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:57:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:57:00 volumio systemd[1]: shairport-sync.service: Consumed 2.240s CPU time. Jan 28 11:57:00 volumio sudo[21869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:57:00 volumio sudo[21864]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:00 volumio volumio[21591]: info: Shairport-Sync Started Jan 28 11:57:00 volumio volumio[21591]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:57:00 volumio volumio[21591]: info: CoreCommandRouter::volumioGetState Jan 28 11:57:00 volumio volumio[21591]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:57:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:57:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:57:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:57:00 volumio sudo[21866]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:00 volumio volumio[21591]: 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 28 11:57:00 volumio volumio[21591]: info: Spotify Successfully logged in Jan 28 11:57:00 volumio sudo[21869]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:00 volumio volumio[21591]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:57:00 volumio volumio[21591]: info: [1769576220644] CoreMusicLibrary::Adding element Spotify Jan 28 11:57:00 volumio volumio[21591]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:00 volumio volumio[21591]: Cannot find translation for source YouTube Music Jan 28 11:57:00 volumio volumio[21591]: Cannot find translation for source Spotify Jan 28 11:57:00 volumio volumio[21591]: info: Shairport-Sync Started Jan 28 11:57:00 volumio volumio[21591]: info: Shairport-Sync Started Jan 28 11:57:01 volumio volumio[21591]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:57:01 volumio volumio[21591]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:57:01 volumio volumio[21591]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:57:01 volumio volumio[21591]: info: CoreCommandRouter::volumioGetState Jan 28 11:57:01 volumio volumio[21591]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:01 volumio volumio[21591]: info: CoreStateMachine::pushState Jan 28 11:57:01 volumio volumio[21591]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:01 volumio volumio[21591]: info: CoreCommandRouter::volumioPushState Jan 28 11:57:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:02 volumio volumio[21591]: info: go-librespot daemon successfully initialized Jan 28 11:57:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 28 11:57:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:03 volumio go-librespot[21916]: go-librespot daemon starting... Jan 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:03 volumio mpd[21815]: 2026-01-28T11:57:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+07:00" level=debug msg="app state loaded" Jan 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:03 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:57:03 volumio sudo[21776]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:03 volumio sudo[21788]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:03 volumio volumio[21591]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:57:03 volumio volumio[21591]: assert.ok(self.idling) Jan 28 11:57:03 volumio volumio[21591]: error: The expression evaluated to a falsy value: Jan 28 11:57:03 volumio volumio[21591]: assert.ok(self.idling) Jan 28 11:57:03 volumio volumio[21591]: info: MPD running with PID21815 Jan 28 11:57:03 volumio volumio[21591]: ,establishing connection Jan 28 11:57:03 volumio volumio[21591]: error: updateQueue error: null Jan 28 11:57:03 volumio volumio[21591]: info: Completed starting Core Plugins Jan 28 11:57:03 volumio volumio[21591]: info: ------------------------------------------- Jan 28 11:57:03 volumio volumio[21591]: info: ----- MyVolumio plugins startup ---- Jan 28 11:57:03 volumio volumio[21591]: info: ------------------------------------------- Jan 28 11:57:03 volumio volumio[21591]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:57:03 volumio volumio[21591]: error: updateQueue error: null Jan 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+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 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+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 28 11:57:03 volumio go-librespot[21917]: time="2026-01-28T11:57:03+07:00" level=info msg="zeroconf server listening on port 33219" Jan 28 11:57:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:04 volumio go-librespot[21917]: time="2026-01-28T11:57:04+07:00" level=debug msg="obtained new client token: AACYPwgLJDXStVCox8I/sB6Y0gGH6BjB1o9ItHrDwT+oOGomh1XT91YNwdut/VkW7HNzcC9nDK56Gh1upWRcDFBlkvUEPEEcuiC19VskNX0wM7lXDoE1RRVxy/S3wC1QmCka69Kh/lb6G6nwY89S0+RovHqwU2k+eStK8OjAIg2ZINsRrIjj7YmVl05rh5bijg767MsVEnSoR/LNs4Bg4Nj//x3PEDnNPE8mxQgOiagHaCPj7H3unOWm" Jan 28 11:57:04 volumio go-librespot[21917]: time="2026-01-28T11:57:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:04 volumio go-librespot[21917]: time="2026-01-28T11:57:04+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:04 volumio go-librespot[21917]: time="2026-01-28T11:57:04+07:00" level=debug msg="completed challenge" Jan 28 11:57:04 volumio go-librespot[21917]: time="2026-01-28T11:57:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:05 volumio volumio[21591]: info: Initializing connection to go-librespot Websocket Jan 28 11:57:05 volumio volumio[21591]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:57:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 28 11:57:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:07 volumio go-librespot[21929]: go-librespot daemon starting... Jan 28 11:57:07 volumio go-librespot[21930]: time="2026-01-28T11:57:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:07 volumio go-librespot[21930]: time="2026-01-28T11:57:07+07:00" level=debug msg="app state loaded" Jan 28 11:57:07 volumio go-librespot[21930]: time="2026-01-28T11:57:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=info msg="zeroconf server listening on port 44487" Jan 28 11:57:08 volumio volumio[21591]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="obtained new client token: AAB+vJdt5yAW/cJ/sQHo4apLY5ri8PSodW1XeE59Ljy9S/5V6v9aFRRYnlDWAHKPoeKco3BF5WF+7uViV4VPmFL10ulidBpR9tVnczL0dcJLt4qz/TgxmM+avd9bz/f71obUeXfcznT4sqOWb94gdn3WKX2uADsocWwW19k6PQlcjf6VQWfpWt/wL71R14Eb/TDSqVaavC7mlv6OJviF7Lr2a/8/7CXkrlFJ1ThYFwEb5DXGEq2b6Gszsk8=" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="completed challenge" Jan 28 11:57:08 volumio volumio[21591]: info: Initializing connection to go-librespot Websocket Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57:08+07:00" level=debug msg="new websocket client" Jan 28 11:57:08 volumio go-librespot[21930]: time="2026-01-28T11:57: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 28 11:57:08 volumio volumio[21591]: info: Connection to go-librespot Websocket established Jan 28 11:57:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:08 volumio volumio[21591]: info: Connection to go-librespot Websocket closed Jan 28 11:57:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 28 11:57:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:12 volumio volumio[21591]: info: Getting Spotify volume Jan 28 11:57:12 volumio volumio[21591]: info: Initializing connection to go-librespot Websocket Jan 28 11:57:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:12 volumio volumio[21591]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:57:12 volumio volumio[21591]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:57:12 volumio volumio[21591]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 11:57:12 volumio volumio[21591]: errno: -111, Jan 28 11:57:12 volumio volumio[21591]: code: 'ECONNREFUSED', Jan 28 11:57:12 volumio volumio[21591]: syscall: 'connect', Jan 28 11:57:12 volumio volumio[21591]: address: '127.0.0.1', Jan 28 11:57:12 volumio volumio[21591]: port: 9879, Jan 28 11:57:12 volumio volumio[21591]: response: undefined Jan 28 11:57:12 volumio volumio[21591]: } Jan 28 11:57:12 volumio volumio[21591]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:57:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:12 volumio go-librespot[21937]: go-librespot daemon starting... Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+07:00" level=debug msg="app state loaded" Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+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 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+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 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+07:00" level=info msg="zeroconf server listening on port 44557" Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+07:00" level=debug msg="obtained new client token: AADrwwvtOiyfVgF040H7kNA0Fwnz5ka1wdR5nmCVvggdSdbaMuQQDaO8xziOgztEuU4IEsIGLKXBADEZRD6Wyn+NkVcKV1sIY5tJrPNlS1xyy5lHxtLfnsobDkEDz8iLUsR75mWK1T3JyoQhOeAGvorhM0KJtkGWsX/pPmXonbFXD4FixLEG31lbkpfqYumWsUfy3zzEUqJ6DrrwGgcG/0cJ+pe5ca+g55B5qnoDtzfJOxsi2D+ioYjbIIU=" Jan 28 11:57:12 volumio go-librespot[21939]: time="2026-01-28T11:57:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:13 volumio go-librespot[21939]: time="2026-01-28T11:57:13+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:13 volumio go-librespot[21939]: time="2026-01-28T11:57:13+07:00" level=debug msg="completed challenge" Jan 28 11:57:13 volumio go-librespot[21939]: time="2026-01-28T11:57:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:13 volumio sudo[21973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:56' Jan 28 11:57:13 volumio sudo[21973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:13 volumio sudo[21973]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:13 volumio volumio-remote-updater[628]: [2026-01-28 11:57:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:57:14 volumio volumio-remote-updater[628]: [2026-01-28 11:57:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:57:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:57:14 volumio systemd[1]: volumio.service: Consumed 53.179s CPU time. Jan 28 11:57:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:57:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:57:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10080. Jan 28 11:57:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:57:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:57:14 volumio systemd[1]: volumio.service: Consumed 53.179s CPU time. Jan 28 11:57:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:57:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:57:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 28 11:57:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:16 volumio go-librespot[22002]: go-librespot daemon starting... Jan 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57:16+07:00" level=debug msg="app state loaded" Jan 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57: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 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57: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 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57: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 28 11:57:16 volumio go-librespot[22003]: time="2026-01-28T11:57:16+07:00" level=info msg="zeroconf server listening on port 35033" Jan 28 11:57:17 volumio go-librespot[22003]: time="2026-01-28T11:57:17+07:00" level=debug msg="obtained new client token: AAAqY+12n1kaZAM3sbSpbebOcoAvzM7e0mjjHx/4p22ZrWKNab/p1OyTZrSsm6TWotEQMK8OsPo8rRuUb2IEL0VtKmJeEOX5nXBl4HTUgx1FWjbVwpZUCiMuOw8HMfTiewgZH7XokwwVI03N6p/zZ/IIfgJ3P3UjJYf3EQd1hH8Q7LZdulqBTLDf9c6EX8hAUKuaUWa2UBSCHv6I2rAZbLVY0EUwM42gSOigaJGFbM07CMt1sXvKItMy" Jan 28 11:57:17 volumio go-librespot[22003]: time="2026-01-28T11:57:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:17 volumio go-librespot[22003]: time="2026-01-28T11:57:17+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:17 volumio go-librespot[22003]: time="2026-01-28T11:57:17+07:00" level=debug msg="completed challenge" Jan 28 11:57:17 volumio go-librespot[22003]: time="2026-01-28T11:57: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 28 11:57:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:17 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:17 volumio volumio[21987]: info: ----- Volumio3 ---- Jan 28 11:57:17 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:17 volumio volumio[21987]: info: ----- System startup ---- Jan 28 11:57:17 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:19 volumio volumio-remote-updater[628]: [2026-01-28 11:57:18] [connect] Successful connection Jan 28 11:57:19 volumio volumio[21987]: info: MYVOLUMIO Environment detected Jan 28 11:57:19 volumio volumio[21987]: info: Plugin folders cleanup Jan 28 11:57:19 volumio volumio[21987]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category audio_interface Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category miscellanea Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category music_service Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category plugins.json Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category system_controller Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category user_interface Jan 28 11:57:19 volumio volumio[21987]: info: Scanning into folder /data/plugins/ Jan 28 11:57:19 volumio volumio[21987]: info: Scanning category music_service Jan 28 11:57:19 volumio volumio[21987]: info: Plugin folders cleanup completed Jan 28 11:57:19 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:19 volumio volumio[21987]: info: ----- Core plugins startup ---- Jan 28 11:57:19 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:19 volumio volumio[21987]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:57:19 volumio volumio[21987]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:57:19 volumio volumio[21987]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:57:19 volumio volumio[21987]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:57:19 volumio volumio[21987]: info: Loading plugins from folder /data/plugins/ Jan 28 11:57:19 volumio volumio[21987]: info: Loading plugin "system"... Jan 28 11:57:19 volumio volumio[21987]: info: Loading plugin "appearance"... Jan 28 11:57:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 28 11:57:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:20 volumio go-librespot[22025]: go-librespot daemon starting... Jan 28 11:57:20 volumio go-librespot[22026]: time="2026-01-28T11:57:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:20 volumio go-librespot[22026]: time="2026-01-28T11:57:20+07:00" level=debug msg="app state loaded" Jan 28 11:57:20 volumio go-librespot[22026]: time="2026-01-28T11:57:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57: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-gew4.spotify.com:80]" Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+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 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+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 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+07:00" level=info msg="zeroconf server listening on port 38261" Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+07:00" level=debug msg="obtained new client token: AAArPAFZdpgcmoCt+7v9pV7pOrC7rOdT8mliRER/kOJ2t5N6Lq3xqBEo8xQWoRuT0sjZHBU9VWuXWjcoz+UsWCOVGM3iW4qQTdVVmI8Goii8Me2TVg4Nj0WYjhMsbJeeKH6DcpCvbnmwmswnZmogzDcz8HOy4yeGaBA67e3QhilS3NNw5PSHx3Gao4K0qoxqxRPsPhICapTfJvIAFrvlg4kXnIXqnDh8iqL3NJjckT+CF8X0Ra9Ed6/U" Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "network"... Jan 28 11:57:21 volumio volumio[21987]: info: Refreshing Cached IP Addresses Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:21 volumio sudo[22035]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:57:21 volumio sudo[22035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "services"... Jan 28 11:57:21 volumio sudo[22037]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:57:21 volumio sudo[22035]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:21 volumio sudo[22037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "alsa_controller"... Jan 28 11:57:21 volumio sudo[22037]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:21 volumio sudo[22041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:57:21 volumio sudo[22041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57:21+07:00" level=debug msg="completed challenge" Jan 28 11:57:21 volumio go-librespot[22026]: time="2026-01-28T11:57: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 28 11:57:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:21 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "wizard"... Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "networkfs"... Jan 28 11:57:21 volumio volumio[21987]: info: Starting Udev Watcher for removable devices Jan 28 11:57:21 volumio volumio[21987]: info: Ignoring mount for partition: boot Jan 28 11:57:21 volumio volumio[21987]: info: Ignoring mount for partition: volumio Jan 28 11:57:21 volumio volumio[21987]: info: Ignoring mount for partition: volumio_data Jan 28 11:57:21 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "upnp"... Jan 28 11:57:21 volumio volumio[21987]: info: [1769576241786] Starting Upmpd Daemon Jan 28 11:57:21 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "my_music"... Jan 28 11:57:21 volumio volumio[21987]: info: Loading plugin "mpd"... Jan 28 11:57:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:22 volumio volumio[21987]: info: Loading plugin "upnp_browser"... Jan 28 11:57:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:24 volumio sudo[22041]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 28 11:57:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:24 volumio go-librespot[22068]: go-librespot daemon starting... Jan 28 11:57:24 volumio go-librespot[22069]: time="2026-01-28T11:57:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:24 volumio go-librespot[22069]: time="2026-01-28T11:57:24+07:00" level=debug msg="app state loaded" Jan 28 11:57:24 volumio go-librespot[22069]: time="2026-01-28T11:57:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:25 volumio volumio[21987]: info: Starting UPNP Browser Jan 28 11:57:25 volumio volumio[21987]: info: Loading plugin "alarm-clock"... Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=info msg="zeroconf server listening on port 44759" Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="obtained new client token: AABL6XVc7w8d2P/uIJFPsm6PiArUz5E6GvKKiL5C6NFincr3DC06dgvEIXJCywuBxYDek5+O1CsNMHpBScTchGy2QYtKsTf0egaMlMdA8pwyhmW1uBYGiZgDE3OMoGFyvrPAYLmX6/kQOIyIIECkODWy7O0cbLtbRdsZIQOSJcZksT3adBtrwDg/uwMngI5FEb9uSJty69qITLgclQb5KQx0imcUvOWzFTCqruLaKnjvojmVzDE0rVFkd6k=" Jan 28 11:57:25 volumio volumio[21987]: info: Loading plugin "airplay_emulation"... Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:25 volumio volumio[21987]: info: Starting Shairport Sync Jan 28 11:57:25 volumio volumio[21987]: info: Loading plugin "last_100"... Jan 28 11:57:25 volumio volumio[21987]: info: Loading plugin "webradio"... Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=debug msg="completed challenge" Jan 28 11:57:25 volumio go-librespot[22069]: time="2026-01-28T11:57:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:25 volumio volumio[21987]: info: Loading plugin "i2s_dacs"... Jan 28 11:57:25 volumio volumio[21987]: info: Loading plugin "volumiodiscovery"... Jan 28 11:57:26 volumio volumio[21987]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:57:26 volumio volumio[21987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:57:26 volumio volumio[21987]: *** WARNING *** For more information see Jan 28 11:57:26 volumio volumio[21987]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:57:26 volumio volumio[21987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:57:26 volumio volumio[21987]: *** WARNING *** For more information see Jan 28 11:57:26 volumio node[21987]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:57:26 volumio node[21987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:57:26 volumio node[21987]: *** WARNING *** For more information see Jan 28 11:57:26 volumio node[21987]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:57:26 volumio node[21987]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:57:26 volumio node[21987]: *** WARNING *** For more information see Jan 28 11:57:26 volumio volumio[21987]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:57:26 volumio volumio[21987]: info: Discovery: Started advertising with name: Volumio Jan 28 11:57:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:26 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:57:26 volumio volumio[21987]: info: Loading plugin "spop"... Jan 28 11:57:27 volumio volumio[21987]: info: Loading plugin "ytcr"... Jan 28 11:57:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 28 11:57:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:29 volumio go-librespot[22079]: go-librespot daemon starting... Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=debug msg="app state loaded" Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+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 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+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 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=info msg="zeroconf server listening on port 40713" Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=debug msg="obtained new client token: AAA4FtUgCwbpsRZ8UItmRHhA+jjLdNvO1eEwsic/l7nqAs8UMR3NdJwNoJhdOj8zM256IG00d8dBfC+JNyt8ko88sOv3/QdYZHygzVQYyQHoQ8dkNPKYxylO1cPsmYfHLChDWkeWUD+tbck2GghNsE08C4HQaM89k99TgUYuCcazLyXc8fvliNrb9ULItjQ1RgGMao/5ndn/GM9nFNgIAwZwTnSHn7tInLAj4aL8NhG7n+FGJjawWZH22W4=" Jan 28 11:57:29 volumio go-librespot[22080]: time="2026-01-28T11:57:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:30 volumio go-librespot[22080]: time="2026-01-28T11:57:30+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:30 volumio go-librespot[22080]: time="2026-01-28T11:57:30+07:00" level=debug msg="completed challenge" Jan 28 11:57:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:30 volumio go-librespot[22080]: time="2026-01-28T11:57: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 28 11:57:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:30 volumio volumio[21987]: info: Loading plugin "ytmusic"... Jan 28 11:57:31 volumio volumio-remote-updater[628]: [2026-01-28 11:57:31] [connect] Successful connection Jan 28 11:57:31 volumio volumio[21987]: info: Loading plugin "outputs"... Jan 28 11:57:31 volumio volumio[21987]: info: Loading plugin "albumart"... Jan 28 11:57:31 volumio volumio[21987]: info: Plugin example_plugin is not enabled Jan 28 11:57:31 volumio volumio[21987]: info: Loading plugin "inputs"... Jan 28 11:57:31 volumio volumio[21987]: info: Loading plugin "updater_comm"... Jan 28 11:57:31 volumio volumio[21987]: info: Plugin mpdemulation is not enabled Jan 28 11:57:31 volumio volumio[21987]: info: Loading plugin "rest_api"... Jan 28 11:57:31 volumio volumio[21987]: info: Loading plugin "websocket"... Jan 28 11:57:32 volumio volumio[21987]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:57:32 volumio volumio[21987]: info: Loading plugin "RoonBridge"... Jan 28 11:57:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:32 volumio volumio[21987]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:57:32 volumio volumio[21987]: info: Loading i18n strings for locale en Jan 28 11:57:32 volumio volumio[21987]: Updating browse sources language Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:32 volumio volumio[22101]: Forking 3 albumart workers Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::initPlayerControls Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:57:32 volumio volumio[21987]: Express server listening on port 3000 Jan 28 11:57:32 volumio volumio[21987]: [Metrics] WebUI: 16s 87.19ms Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::resetVolumioState Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::getcurrentVolume Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:57:33 volumio sudo[22146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:57:33 volumio sudo[22146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:33 volumio sudo[22146]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 28 11:57:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:33 volumio sudo[22148]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:57:33 volumio sudo[22148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:33 volumio sudo[22148]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:33 volumio volumio[21987]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:57:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:33 volumio go-librespot[22150]: go-librespot daemon starting... Jan 28 11:57:33 volumio go-librespot[22152]: time="2026-01-28T11:57:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:33 volumio go-librespot[22152]: time="2026-01-28T11:57:33+07:00" level=debug msg="app state loaded" Jan 28 11:57:33 volumio go-librespot[22152]: time="2026-01-28T11:57:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:33 volumio volumio-remote-updater[628]: [2026-01-28 11:57:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769576251 101 Jan 28 11:57:33 volumio volumio[21987]: 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 28 11:57:33 volumio volumio[21987]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::pushState Jan 28 11:57:33 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::volumioPushState Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::updateTrackBlock Jan 28 11:57:33 volumio volumio[21987]: info: CorePlayQueue::getTrackBlock Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:33 volumio volumio[21987]: info: Reloading queue from file Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::pushState Jan 28 11:57:33 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::volumioPushState Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::setRandom null Jan 28 11:57:33 volumio volumio[21987]: info: CoreStateMachine::pushState Jan 28 11:57:33 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:33 volumio volumio[21987]: info: CoreCommandRouter::volumioPushState Jan 28 11:57:34 volumio volumio[21987]: info: Setting Device type: Raspberry PI Jan 28 11:57:34 volumio volumio[21987]: info: Completed loading Core Plugins Jan 28 11:57:34 volumio volumio[21987]: info: Preparing to generate the ALSA configuration file Jan 28 11:57:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+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 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+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 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+07:00" level=info msg="zeroconf server listening on port 34391" Jan 28 11:57:34 volumio sudo[22169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:57:34 volumio sudo[22169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:34 volumio volumio[21987]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:57:34 volumio volumio[21987]: info: CoreStateMachine::pushState Jan 28 11:57:34 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::volumioPushState Jan 28 11:57:34 volumio volumio[21987]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:57:34 volumio volumio[21987]: info: Output device has changed, restarting MPD Jan 28 11:57:34 volumio sudo[22169]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:34 volumio volumio[21987]: info: Output device has changed, restarting Shairport Sync Jan 28 11:57:34 volumio sudo[22173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:57:34 volumio sudo[22173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:34 volumio sudo[22173]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+07:00" level=debug msg="obtained new client token: AACeh6BDE3fF1GG1j/M5FVJp43RxQEw48Pv+3lsR1CTT9FMamEGCm9V0t+LGzzFW6RhZQKUZgukTaOVHGUTxM52XtdyuRVRufycuenggIaNS/shVbKerF+bd/RniHPDdcp93b+HU92zBjRTVqAnWFKvOJXqnpDR1tY52PGdO8DEhFFl37/8+Af90/bOpeZ4yCA9Hip8QbYpJ246fQMKY/Cb+ds0GHwbZXBWAnAK4xsizAssWQfFlDg3DOkQ=" Jan 28 11:57:34 volumio sudo[22175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:57:34 volumio sudo[22175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:34 volumio volumio[21987]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:57:34 volumio volumio[21987]: info: ___________ START PLUGINS ___________ Jan 28 11:57:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:34 volumio volumio[21987]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:57:34 volumio volumio[21987]: info: Creating MPD Configuration file Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:57:34 volumio volumio[21987]: info: [1769576254754] CoreMusicLibrary::Adding element Media Servers Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:34 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:57:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:57:34 volumio systemd[1]: mpd.service: Consumed 7.459s CPU time. Jan 28 11:57:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:57:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:57:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+07:00" level=debug msg="completed challenge" Jan 28 11:57:34 volumio volumio[21987]: info: UPNP Browser: Client initialized successfully Jan 28 11:57:34 volumio sudo[22185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:57:34 volumio sudo[22187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:57:34 volumio sudo[22185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:34 volumio sudo[22187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:34 volumio sudo[22185]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:57:34 volumio go-librespot[22152]: time="2026-01-28T11:57:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:57:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:34 volumio volumio[21987]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:34 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:34 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:57:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:57:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:57:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:57:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:57:35 volumio volumio[21987]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:57:35 volumio volumio[21987]: info: [1769576255017] CoreMusicLibrary::Adding element Last_100 Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:57:35 volumio volumio[21987]: info: [1769576255028] CoreMusicLibrary::Adding element Webradio Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:57:35 volumio volumio[21987]: info: Initializing BBC Radios Jan 28 11:57:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:57:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:35 volumio volumio[21987]: info: Creating Spotify config file Jan 28 11:57:35 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:35 volumio sudo[22206]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:57:35 volumio sudo[22206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:57:35 volumio sudo[22206]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:36 volumio volumio[22112]: Starting albumart workers Jan 28 11:57:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:36 volumio volumio[22111]: Starting albumart workers Jan 28 11:57:36 volumio volumio[22113]: Starting albumart workers Jan 28 11:57:36 volumio volumio[21987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:57:36 volumio volumio[21987]: info: [1769576256585] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:57:36 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:36 volumio volumio[21987]: Cannot find translation for source YouTube Music Jan 28 11:57:36 volumio volumio[21987]: info: Volumio Calling Home Jan 28 11:57:36 volumio sudo[22218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:57:36 volumio sudo[22218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:36 volumio sudo[22218]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:37 volumio volumio[21987]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:57:37 volumio volumio[21987]: info: Discovery: Found device Volumio Jan 28 11:57:37 volumio volumio[21987]: info: CoreCommandRouter::volumioGetState Jan 28 11:57:37 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:37 volumio volumio[21987]: info: MPD Permissions set Jan 28 11:57:37 volumio volumio[21987]: info: MPD Permissions set Jan 28 11:57:37 volumio volumio[21987]: info: Upmpdcli Daemon Started Jan 28 11:57:37 volumio volumio[21987]: info: Volumio called home Jan 28 11:57:37 volumio volumio[21987]: info: Spotify config file written Jan 28 11:57:37 volumio sudo[22225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:57:37 volumio sudo[22225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 28 11:57:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:38 volumio go-librespot[22229]: go-librespot daemon starting... Jan 28 11:57:38 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:57:38 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:57:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:38 volumio go-librespot[22244]: go-librespot daemon starting... Jan 28 11:57:38 volumio sudo[22225]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+07:00" level=debug msg="app state loaded" Jan 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:38 volumio volumio[21987]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:57:38 volumio volumio[21987]: info: Discovery: Found device Volumio Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::volumioGetState Jan 28 11:57:38 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:38 volumio volumio[21987]: 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 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:57:38 volumio volumio[21987]: info: No need to fix Spotify hosts Jan 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+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 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+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 28 11:57:38 volumio go-librespot[22246]: time="2026-01-28T11:57:38+07:00" level=info msg="zeroconf server listening on port 40249" Jan 28 11:57:39 volumio go-librespot[22246]: time="2026-01-28T11:57:39+07:00" level=debug msg="obtained new client token: AACwnwAHoGZt7EV5R7nMWT0aAzaHA74i91xePqZuubdEZ/XTUDC/Xo0eAJXFMdGf3AIaBG55kHwe7cIWkvgp3fyscbq0OZliOyhc2yBkYasaBF0kJ3Y5a9hjCq0c8iK0Gjtkwz6LBLUm1u/q7mwiaTi7e2rAJxzQ4dUHiQUNXfEeU2hMqjBWpI0TAT9/HW9HQlPrTpdN7TWLlp1fZpPDI8y70yTfGAX6p29kPAAawywucNHBn8Yu8vqU" Jan 28 11:57:39 volumio volumio[21987]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:57:39 volumio volumio[21987]: SPOTIFY: BQCU3_5n5Ss2fv6EZ4rXRjM0K9MAHEf5uTr_aoJ-JHGDSTBIOKS9OQ4b2fPjnp8fVIWTEesnLU9Gts_rwDlrEaQaMwRGtEVxYlZdaPdQwz9kYvWRrpWWDexmCHhFkbQMQCHMzJz5nUF75-z2abM-9HLGDmU627RmNssTatGFKYX0xbNYLHHdjhdLbUHFebFGXzLxDU2igICen9armrrPsbt3UHedb3Ak48Zbr1YslSYdTZjcrtE6yzLQlUva-V8DwUR84BnXVmKT9zzn7rMKBQymPqVoRW9LWGkJoXNusqdlg-YQZeu9k0Y5 Jan 28 11:57:39 volumio volumio[21987]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:57:39 volumio volumio[21987]: info: New Spotify access token = BQCU3_5n5Ss2fv6EZ4rXRjM0K9MAHEf5uTr_aoJ-JHGDSTBIOKS9OQ4b2fPjnp8fVIWTEesnLU9Gts_rwDlrEaQaMwRGtEVxYlZdaPdQwz9kYvWRrpWWDexmCHhFkbQMQCHMzJz5nUF75-z2abM-9HLGDmU627RmNssTatGFKYX0xbNYLHHdjhdLbUHFebFGXzLxDU2igICen9armrrPsbt3UHedb3Ak48Zbr1YslSYdTZjcrtE6yzLQlUva-V8DwUR84BnXVmKT9zzn7rMKBQymPqVoRW9LWGkJoXNusqdlg-YQZeu9k0Y5 Jan 28 11:57:39 volumio volumio[21987]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:57:39 volumio go-librespot[22246]: time="2026-01-28T11:57:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:39 volumio volumio[21987]: info: Starting Shairport Sync Jan 28 11:57:39 volumio volumio[21987]: info: Starting Shairport Sync Jan 28 11:57:39 volumio volumio[21987]: info: Starting Shairport Sync Jan 28 11:57:39 volumio sudo[22266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:57:39 volumio sudo[22266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:39 volumio go-librespot[22246]: time="2026-01-28T11:57:39+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:39 volumio go-librespot[22246]: time="2026-01-28T11:57:39+07:00" level=debug msg="completed challenge" Jan 28 11:57:39 volumio sudo[22268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:57:39 volumio sudo[22268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:39 volumio sudo[22270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:57:39 volumio sudo[22270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:39 volumio go-librespot[22246]: time="2026-01-28T11:57:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:57:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:57:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:57:39 volumio systemd[1]: shairport-sync.service: Consumed 2.210s CPU time. Jan 28 11:57:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:57:39 volumio sudo[22270]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:39 volumio sudo[22266]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:39 volumio sudo[22268]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:39 volumio volumio[21987]: info: Shairport-Sync Started Jan 28 11:57:39 volumio volumio[21987]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:57:39 volumio volumio[21987]: info: Shairport-Sync Started Jan 28 11:57:39 volumio volumio[21987]: info: Shairport-Sync Started Jan 28 11:57:40 volumio volumio[21987]: info: CoreCommandRouter::volumioGetState Jan 28 11:57:40 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:40 volumio volumio[21987]: 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 28 11:57:40 volumio volumio[21987]: info: Spotify Successfully logged in Jan 28 11:57:40 volumio volumio[21987]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:57:40 volumio volumio[21987]: info: [1769576260283] CoreMusicLibrary::Adding element Spotify Jan 28 11:57:40 volumio volumio[21987]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:57:40 volumio volumio[21987]: Cannot find translation for source YouTube Music Jan 28 11:57:40 volumio volumio[21987]: Cannot find translation for source Spotify Jan 28 11:57:40 volumio volumio[21987]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:57:40 volumio volumio[21987]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:57:41 volumio volumio[21987]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:57:41 volumio volumio[21987]: info: CoreCommandRouter::volumioGetState Jan 28 11:57:41 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:41 volumio volumio[21987]: info: CoreStateMachine::pushState Jan 28 11:57:41 volumio volumio[21987]: info: CorePlayQueue::getTrack 0 Jan 28 11:57:41 volumio volumio[21987]: info: CoreCommandRouter::volumioPushState Jan 28 11:57:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:42 volumio volumio[21987]: info: go-librespot daemon successfully initialized Jan 28 11:57:42 volumio mpd[22216]: 2026-01-28T11:57:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:57:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:57:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:57:42 volumio sudo[22175]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:42 volumio sudo[22187]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:42 volumio go-librespot[22309]: go-librespot daemon starting... Jan 28 11:57:42 volumio go-librespot[22312]: time="2026-01-28T11:57:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:42 volumio go-librespot[22312]: time="2026-01-28T11:57:42+07:00" level=debug msg="app state loaded" Jan 28 11:57:42 volumio go-librespot[22312]: time="2026-01-28T11:57:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:42 volumio volumio[21987]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:57:42 volumio volumio[21987]: assert.ok(self.idling) Jan 28 11:57:42 volumio volumio[21987]: error: The expression evaluated to a falsy value: Jan 28 11:57:42 volumio volumio[21987]: assert.ok(self.idling) Jan 28 11:57:42 volumio volumio[21987]: error: updateQueue error: null Jan 28 11:57:42 volumio volumio[21987]: info: MPD running with PID22216 Jan 28 11:57:42 volumio volumio[21987]: ,establishing connection Jan 28 11:57:43 volumio volumio[21987]: info: Completed starting Core Plugins Jan 28 11:57:43 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:43 volumio volumio[21987]: info: ----- MyVolumio plugins startup ---- Jan 28 11:57:43 volumio volumio[21987]: info: ------------------------------------------- Jan 28 11:57:43 volumio volumio[21987]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:57:43 volumio volumio[21987]: error: updateQueue error: null Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+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 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+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 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=info msg="zeroconf server listening on port 40989" Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=debug msg="obtained new client token: AAA0cRY+evNEiP+ppm86AN8NE4bkK3Fr9DxCfLj1EwHO+swFw0q3fzc/LfxTSNN2T+ARwaR3bXP3vLcAi0GxxhQ4lGdfB5rLrIBte+mYO+0ZzA2b27JXjxpsg5IRyS+elCFCkVQmPynrWrX+SrNNYRzFFY+iUuyfPvcDugxODibjQRPiF6VoLdAYnVuH5NYpahJnSA8B5XK6DycF7rYOZQL2rCpuyub4v4lBbswKfL2tYlBqu4iCCcHiMSg=" Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=debug msg="completed challenge" Jan 28 11:57:43 volumio go-librespot[22312]: time="2026-01-28T11:57:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:45 volumio volumio[21987]: info: Initializing connection to go-librespot Websocket Jan 28 11:57:45 volumio volumio[21987]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:57:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:57:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:47 volumio go-librespot[22319]: go-librespot daemon starting... Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=debug msg="app state loaded" Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:47 volumio volumio[21987]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:57:47 volumio go-librespot[22320]: time="2026-01-28T11:57:47+07:00" level=info msg="zeroconf server listening on port 41341" Jan 28 11:57:48 volumio go-librespot[22320]: time="2026-01-28T11:57:48+07:00" level=debug msg="obtained new client token: AACQL5zu9PStgiFNx3E3C8RW9nYm/fmJwGri4PCipi2WpUIrFzr8fc36e61xUpq1qdpAwGnOCeg7r1x77wODejT13dn1Wo9Uw+qI1Oba5eCtMt6DOpRqfMzUkptM0U4whJHLKFpBKAhsNQ6/iclNGGLe+d2bncNlZGD5RjSQ2xB2J2Ar/VTVIgikd5BunDApk2aJyRK+m4d6SQ/sNmDGIpwMLKyXHtDFCrWORGoiFBHAeJRBBXXqN7xN" Jan 28 11:57:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:48 volumio volumio[21987]: info: Initializing connection to go-librespot Websocket Jan 28 11:57:48 volumio go-librespot[22320]: time="2026-01-28T11:57:48+07:00" level=debug msg="new websocket client" Jan 28 11:57:48 volumio volumio[21987]: info: Connection to go-librespot Websocket established Jan 28 11:57:48 volumio go-librespot[22320]: time="2026-01-28T11:57:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:48 volumio go-librespot[22320]: time="2026-01-28T11:57:48+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:48 volumio go-librespot[22320]: time="2026-01-28T11:57:48+07:00" level=debug msg="completed challenge" Jan 28 11:57:48 volumio go-librespot[22320]: time="2026-01-28T11:57:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:48 volumio volumio[21987]: info: Connection to go-librespot Websocket closed Jan 28 11:57:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:51 volumio volumio[21987]: info: Getting Spotify volume Jan 28 11:57:51 volumio volumio[21987]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:57:51 volumio volumio[21987]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:57:51 volumio volumio[21987]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 11:57:51 volumio volumio[21987]: errno: -111, Jan 28 11:57:51 volumio volumio[21987]: code: 'ECONNREFUSED', Jan 28 11:57:51 volumio volumio[21987]: syscall: 'connect', Jan 28 11:57:51 volumio volumio[21987]: address: '127.0.0.1', Jan 28 11:57:51 volumio volumio[21987]: port: 9879, Jan 28 11:57:51 volumio volumio[21987]: response: undefined Jan 28 11:57:51 volumio volumio[21987]: } Jan 28 11:57:51 volumio volumio[21987]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:57:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 11:57:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:51 volumio go-librespot[22338]: go-librespot daemon starting... Jan 28 11:57:51 volumio go-librespot[22340]: time="2026-01-28T11:57:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:51 volumio go-librespot[22340]: time="2026-01-28T11:57:51+07:00" level=debug msg="app state loaded" Jan 28 11:57:51 volumio go-librespot[22340]: time="2026-01-28T11:57:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+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 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+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 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=info msg="zeroconf server listening on port 38331" Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=debug msg="obtained new client token: AAD2Hl85zXNUzDJFgYCCOXbqpsZ/Vhq1jPI8SMvTE/vdMgrtSZtRnYYZSvN9pm9bbV7osYHHVW1dmIh3mpZcrtEeMD3umlpzRS53bPyQ7fs53sNqpqGoDwaAfIHL4OVUEPQ+v/v2Rmj/aYYYF8fdJmUeo6hNWIOZ282+oSY+kFbgx6Veed6FW05eVgqoF0cstkmUqtOsvImur2TNSO4VoW7JIJNhIIE8Bvq9BvZXyfZMv/v0NOiUE1tzxvI=" Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=debug msg="completed challenge" Jan 28 11:57:52 volumio go-librespot[22340]: time="2026-01-28T11:57:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:52 volumio sudo[22363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:56' Jan 28 11:57:52 volumio sudo[22363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:57:53 volumio sudo[22363]: pam_unix(sudo:session): session closed for user root Jan 28 11:57:53 volumio volumio-remote-updater[628]: [2026-01-28 11:57:53] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:57:53 volumio volumio-remote-updater[628]: [2026-01-28 11:57:53] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:57:53 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:53 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:57:53 volumio systemd[1]: volumio.service: Consumed 53.096s CPU time. Jan 28 11:57:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:57:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:57:53 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10081. Jan 28 11:57:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:57:53 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:57:53 volumio systemd[1]: volumio.service: Consumed 53.096s CPU time. Jan 28 11:57:53 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:57:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:57:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 11:57:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:57:55 volumio go-librespot[22390]: go-librespot daemon starting... Jan 28 11:57:55 volumio go-librespot[22391]: time="2026-01-28T11:57:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:57:55 volumio go-librespot[22391]: time="2026-01-28T11:57:55+07:00" level=debug msg="app state loaded" Jan 28 11:57:55 volumio go-librespot[22391]: time="2026-01-28T11:57:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:57:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+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 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+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 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+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 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+07:00" level=info msg="zeroconf server listening on port 45487" Jan 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+07:00" level=debug msg="obtained new client token: AABzSap7Vt/Yde7XAxu/027IXasCFMUs64BuJp5X+aAAB0k8KP7DmSZxBhHIAAi7Fr1avdT4iNA55aE7UbYIykPRbwjqatk5nNnO64gSQRnk8yESRefEGl+inIyLjITGpwrkwu02BF7iDD8d16FQ9yRy4LCNDGaviP61dlHkheF9Zir9mHRoRizA/+rB3pJo5rTCy74FAMX0IOT21WydUanRUCYKgUF1XqOsFV/nA7VtG+TzwZKs5q9GjcE=" Jan 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+07:00" level=debug msg="completed keyexchange" Jan 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+07:00" level=debug msg="completed challenge" Jan 28 11:57:56 volumio go-librespot[22391]: time="2026-01-28T11:57:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:57:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:57:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:57:57 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:57:57 volumio volumio[22375]: info: ----- Volumio3 ---- Jan 28 11:57:57 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:57:57 volumio volumio[22375]: info: ----- System startup ---- Jan 28 11:57:57 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:57:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:57:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:57:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:57:58 volumio volumio-remote-updater[628]: [2026-01-28 11:57:58] [connect] Successful connection Jan 28 11:57:58 volumio volumio[22375]: info: MYVOLUMIO Environment detected Jan 28 11:57:58 volumio volumio[22375]: info: Plugin folders cleanup Jan 28 11:57:58 volumio volumio[22375]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category audio_interface Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category miscellanea Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category music_service Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category plugins.json Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category system_controller Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category user_interface Jan 28 11:57:58 volumio volumio[22375]: info: Scanning into folder /data/plugins/ Jan 28 11:57:58 volumio volumio[22375]: info: Scanning category music_service Jan 28 11:57:58 volumio volumio[22375]: info: Plugin folders cleanup completed Jan 28 11:57:58 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:57:58 volumio volumio[22375]: info: ----- Core plugins startup ---- Jan 28 11:57:58 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:57:58 volumio volumio[22375]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:57:58 volumio volumio[22375]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:57:58 volumio volumio[22375]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:57:58 volumio volumio[22375]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:57:58 volumio volumio[22375]: info: Loading plugins from folder /data/plugins/ Jan 28 11:57:58 volumio volumio[22375]: info: Loading plugin "system"... Jan 28 11:57:58 volumio volumio[22375]: info: Loading plugin "appearance"... Jan 28 11:57:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 11:57:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:00 volumio go-librespot[22412]: go-librespot daemon starting... Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=debug msg="app state loaded" Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+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 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+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 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=info msg="zeroconf server listening on port 44143" Jan 28 11:58:00 volumio volumio[22375]: info: Loading plugin "network"... Jan 28 11:58:00 volumio volumio[22375]: info: Refreshing Cached IP Addresses Jan 28 11:58:00 volumio sudo[22421]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:58:00 volumio sudo[22421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:00 volumio sudo[22423]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:58:00 volumio sudo[22423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:00 volumio sudo[22421]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=debug msg="obtained new client token: AAB79T/kWVBCa8fMcwiwPh7lc5bfsRcM38txX2XMqJLSok5bxQmvpd46rjuZHJLEkmbvvftZYWaHgopqlxsJhje888E14sGVGKa3IGLFJ5jKbIXDlyQRQZFRTVgiW1qQvuBKnG3Flnw2LxYFyQdBeNJvFsweUxzKC6jPsKqrCEjAtV8mmC7SOTi7UwYPsjGbSa5z+Ucs6VrYWdWfHQLsfm1GSbI/yiEFdFSbihnOynyZ7DZGZaWmxReStu8=" Jan 28 11:58:00 volumio volumio[22375]: info: Loading plugin "services"... Jan 28 11:58:00 volumio volumio[22375]: info: Loading plugin "alsa_controller"... Jan 28 11:58:00 volumio sudo[22423]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:00 volumio sudo[22432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:58:00 volumio sudo[22432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:00 volumio go-librespot[22413]: time="2026-01-28T11:58:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:00 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:58:00 volumio volumio[22375]: info: Loading plugin "wizard"... Jan 28 11:58:01 volumio volumio[22375]: info: Loading plugin "networkfs"... Jan 28 11:58:01 volumio volumio[22375]: info: Starting Udev Watcher for removable devices Jan 28 11:58:01 volumio volumio[22375]: info: Ignoring mount for partition: boot Jan 28 11:58:01 volumio volumio[22375]: info: Ignoring mount for partition: volumio Jan 28 11:58:01 volumio volumio[22375]: info: Ignoring mount for partition: volumio_data Jan 28 11:58:01 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:58:01 volumio volumio[22375]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:58:01 volumio volumio[22375]: info: Loading plugin "upnp"... Jan 28 11:58:01 volumio volumio[22375]: info: [1769576281145] Starting Upmpd Daemon Jan 28 11:58:01 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:58:01 volumio volumio[22375]: info: Loading plugin "my_music"... Jan 28 11:58:01 volumio volumio[22375]: info: Loading plugin "mpd"... Jan 28 11:58:01 volumio go-librespot[22413]: time="2026-01-28T11:58:01+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:01 volumio go-librespot[22413]: time="2026-01-28T11:58:01+07:00" level=debug msg="completed challenge" Jan 28 11:58:01 volumio volumio[22375]: info: Loading plugin "upnp_browser"... Jan 28 11:58:02 volumio go-librespot[22413]: time="2026-01-28T11:58: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 28 11:58:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:03 volumio sudo[22432]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:04 volumio volumio[22375]: info: Starting UPNP Browser Jan 28 11:58:04 volumio volumio[22375]: info: Loading plugin "alarm-clock"... Jan 28 11:58:05 volumio volumio[22375]: info: Loading plugin "airplay_emulation"... Jan 28 11:58:05 volumio volumio[22375]: info: Starting Shairport Sync Jan 28 11:58:05 volumio volumio[22375]: info: Loading plugin "last_100"... Jan 28 11:58:05 volumio volumio[22375]: info: Loading plugin "webradio"... Jan 28 11:58:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 11:58:05 volumio volumio[22375]: info: Loading plugin "i2s_dacs"... Jan 28 11:58:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:05 volumio volumio[22375]: info: Loading plugin "volumiodiscovery"... Jan 28 11:58:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:05 volumio go-librespot[22454]: go-librespot daemon starting... Jan 28 11:58:05 volumio volumio[22375]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:58:05 volumio volumio[22375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:58:05 volumio volumio[22375]: *** WARNING *** For more information see Jan 28 11:58:05 volumio volumio[22375]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:58:05 volumio volumio[22375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:58:05 volumio volumio[22375]: *** WARNING *** For more information see Jan 28 11:58:05 volumio node[22375]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:58:05 volumio node[22375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:58:05 volumio node[22375]: *** WARNING *** For more information see Jan 28 11:58:05 volumio node[22375]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:58:05 volumio node[22375]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:58:05 volumio node[22375]: *** WARNING *** For more information see Jan 28 11:58:05 volumio volumio[22375]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:58:05 volumio volumio[22375]: info: Discovery: Started advertising with name: Volumio Jan 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+07:00" level=debug msg="app state loaded" Jan 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:05 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:58:05 volumio volumio[22375]: info: Loading plugin "spop"... Jan 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+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 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+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 28 11:58:05 volumio go-librespot[22455]: time="2026-01-28T11:58:05+07:00" level=info msg="zeroconf server listening on port 39865" Jan 28 11:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:06 volumio go-librespot[22455]: time="2026-01-28T11:58:06+07:00" level=debug msg="obtained new client token: AAAbXxq3q2EAc/R4ekxT5yOwOQNzp455THv3xnkvCel9ypdDutkHC+fZGgFb9mPi9UG8fG7OQ9DlXBsfPyW40/SDMFgBRbZA0hasGrkFRPSjClUdEythLzhE6Yejidwo2B53Lx286wA7IV99l1dM4KbAQfAQchf1rVcf44Fa67uu3O+wP/cj1O0pbBcqAQ+g0TZhwRJAjnxxhMcDpTlsfOGhYP8vLTfndjPvOcCgjLFXyZJJNCWUNYhS" Jan 28 11:58:06 volumio go-librespot[22455]: time="2026-01-28T11:58:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:06 volumio go-librespot[22455]: time="2026-01-28T11:58:06+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:06 volumio go-librespot[22455]: time="2026-01-28T11:58:06+07:00" level=debug msg="completed challenge" Jan 28 11:58:06 volumio go-librespot[22455]: time="2026-01-28T11:58: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 28 11:58:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:07 volumio volumio[22375]: info: Loading plugin "ytcr"... Jan 28 11:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 11:58:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:09 volumio go-librespot[22467]: go-librespot daemon starting... Jan 28 11:58:09 volumio go-librespot[22468]: time="2026-01-28T11:58:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:09 volumio go-librespot[22468]: time="2026-01-28T11:58:09+07:00" level=debug msg="app state loaded" Jan 28 11:58:09 volumio go-librespot[22468]: time="2026-01-28T11:58:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:09 volumio volumio[22375]: info: Loading plugin "ytmusic"... Jan 28 11:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=info msg="zeroconf server listening on port 45773" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="obtained new client token: AABEnHkM2Y6RkjPc2A+ASAFS14XXZWLM2oAtX/WqA1xGv7Nq/c2MnEP59Ym9LrnLsNkKg5Pi0U7NFBRVV5lILhBVilkSAJtJ1SH1X5bH3vdiyC7TxuuGmwlkD9pvwv+t30K6XQcL/bldB9BeJamAajk4OY1FQJDlmP1axtJ+D81iAqIOW3lR/kNShtTu/ZiX1/kD/5Jhquk/6oz0SKTfWnVgpE6UblnkAo3vcfUwgw9LL0yZPNYayY8jFiE=" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:10 volumio volumio-remote-updater[628]: [2026-01-28 11:58:10] [connect] Successful connection Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+07:00" level=debug msg="completed challenge" Jan 28 11:58:10 volumio go-librespot[22468]: time="2026-01-28T11:58:10+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 28 11:58:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "outputs"... Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "albumart"... Jan 28 11:58:11 volumio volumio[22375]: info: Plugin example_plugin is not enabled Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "inputs"... Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "updater_comm"... Jan 28 11:58:11 volumio volumio[22375]: info: Plugin mpdemulation is not enabled Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "rest_api"... Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "websocket"... Jan 28 11:58:11 volumio volumio[22375]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:58:11 volumio volumio[22375]: info: Loading plugin "RoonBridge"... Jan 28 11:58:11 volumio volumio[22375]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:58:11 volumio volumio[22375]: info: Loading i18n strings for locale en Jan 28 11:58:11 volumio volumio[22375]: Updating browse sources language Jan 28 11:58:11 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:12 volumio volumio[22490]: Forking 3 albumart workers Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::initPlayerControls Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:58:12 volumio volumio[22375]: Express server listening on port 3000 Jan 28 11:58:12 volumio volumio[22375]: [Metrics] WebUI: 16s 47.58ms Jan 28 11:58:12 volumio volumio[22375]: info: CoreStateMachine::resetVolumioState Jan 28 11:58:12 volumio volumio[22375]: info: CoreStateMachine::getcurrentVolume Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:58:12 volumio sudo[22532]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:58:12 volumio sudo[22532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:12 volumio sudo[22532]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:12 volumio sudo[22535]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:58:12 volumio sudo[22535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:12 volumio sudo[22535]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:12 volumio volumio[22375]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:58:12 volumio volumio[22375]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:58:12 volumio volumio[22375]: info: CoreStateMachine::pushState Jan 28 11:58:12 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::volumioPushState Jan 28 11:58:12 volumio volumio[22375]: info: CoreStateMachine::updateTrackBlock Jan 28 11:58:12 volumio volumio[22375]: info: CorePlayQueue::getTrackBlock Jan 28 11:58:12 volumio volumio[22375]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:58:12 volumio volumio-remote-updater[628]: [2026-01-28 11:58:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769576290 101 Jan 28 11:58:13 volumio volumio[22375]: 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 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:13 volumio volumio[22375]: info: Reloading queue from file Jan 28 11:58:13 volumio volumio[22375]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:58:13 volumio volumio[22375]: info: CoreStateMachine::pushState Jan 28 11:58:13 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::volumioPushState Jan 28 11:58:13 volumio volumio[22375]: info: CoreStateMachine::setRandom null Jan 28 11:58:13 volumio volumio[22375]: info: CoreStateMachine::pushState Jan 28 11:58:13 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::volumioPushState Jan 28 11:58:13 volumio volumio[22375]: info: Setting Device type: Raspberry PI Jan 28 11:58:13 volumio volumio[22375]: info: Completed loading Core Plugins Jan 28 11:58:13 volumio volumio[22375]: info: Preparing to generate the ALSA configuration file Jan 28 11:58:13 volumio volumio[22375]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:58:13 volumio volumio[22375]: info: CoreStateMachine::pushState Jan 28 11:58:13 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::volumioPushState Jan 28 11:58:13 volumio volumio[22375]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:58:13 volumio volumio[22375]: info: Output device has changed, restarting MPD Jan 28 11:58:13 volumio volumio[22375]: info: Output device has changed, restarting Shairport Sync Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:13 volumio sudo[22551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:58:13 volumio sudo[22551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:13 volumio sudo[22553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:58:13 volumio sudo[22553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:13 volumio sudo[22555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:58:13 volumio sudo[22555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:13 volumio volumio[22375]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:58:13 volumio volumio[22375]: info: ___________ START PLUGINS ___________ Jan 28 11:58:13 volumio sudo[22553]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:13 volumio volumio[22375]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:58:13 volumio volumio[22375]: info: Creating MPD Configuration file Jan 28 11:58:13 volumio sudo[22551]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:58:13 volumio volumio[22375]: info: [1769576293692] CoreMusicLibrary::Adding element Media Servers Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:58:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:58:13 volumio sudo[22566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:58:13 volumio sudo[22566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:13 volumio volumio[22375]: info: UPNP Browser: Client initialized successfully Jan 28 11:58:13 volumio sudo[22564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:58:13 volumio sudo[22564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:13 volumio sudo[22564]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:13 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:58:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:58:13 volumio systemd[1]: mpd.service: Consumed 7.259s CPU time. Jan 28 11:58:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:58:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:58:13 volumio volumio[22375]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:13 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:58:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:58:14 volumio volumio[22375]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:58:14 volumio volumio[22375]: info: [1769576294047] CoreMusicLibrary::Adding element Last_100 Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:58:14 volumio volumio[22375]: info: [1769576294072] CoreMusicLibrary::Adding element Webradio Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:58:14 volumio volumio[22375]: info: Initializing BBC Radios Jan 28 11:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:14 volumio volumio[22375]: info: Creating Spotify config file Jan 28 11:58:14 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:14 volumio go-librespot[22593]: go-librespot daemon starting... Jan 28 11:58:14 volumio go-librespot[22594]: time="2026-01-28T11:58:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:14 volumio sudo[22579]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:58:14 volumio sudo[22579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:58:14 volumio sudo[22579]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:15 volumio go-librespot[22594]: time="2026-01-28T11:58:15+07:00" level=info msg="zeroconf server listening on port 36041" Jan 28 11:58:15 volumio volumio[22502]: Starting albumart workers Jan 28 11:58:15 volumio volumio[22375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:58:15 volumio volumio[22501]: Starting albumart workers Jan 28 11:58:15 volumio volumio[22375]: info: [1769576295595] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:58:15 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:58:15 volumio volumio[22375]: Cannot find translation for source YouTube Music Jan 28 11:58:15 volumio volumio[22375]: info: Volumio Calling Home Jan 28 11:58:15 volumio sudo[22604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:58:15 volumio sudo[22604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:15 volumio volumio[22500]: Starting albumart workers Jan 28 11:58:15 volumio sudo[22604]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:16 volumio volumio[22375]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:58:16 volumio volumio[22375]: info: Discovery: Found device Volumio Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::volumioGetState Jan 28 11:58:16 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:16 volumio volumio[22375]: info: MPD Permissions set Jan 28 11:58:16 volumio volumio[22375]: info: MPD Permissions set Jan 28 11:58:16 volumio volumio[22375]: info: Upmpdcli Daemon Started Jan 28 11:58:16 volumio volumio[22375]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:58:16 volumio volumio[22375]: info: Discovery: Found device Volumio Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::volumioGetState Jan 28 11:58:16 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:16 volumio volumio[22375]: info: Volumio called home Jan 28 11:58:16 volumio volumio[22375]: info: Spotify config file written Jan 28 11:58:16 volumio volumio[22375]: 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 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio sudo[22612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:58:16 volumio sudo[22612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:16 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:17 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:58:17 volumio volumio[22375]: info: No need to fix Spotify hosts Jan 28 11:58:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:58:17 volumio systemd[1]: go-librespot-daemon.service: Killing process 22597 (go-librespot) with signal SIGKILL. Jan 28 11:58:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:58:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:17 volumio go-librespot[22624]: go-librespot daemon starting... Jan 28 11:58:17 volumio sudo[22612]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=debug msg="app state loaded" Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:58:17 volumio go-librespot[22625]: time="2026-01-28T11:58:17+07:00" level=info msg="zeroconf server listening on port 43729" Jan 28 11:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:18 volumio go-librespot[22625]: time="2026-01-28T11:58:18+07:00" level=debug msg="obtained new client token: AACauE1e1ePXuQ2U+Gd7H3rZFdcp3fEumKkAU1nbv5G+O1OnRmbJ1aC+nWLbXig5t4jV61DJyVFXvQzS2j5FFUSYz7r3Kujv7T88BTu1NH+JAlCbCHySiZQQ1fVR7phhvW8BowddtIP/hd+doU0/Fqm/DEYzCKUa6QgLzKDl1mL94pJjvTacuw5nj5JidUtN3gOaFFN4nxArlkG7Koe557LEMR6v2Oheaqog0C06ZHy/USiGmA7bGBzm" Jan 28 11:58:18 volumio go-librespot[22625]: time="2026-01-28T11:58:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:18 volumio volumio[22375]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:58:18 volumio volumio[22375]: SPOTIFY: BQAYPaNWwhAMshuO8i-BKA3iM0lY-mV8Esshv9nO8VDfWSQZ8J7yVO6it-k1MGcgHbCf3eozgMQycqqTcpsV_1smH6PdWqnO2RUL8pajPyVCNnE0JU50PYkyjX-aFcZAZCEItGDtUf-xmc-D0Lox6rLTtTQN6lYSrqxUJOnPokvD8J85pnKdVKIjX45UrwfDEAXF6ROgtt9s9seg5ZKEMS0WC5Tpmew5A9bkBwQDCfrNGl0as-r0gEDhwfep2UJ_FvdJ132Z2dxx6QQrNBHDUPcEjqW-sagWRMBzCdokWDYQqWSz7NiUD5Qx Jan 28 11:58:18 volumio volumio[22375]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:58:18 volumio go-librespot[22625]: time="2026-01-28T11:58:18+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:18 volumio volumio[22375]: info: New Spotify access token = BQAYPaNWwhAMshuO8i-BKA3iM0lY-mV8Esshv9nO8VDfWSQZ8J7yVO6it-k1MGcgHbCf3eozgMQycqqTcpsV_1smH6PdWqnO2RUL8pajPyVCNnE0JU50PYkyjX-aFcZAZCEItGDtUf-xmc-D0Lox6rLTtTQN6lYSrqxUJOnPokvD8J85pnKdVKIjX45UrwfDEAXF6ROgtt9s9seg5ZKEMS0WC5Tpmew5A9bkBwQDCfrNGl0as-r0gEDhwfep2UJ_FvdJ132Z2dxx6QQrNBHDUPcEjqW-sagWRMBzCdokWDYQqWSz7NiUD5Qx Jan 28 11:58:18 volumio go-librespot[22625]: time="2026-01-28T11:58:18+07:00" level=debug msg="completed challenge" Jan 28 11:58:18 volumio volumio[22375]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:58:18 volumio volumio[22375]: info: Starting Shairport Sync Jan 28 11:58:18 volumio volumio[22375]: info: Starting Shairport Sync Jan 28 11:58:18 volumio go-librespot[22625]: time="2026-01-28T11:58:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:58:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:18 volumio volumio[22375]: info: Starting Shairport Sync Jan 28 11:58:18 volumio sudo[22652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:58:18 volumio sudo[22652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:18 volumio sudo[22654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:58:18 volumio sudo[22654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:18 volumio sudo[22656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:58:18 volumio sudo[22656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:58:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:58:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:58:18 volumio systemd[1]: shairport-sync.service: Consumed 2.249s CPU time. Jan 28 11:58:18 volumio volumio[22375]: info: CoreCommandRouter::volumioGetState Jan 28 11:58:18 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:58:18 volumio sudo[22652]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:18 volumio sudo[22654]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:19 volumio sudo[22656]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:19 volumio volumio[22375]: info: Shairport-Sync Started Jan 28 11:58:19 volumio volumio[22375]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:58:19 volumio volumio[22375]: info: Shairport-Sync Started Jan 28 11:58:19 volumio volumio[22375]: info: Shairport-Sync Started Jan 28 11:58:19 volumio volumio[22375]: 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 28 11:58:19 volumio volumio[22375]: info: Spotify Successfully logged in Jan 28 11:58:19 volumio volumio[22375]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:58:19 volumio volumio[22375]: info: [1769576299209] CoreMusicLibrary::Adding element Spotify Jan 28 11:58:19 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:58:19 volumio volumio[22375]: Cannot find translation for source YouTube Music Jan 28 11:58:19 volumio volumio[22375]: Cannot find translation for source Spotify Jan 28 11:58:19 volumio volumio[22375]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:58:20 volumio volumio[22375]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:20 volumio volumio[22375]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:58:20 volumio volumio[22375]: info: CoreCommandRouter::volumioGetState Jan 28 11:58:20 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:20 volumio volumio[22375]: info: CoreStateMachine::pushState Jan 28 11:58:20 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:20 volumio volumio[22375]: info: CoreCommandRouter::volumioPushState Jan 28 11:58:21 volumio volumio[22375]: info: go-librespot daemon successfully initialized Jan 28 11:58:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:58:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:21 volumio mpd[22601]: 2026-01-28T11:58:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:58:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:21 volumio go-librespot[22692]: go-librespot daemon starting... Jan 28 11:58:21 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:58:21 volumio sudo[22566]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:21 volumio sudo[22555]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:21 volumio go-librespot[22695]: time="2026-01-28T11:58:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:21 volumio go-librespot[22695]: time="2026-01-28T11:58:21+07:00" level=debug msg="app state loaded" Jan 28 11:58:21 volumio go-librespot[22695]: time="2026-01-28T11:58:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:22 volumio volumio[22375]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:58:22 volumio volumio[22375]: assert.ok(self.idling) Jan 28 11:58:22 volumio volumio[22375]: error: The expression evaluated to a falsy value: Jan 28 11:58:22 volumio volumio[22375]: assert.ok(self.idling) Jan 28 11:58:22 volumio volumio[22375]: error: updateQueue error: null Jan 28 11:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:22 volumio volumio[22375]: info: Completed starting Core Plugins Jan 28 11:58:22 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:58:22 volumio volumio[22375]: info: ----- MyVolumio plugins startup ---- Jan 28 11:58:22 volumio volumio[22375]: info: ------------------------------------------- Jan 28 11:58:22 volumio volumio[22375]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:58:22 volumio volumio[22375]: info: MPD running with PID22601 Jan 28 11:58:22 volumio volumio[22375]: ,establishing connection Jan 28 11:58:22 volumio volumio[22375]: error: updateQueue error: null Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+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 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+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 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=info msg="zeroconf server listening on port 36101" Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=debug msg="obtained new client token: AABFy0tMXmT9PXSEnZJLQEqV1yrwD7YG8GYKRGKAqoRTlkAU2TrBLw+i6fXZMkcbwcduBAZLpDcb8GGErCcqa7xuiZ6UaZ3EQ1DIDqD/Xw7h5bES1gp+KdPjAcVKEN5laXQ79Lulwpjps5doRpepo0D6QMjtclQGA9kbitEDGUJJV5ThbKysfGQLKLwGRCK72D73xLNEbsiR3DZR3Jz2c6YhjnxZeJv8YEzMMFPaaA/fLOTuBsqXYQH3BQo=" Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=debug msg="completed challenge" Jan 28 11:58:22 volumio go-librespot[22695]: time="2026-01-28T11:58:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:58:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:24 volumio volumio[22375]: info: Initializing connection to go-librespot Websocket Jan 28 11:58:24 volumio volumio[22375]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:58:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:58:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:26 volumio go-librespot[22705]: go-librespot daemon starting... Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=debug msg="app state loaded" Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+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 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+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 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=info msg="zeroconf server listening on port 34413" Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=debug msg="obtained new client token: AACTJGmWKleEIwNZHqzEGDkEw/vzMo0T6SfZhxcbeXjtuZGU3JKaQJPUmST6XDubKmoabbJb1pXrF8QSx//iQYdmaj140fbfJSc8FpFopakExEn4Y7wldJEUFIQtZPBBZdJZf6OXjwMITAmg5ccY7vY65GrEhkVRZghDh1kXYjTmOFZMh7Pw6OEOSoHF6qGxHibL8PzhMnuYLQv2x1nZL5cHZU3wnzAiBCe3rICvszQytmAyFUEpNvK8rbE=" Jan 28 11:58:26 volumio go-librespot[22706]: time="2026-01-28T11:58:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:26 volumio volumio[22375]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:58:27 volumio go-librespot[22706]: time="2026-01-28T11:58:27+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:27 volumio go-librespot[22706]: time="2026-01-28T11:58:27+07:00" level=debug msg="completed challenge" Jan 28 11:58:27 volumio go-librespot[22706]: time="2026-01-28T11:58:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:58:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:27 volumio volumio[22375]: info: Initializing connection to go-librespot Websocket Jan 28 11:58:27 volumio volumio[22375]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 11:58:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:30 volumio go-librespot[22713]: go-librespot daemon starting... Jan 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58:30+07:00" level=debug msg="app state loaded" Jan 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:30 volumio volumio[22375]: info: Initializing connection to go-librespot Websocket Jan 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58:30+07:00" level=debug msg="new websocket client" Jan 28 11:58:30 volumio volumio[22375]: info: Connection to go-librespot Websocket established Jan 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58: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 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58: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 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58: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 28 11:58:30 volumio go-librespot[22714]: time="2026-01-28T11:58:30+07:00" level=info msg="zeroconf server listening on port 41365" Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:58:30 volumio volumio[22375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:58:30 volumio volumio[22375]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:58:31 volumio volumio[22375]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:58:31 volumio go-librespot[22714]: time="2026-01-28T11:58:31+07:00" level=debug msg="obtained new client token: AADl9JEkkIX49WLkOtPmvgSaAXDrtVzWAFHJWwokcakb1d1WlrpkVAbNTFheHCkGI/MEGINE5zj/ol0dwgfnq7XxuPEQNUbLA7VsQ24o3GvXdoDkzP8xvHIi/KEmJ5hVjLnaskHa2j99T9s48JSsbY5cKu/4vjoUNFGGXekBaPOy+/7ZVsNuV+4juvXUXu2zWTQMVqOy/HnGSBpZ8Scubs2PyRE6ZaViLL8v6lNyFLBhxTeifYZXLvOk" Jan 28 11:58:31 volumio go-librespot[22714]: time="2026-01-28T11:58:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:31 volumio go-librespot[22714]: time="2026-01-28T11:58:31+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:31 volumio go-librespot[22714]: time="2026-01-28T11:58:31+07:00" level=debug msg="completed challenge" Jan 28 11:58:31 volumio go-librespot[22714]: time="2026-01-28T11:58:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:58:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:32 volumio volumio[22375]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:58:32 volumio volumio[22375]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:58:32 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:32 volumio volumio[22375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:58:32 volumio volumio[22375]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:58:32 volumio volumio[22375]: info: MyVolumio login type: Token Jan 28 11:58:33 volumio volumio[22375]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:58:33 volumio volumio[22375]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 11:58:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:58:34 volumio go-librespot[22735]: go-librespot daemon starting... Jan 28 11:58:34 volumio go-librespot[22736]: time="2026-01-28T11:58:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:58:34 volumio go-librespot[22736]: time="2026-01-28T11:58:34+07:00" level=debug msg="app state loaded" Jan 28 11:58:34 volumio go-librespot[22736]: time="2026-01-28T11:58:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:58:34 volumio volumio[22375]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:58:34 volumio volumio[22375]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:58:34 volumio volumio[22375]: info: Streaming services startup Jan 28 11:58:34 volumio volumio[22375]: info: Starting Streaming Daemon Jan 28 11:58:34 volumio volumio[22375]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:58:34 volumio sudo[22744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:58:34 volumio sudo[22744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:58:34 volumio sudo[22744]: pam_unix(sudo:session): session closed for user root Jan 28 11:58:34 volumio volumio[22375]: info: Getting Spotify volume Jan 28 11:58:34 volumio volumio[22375]: info: Connection to go-librespot Websocket closed Jan 28 11:58:34 volumio volumio[22375]: error: Cannot start Volumio Streaming Daemon Jan 28 11:58:34 volumio volumio[22375]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:58:34 volumio volumio[22375]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:58:34 volumio volumio[22375]: 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 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+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 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+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 28 11:58:35 volumio volumio[22375]: info: CoreCommandRouter::volumioGetState Jan 28 11:58:35 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+07:00" level=info msg="zeroconf server listening on port 32931" Jan 28 11:58:35 volumio volumio[22375]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 11:58:35 volumio volumio[22375]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:58:35 volumio volumio[22375]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 11:58:35 volumio volumio[22375]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:58:35 volumio volumio[22375]: info: CoreCommandRouter::volumioGetState Jan 28 11:58:35 volumio volumio[22375]: info: CorePlayQueue::getTrack 0 Jan 28 11:58:35 volumio volumio[22375]: info: Setting Spotify Volume from Volumio: 100 Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+07:00" level=debug msg="obtained new client token: AACmoC1+R/59YgrMjerwaeErHKgVERIH4++AcKGRx7wtUwSTd4TKTnE55mDULPzHhkBHIX+/o5hhU2bPzxkoB94mnqoq1wye3usKG/FSMaXouv0WxIWFTWMp/Oz4CwB7cBpKP/AD8THso+KzyU+hCDmYk0fB4VMVTYiozu152vaJuprbg+Ox+LBOB45S4cNCRJG9oKenTT13jzL3jERZSi2EKvsDqfVZ2WLoW0/D0agiQ6ndpBZIfW1Eog4=" Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+07:00" level=debug msg="completed keyexchange" Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58:35+07:00" level=debug msg="completed challenge" Jan 28 11:58:35 volumio go-librespot[22736]: time="2026-01-28T11:58: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 28 11:58:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:58:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:58:35 volumio volumio[22375]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:58:35 volumio volumio[22375]: Error: socket hang up Jan 28 11:58:35 volumio volumio[22375]: at connResetException (node:internal/errors:720:14) Jan 28 11:58:35 volumio volumio[22375]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:58:35 volumio volumio[22375]: at Socket.emit (node:events:526:35) Jan 28 11:58:35 volumio volumio[22375]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:58:35 volumio volumio[22375]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:58:35 volumio volumio[22375]: code: 'ECONNRESET', Jan 28 11:58:35 volumio volumio[22375]: response: undefined Jan 28 11:58:35 volumio volumio[22375]: } Jan 28 11:58:35 volumio volumio[22375]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:58:37 volumio sudo[22766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:57' Jan 28 11:58:37 volumio sudo[22766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"