Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "network"... Jan 28 07:03:00 volumio volumio[13197]: info: Refreshing Cached IP Addresses Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:03:00 volumio sudo[13242]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:03:00 volumio sudo[13242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:00 volumio sudo[13242]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:00 volumio sudo[13244]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:03:00 volumio sudo[13244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=info msg="zeroconf server listening on port 43065" Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "services"... Jan 28 07:03:00 volumio sudo[13244]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "alsa_controller"... Jan 28 07:03:00 volumio sudo[13252]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 07:03:00 volumio sudo[13252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:00 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "wizard"... Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "networkfs"... Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="obtained new client token: AACGiyeBSQKyCoq9yRBlutFiTePskOo8X/aiNPmD/aCpRulxsQDSK3nLznLAoXadyvVfs5WOgB/73zVVkG4QQH3ZVV0ftKyUf2/q4irfA7JgapuB3jsD2IXAk8o3aGRSzNkIFCbF/s9EoiG+CgBTE3Xui0k8cjOQYhzSUkzzHg9FY8Jk/tVwUZVB/h/x3MG/rheYVh6wgv3LHLqGaftsf8hNF6qduy2nAa7gducxRULCWCdQIF2dJCtf8sI=" Jan 28 07:03:00 volumio volumio[13197]: info: Starting Udev Watcher for removable devices Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:00 volumio volumio[13197]: info: Ignoring mount for partition: boot Jan 28 07:03:00 volumio volumio[13197]: info: Ignoring mount for partition: volumio Jan 28 07:03:00 volumio volumio[13197]: info: Ignoring mount for partition: volumio_data Jan 28 07:03:00 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "volumio_command_line_client"... Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "upnp"... Jan 28 07:03:00 volumio volumio[13197]: info: [1769558580716] Starting Upmpd Daemon Jan 28 07:03:00 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "my_music"... Jan 28 07:03:00 volumio volumio[13197]: info: Loading plugin "mpd"... Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=debug msg="completed challenge" Jan 28 07:03:00 volumio go-librespot[13234]: time="2026-01-28T07:03:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:03:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:01 volumio volumio[13197]: info: Loading plugin "upnp_browser"... Jan 28 07:03:03 volumio sudo[13252]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 07:03:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:04 volumio go-librespot[13275]: go-librespot daemon starting... Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+07:00" level=debug msg="app state loaded" Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:04 volumio volumio[13197]: info: Starting UPNP Browser Jan 28 07:03:04 volumio volumio[13197]: info: Loading plugin "alarm-clock"... Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+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 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+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 07:03:04 volumio volumio[13197]: info: Loading plugin "airplay_emulation"... Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+07:00" level=info msg="zeroconf server listening on port 33909" Jan 28 07:03:04 volumio volumio[13197]: info: Starting Shairport Sync Jan 28 07:03:04 volumio volumio[13197]: info: Loading plugin "last_100"... Jan 28 07:03:04 volumio volumio[13197]: info: Loading plugin "webradio"... Jan 28 07:03:04 volumio volumio[13197]: info: Loading plugin "i2s_dacs"... Jan 28 07:03:04 volumio volumio[13197]: info: Loading plugin "volumiodiscovery"... Jan 28 07:03:04 volumio go-librespot[13276]: time="2026-01-28T07:03:04+07:00" level=debug msg="obtained new client token: AAA/k1sJHm4YwPnq0kSthSl0NICzJS8nTrKpi7aBIu74rtfap1tKImeRwZsR2GCcYDpCiGv+i1MdJQEPhCC4A1H80i3KhQ27RMKp51Yqy7/7ymDLHeSx2iOZ+lvCKOTP+eh+lXiHMrcJm09GalpRHYhonZqtfl7lF147R/J+vWGP4R7INMM79axuwZY8u9J7d0PRF2v5XEYFJGsFiUEHfvz2NYURMyVo6Q05+vfQS+ijLgj2xFzfu8GVvUw=" Jan 28 07:03:04 volumio volumio[13197]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:04 volumio volumio[13197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:04 volumio volumio[13197]: *** WARNING *** For more information see Jan 28 07:03:04 volumio volumio[13197]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:04 volumio volumio[13197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:04 volumio volumio[13197]: *** WARNING *** For more information see Jan 28 07:03:04 volumio node[13197]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:04 volumio node[13197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:04 volumio node[13197]: *** WARNING *** For more information see Jan 28 07:03:04 volumio node[13197]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:04 volumio node[13197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:04 volumio node[13197]: *** WARNING *** For more information see Jan 28 07:03:04 volumio volumio[13197]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 07:03:04 volumio volumio[13197]: info: Discovery: Started advertising with name: Volumio Jan 28 07:03:05 volumio go-librespot[13276]: time="2026-01-28T07:03:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:05 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:03:05 volumio volumio[13197]: info: Loading plugin "spop"... Jan 28 07:03:05 volumio go-librespot[13276]: time="2026-01-28T07:03:05+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:05 volumio go-librespot[13276]: time="2026-01-28T07:03:05+07:00" level=debug msg="completed challenge" Jan 28 07:03:05 volumio go-librespot[13276]: time="2026-01-28T07:03:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:03:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:06 volumio volumio[13197]: info: Loading plugin "ytcr"... Jan 28 07:03:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 07:03:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:08 volumio go-librespot[13289]: go-librespot daemon starting... Jan 28 07:03:08 volumio go-librespot[13290]: time="2026-01-28T07:03:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:08 volumio go-librespot[13290]: time="2026-01-28T07:03:08+07:00" level=debug msg="app state loaded" Jan 28 07:03:08 volumio go-librespot[13290]: time="2026-01-28T07:03:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=info msg="zeroconf server listening on port 40565" Jan 28 07:03:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="obtained new client token: AAAllRy/INzXkQ+y7lmMksgL0jYfnW0ZcOTw0PIlgLVIZRermKaB0GPX4OIkcp+DekUPIXLUaM12IocfqV3K8zHBUP9HaWmRqTtSQBrdgJw9tu8RMJVER8g1+lcQw8rzWN6wYAioFfScASoGqlNcMoO72k+xr5fWbyOxLlBG+frOX5fzYSxXC6EO39WEv9jGyg8PWaTQ+KoLdL16J54pX7uYcBzGy43MYUl2xhWPZEnywxBCoS0Tz+1H7eg=" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:09 volumio volumio[13197]: info: Loading plugin "ytmusic"... Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=debug msg="completed challenge" Jan 28 07:03:09 volumio go-librespot[13290]: time="2026-01-28T07:03:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:03:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:10 volumio volumio-remote-updater[628]: [2026-01-28 07:03:10] [connect] Successful connection Jan 28 07:03:10 volumio volumio[13197]: info: Loading plugin "outputs"... Jan 28 07:03:10 volumio volumio[13197]: info: Loading plugin "albumart"... Jan 28 07:03:10 volumio volumio[13197]: info: Plugin example_plugin is not enabled Jan 28 07:03:10 volumio volumio[13197]: info: Loading plugin "inputs"... Jan 28 07:03:10 volumio volumio[13197]: info: Loading plugin "updater_comm"... Jan 28 07:03:10 volumio volumio[13197]: info: Plugin mpdemulation is not enabled Jan 28 07:03:10 volumio volumio[13197]: info: Loading plugin "rest_api"... Jan 28 07:03:10 volumio volumio[13197]: info: Loading plugin "websocket"... Jan 28 07:03:10 volumio volumio[13197]: info: Starting Socket.io Server version 1.7.4 Jan 28 07:03:11 volumio volumio[13197]: info: Loading plugin "RoonBridge"... Jan 28 07:03:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:11 volumio volumio[13197]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 07:03:11 volumio volumio[13197]: info: Loading i18n strings for locale en Jan 28 07:03:11 volumio volumio[13197]: Updating browse sources language Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:11 volumio volumio[13311]: Forking 3 albumart workers Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::initPlayerControls Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:03:11 volumio volumio[13197]: Express server listening on port 3000 Jan 28 07:03:11 volumio volumio[13197]: [Metrics] WebUI: 16s 31.64ms Jan 28 07:03:11 volumio volumio[13197]: info: CoreStateMachine::resetVolumioState Jan 28 07:03:11 volumio volumio[13197]: info: CoreStateMachine::getcurrentVolume Jan 28 07:03:11 volumio volumio[13197]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:03:12 volumio sudo[13353]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:03:12 volumio sudo[13353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:12 volumio sudo[13353]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:12 volumio sudo[13356]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:03:12 volumio sudo[13356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:12 volumio sudo[13356]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:12 volumio volumio[13197]: info: Volumio Network Manager: Network status updated: 1 Jan 28 07:03:12 volumio volumio-remote-updater[628]: [2026-01-28 07:03:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769558590 101 Jan 28 07:03:12 volumio volumio[13197]: 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 07:03:12 volumio volumio[13197]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::pushState Jan 28 07:03:12 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::updateTrackBlock Jan 28 07:03:12 volumio volumio[13197]: info: CorePlayQueue::getTrackBlock Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:12 volumio volumio[13197]: info: Reloading queue from file Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::setRepeat null single undefined Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::pushState Jan 28 07:03:12 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::setRandom null Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::pushState Jan 28 07:03:12 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:12 volumio volumio[13197]: info: Setting Device type: Raspberry PI Jan 28 07:03:12 volumio volumio[13197]: info: Completed loading Core Plugins Jan 28 07:03:12 volumio volumio[13197]: info: Preparing to generate the ALSA configuration file Jan 28 07:03:12 volumio volumio[13197]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:03:12 volumio volumio[13197]: info: CoreStateMachine::pushState Jan 28 07:03:12 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:12 volumio volumio[13197]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:12 volumio volumio[13197]: info: Asound.conf file unchanged, so no further update is needed Jan 28 07:03:12 volumio volumio[13197]: info: Output device has changed, restarting MPD Jan 28 07:03:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 07:03:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:13 volumio volumio[13197]: info: Output device has changed, restarting Shairport Sync Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:13 volumio sudo[13371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 07:03:13 volumio sudo[13371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:13 volumio sudo[13373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:03:13 volumio sudo[13373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:13 volumio go-librespot[13376]: go-librespot daemon starting... Jan 28 07:03:13 volumio sudo[13373]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:13 volumio volumio[13197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:03:13 volumio sudo[13375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+07:00" level=debug msg="app state loaded" Jan 28 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:13 volumio sudo[13375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:13 volumio volumio[13197]: info: ___________ START PLUGINS ___________ Jan 28 07:03:13 volumio sudo[13371]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:13 volumio volumio[13197]: info: ControllerMpd::onStart: Initializing MPD Jan 28 07:03:13 volumio volumio[13197]: info: Creating MPD Configuration file Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:03:13 volumio volumio[13197]: info: [1769558593278] CoreMusicLibrary::Adding element Media Servers Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:13 volumio sudo[13391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:03:13 volumio sudo[13391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:13 volumio volumio[13197]: info: UPNP Browser: Client initialized successfully Jan 28 07:03:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 07:03:13 volumio sudo[13391]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:13 volumio sudo[13393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:03:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:13 volumio sudo[13393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:13 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:03:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:03:13 volumio systemd[1]: mpd.service: Consumed 7.314s CPU time. Jan 28 07:03:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:03:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:03:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:03:13 volumio volumio[13197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:03:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:03:13 volumio volumio[13197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:03:13 volumio volumio[13197]: info: [1769558593679] CoreMusicLibrary::Adding element Last_100 Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:03:13 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:03:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:03:13 volumio volumio[13197]: info: [1769558593702] CoreMusicLibrary::Adding element Webradio Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:03:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:03:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:03:13 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:03:13 volumio volumio[13197]: info: Initializing BBC Radios Jan 28 07:03:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:03:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+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 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+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 07:03:13 volumio go-librespot[13383]: time="2026-01-28T07:03:13+07:00" level=info msg="zeroconf server listening on port 41651" Jan 28 07:03:14 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:03:14 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:14 volumio volumio[13197]: info: Creating Spotify config file Jan 28 07:03:14 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:14 volumio go-librespot[13383]: time="2026-01-28T07:03:14+07:00" level=debug msg="obtained new client token: AACWNRN9Zby1kRh1CB9OQBTjM3ZH1EebjbyL6vHK4N2dDeAfoloEhnRS1fsiv2b5MaTcCU19tXecN1XgVJjguAoVBNajWz5ev2oC6IF2HzDlSK3DfFCtU9rgHOyNR+zBnAzmx37IHLBQr7JUTsR0ben7sW9USI4tHhcSl087KOCAgDupiEnWyicUZtg9yY2C38aXPblLOY4Eru+6rb3E3hhfpzbCZ8HHXaMWge+3A8bQp7rzXtk2pdsd" Jan 28 07:03:14 volumio go-librespot[13383]: time="2026-01-28T07:03:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 07:03:14 volumio sudo[13410]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 07:03:14 volumio sudo[13410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 07:03:14 volumio sudo[13410]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:14 volumio go-librespot[13383]: time="2026-01-28T07:03:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 07:03:14 volumio go-librespot[13383]: time="2026-01-28T07:03:14+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:14 volumio go-librespot[13383]: time="2026-01-28T07:03:14+07:00" level=debug msg="completed challenge" Jan 28 07:03:14 volumio go-librespot[13383]: time="2026-01-28T07:03:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:03:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:15 volumio volumio[13322]: Starting albumart workers Jan 28 07:03:15 volumio volumio[13321]: Starting albumart workers Jan 28 07:03:15 volumio volumio[13197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:03:15 volumio volumio[13197]: info: [1769558595394] CoreMusicLibrary::Adding element YouTube Music Jan 28 07:03:15 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:15 volumio volumio[13197]: Cannot find translation for source YouTube Music Jan 28 07:03:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:15 volumio volumio[13197]: info: Volumio Calling Home Jan 28 07:03:15 volumio volumio[13323]: Starting albumart workers Jan 28 07:03:15 volumio sudo[13427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 07:03:15 volumio sudo[13427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:15 volumio sudo[13427]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:16 volumio volumio[13197]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:03:16 volumio volumio[13197]: info: Discovery: Found device Volumio Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::volumioGetState Jan 28 07:03:16 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:16 volumio volumio[13197]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:03:16 volumio volumio[13197]: info: Discovery: Found device Volumio Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::volumioGetState Jan 28 07:03:16 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:16 volumio volumio[13197]: info: MPD Permissions set Jan 28 07:03:16 volumio volumio[13197]: info: MPD Permissions set Jan 28 07:03:16 volumio volumio[13197]: info: Upmpdcli Daemon Started Jan 28 07:03:16 volumio volumio[13197]: info: Volumio called home Jan 28 07:03:16 volumio volumio[13197]: info: Spotify config file written Jan 28 07:03:16 volumio sudo[13433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 07:03:16 volumio sudo[13433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:16 volumio volumio[13197]: 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 07:03:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:16 volumio go-librespot[13435]: go-librespot daemon starting... Jan 28 07:03:16 volumio sudo[13433]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio go-librespot[13438]: time="2026-01-28T07:03:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:16 volumio go-librespot[13438]: time="2026-01-28T07:03:16+07:00" level=debug msg="app state loaded" Jan 28 07:03:16 volumio go-librespot[13438]: time="2026-01-28T07:03:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:16 volumio volumio[13197]: info: No need to fix Spotify hosts Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03: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-gew1.spotify.com:80]" Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+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 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+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 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+07:00" level=info msg="zeroconf server listening on port 38805" Jan 28 07:03:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+07:00" level=debug msg="obtained new client token: AAD2Y/3Y+LFmcskJNUfuT5jgI0vpYv69+zIR2o8I7mhvnKUk+WVIFlTHvF3UJZ66zYVxCNO5u52vS+xBpApskaZbewobDI+ZuNh06itsIO8lRebMHAdTtEMKKHMQVAOW+3zF0d6YFoNxIrmm7EmWPrkbtlw2o1YlTqqxKhsVcbniJ8XWVCgcCBpO5cLIMxpKGpSv56xEYQKncf1g5cT9U3TpEGzeekKjZbz/PgXCdVXmtW9hKVzWR6FNOBE=" Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03:17+07:00" level=debug msg="completed challenge" Jan 28 07:03:17 volumio go-librespot[13438]: time="2026-01-28T07:03: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 07:03:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:18 volumio volumio[13197]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:03:18 volumio volumio[13197]: SPOTIFY: BQCq4aTXph4WpRBxdn9AFfO2THOfcsaWaWiSRiJPY7rmyfn0B8ii1uAl03Kn1xScIlM4D2u4tfQm7Syh29UPJnwMPtTlRy-nCsw0KGe-_nkljJhBGTYkZmYvn7pzRPPurvTn-VYBU4QMMgqjkAQzBlDAS6uG5_DnsHCRFvD9aLN4h4rxpUYGop5q_ChZQauPKek3P1UkpwFyrrIiQbluvrN7TWeJZhBpBOjMXSJS-2QSYXyxc1WgP06ggWxQZ4cOJp8jGh_GAeG45rtfQApIcFfG1jLFAO4UHnTNEkk-GzrvWcMyL6AUzjWe Jan 28 07:03:18 volumio volumio[13197]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:03:18 volumio volumio[13197]: info: New Spotify access token = BQCq4aTXph4WpRBxdn9AFfO2THOfcsaWaWiSRiJPY7rmyfn0B8ii1uAl03Kn1xScIlM4D2u4tfQm7Syh29UPJnwMPtTlRy-nCsw0KGe-_nkljJhBGTYkZmYvn7pzRPPurvTn-VYBU4QMMgqjkAQzBlDAS6uG5_DnsHCRFvD9aLN4h4rxpUYGop5q_ChZQauPKek3P1UkpwFyrrIiQbluvrN7TWeJZhBpBOjMXSJS-2QSYXyxc1WgP06ggWxQZ4cOJp8jGh_GAeG45rtfQApIcFfG1jLFAO4UHnTNEkk-GzrvWcMyL6AUzjWe Jan 28 07:03:18 volumio volumio[13197]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 07:03:18 volumio volumio[13197]: info: Starting Shairport Sync Jan 28 07:03:18 volumio volumio[13197]: info: Starting Shairport Sync Jan 28 07:03:18 volumio volumio[13197]: info: Starting Shairport Sync Jan 28 07:03:18 volumio sudo[13474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:03:18 volumio sudo[13474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:18 volumio sudo[13476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:03:18 volumio sudo[13476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:18 volumio sudo[13478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:03:18 volumio sudo[13478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:03:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:03:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:03:18 volumio systemd[1]: shairport-sync.service: Consumed 2.264s CPU time. Jan 28 07:03:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:03:18 volumio sudo[13474]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:03:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:03:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:03:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:03:18 volumio sudo[13476]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:18 volumio volumio[13197]: info: Shairport-Sync Started Jan 28 07:03:18 volumio volumio[13197]: Error adding Membership: Error: addMembership EINVAL Jan 28 07:03:18 volumio sudo[13478]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:18 volumio volumio[13197]: info: Shairport-Sync Started Jan 28 07:03:18 volumio volumio[13197]: info: CoreCommandRouter::volumioGetState Jan 28 07:03:18 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:18 volumio volumio[13197]: info: Shairport-Sync Started Jan 28 07:03:18 volumio volumio[13197]: 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 07:03:18 volumio volumio[13197]: info: Spotify Successfully logged in Jan 28 07:03:19 volumio volumio[13197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:03:19 volumio volumio[13197]: info: [1769558599005] CoreMusicLibrary::Adding element Spotify Jan 28 07:03:19 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:19 volumio volumio[13197]: Cannot find translation for source YouTube Music Jan 28 07:03:19 volumio volumio[13197]: Cannot find translation for source Spotify Jan 28 07:03:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:19 volumio volumio[13197]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 07:03:19 volumio volumio[13197]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:03:20 volumio volumio[13197]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:03:20 volumio volumio[13197]: info: CoreCommandRouter::volumioGetState Jan 28 07:03:20 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:20 volumio volumio[13197]: info: CoreStateMachine::pushState Jan 28 07:03:20 volumio volumio[13197]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:20 volumio volumio[13197]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:21 volumio volumio[13197]: info: go-librespot daemon successfully initialized Jan 28 07:03:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 07:03:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:21 volumio go-librespot[13516]: go-librespot daemon starting... Jan 28 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03:21+07:00" level=debug msg="app state loaded" Jan 28 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:21 volumio mpd[13425]: 2026-01-28T07:03:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 07:03:21 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 07:03:21 volumio sudo[13375]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:21 volumio sudo[13393]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:21 volumio volumio[13197]: error: MPD error: The expression evaluated to a falsy value: Jan 28 07:03:21 volumio volumio[13197]: assert.ok(self.idling) Jan 28 07:03:21 volumio volumio[13197]: error: The expression evaluated to a falsy value: Jan 28 07:03:21 volumio volumio[13197]: assert.ok(self.idling) Jan 28 07:03:21 volumio volumio[13197]: info: MPD running with PID13425 Jan 28 07:03:21 volumio volumio[13197]: ,establishing connection Jan 28 07:03:21 volumio volumio[13197]: error: updateQueue error: null Jan 28 07:03:21 volumio volumio[13197]: info: Completed starting Core Plugins Jan 28 07:03:21 volumio volumio[13197]: info: ------------------------------------------- Jan 28 07:03:21 volumio volumio[13197]: info: ----- MyVolumio plugins startup ---- Jan 28 07:03:21 volumio volumio[13197]: info: ------------------------------------------- Jan 28 07:03:21 volumio volumio[13197]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 07:03:21 volumio volumio[13197]: error: updateQueue error: null Jan 28 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03: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 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03: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 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03: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 07:03:21 volumio go-librespot[13517]: time="2026-01-28T07:03:21+07:00" level=info msg="zeroconf server listening on port 39817" Jan 28 07:03:22 volumio go-librespot[13517]: time="2026-01-28T07:03:22+07:00" level=debug msg="obtained new client token: AACl3t+/n9N95v2bK/ImOvpe6KKYaEA5cyoRyCJq6y3+Xk+0EDCd5nd6/3v/FubQ7QDJ/m0qCEkqx+GtcLOmDGTscFMJktzeOUivOmwNmymWEwcO86I+OrybQfJt0vYYRbw6IQOpBam7R+UZPyJNN8uik69FIv5MHBTmlm18W5zZcg9QekZyk7uA7w1dr7Xz+o8jyRbdMnB2iGrcjJspfcTlFBoCleFB1ZK1nnSun+Ke+yHJGurRg68x" Jan 28 07:03:22 volumio go-librespot[13517]: time="2026-01-28T07:03:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:22 volumio go-librespot[13517]: time="2026-01-28T07:03:22+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:22 volumio go-librespot[13517]: time="2026-01-28T07:03:22+07:00" level=debug msg="completed challenge" Jan 28 07:03:22 volumio go-librespot[13517]: time="2026-01-28T07:03: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 07:03:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:24 volumio volumio[13197]: info: Initializing connection to go-librespot Websocket Jan 28 07:03:24 volumio volumio[13197]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:03:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 07:03:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:25 volumio go-librespot[13528]: go-librespot daemon starting... Jan 28 07:03:25 volumio go-librespot[13529]: time="2026-01-28T07:03:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:25 volumio go-librespot[13529]: time="2026-01-28T07:03:25+07:00" level=debug msg="app state loaded" Jan 28 07:03:25 volumio go-librespot[13529]: time="2026-01-28T07:03:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=info msg="zeroconf server listening on port 43521" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="obtained new client token: AAAFqg0coqgy7nxQiFiRyyPyAknMKygBEGQuXwDqlcGTg3+wdOWnw0Gr4NALAKxSvs0K9ihIH0NqTI3W5D7yEfOb3cU2RwFiDejJQ6u0fRkp+xCkz3GHArjqTA5Vvzq61SBVfgNUVoRRgi4uYpqtVx0UQpS7KzznanTzDLFFDs06Vcktqsu90xiM1wch+AAhHwqtkw60zxCIRNQ/WhAV9jBST7ELQesmBpsTOaLZ2608wbKXbo7p72cgRLo=" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:26 volumio volumio[13197]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=debug msg="completed challenge" Jan 28 07:03:26 volumio go-librespot[13529]: time="2026-01-28T07:03:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:03:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:27 volumio volumio[13197]: info: Initializing connection to go-librespot Websocket Jan 28 07:03:27 volumio volumio[13197]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:03:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 07:03:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:30 volumio volumio[13197]: info: Initializing connection to go-librespot Websocket Jan 28 07:03:30 volumio volumio[13197]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:03:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:30 volumio go-librespot[13536]: go-librespot daemon starting... Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=debug msg="app state loaded" Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 07:03:30 volumio volumio[13197]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+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 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+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 07:03:30 volumio volumio[13197]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=info msg="zeroconf server listening on port 45123" Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=debug msg="obtained new client token: AAB2VphFGlYqgtoTrQVbTXKSEVQxJE2wq8/r5cUkVr5KfdHp7OOCO73B02YqqIk490o00OYaHCLqfw9SiLsZTAV+9dpTFKH+mgmd571rLTOrhohwBbgXkn+p29ytrnfjhy3YiZx8J9rJOifx1bEaMKbe3gNqnNhrdMTWlkCjK3DVxVzeIzyBrgtvKkSI9zf1vffuFHCLYXNdMNbwkXSh3ROkj2Wt2dUJPnJdifYGMBsNXlO5+rTOCl/6d3Q=" Jan 28 07:03:30 volumio go-librespot[13537]: time="2026-01-28T07:03:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:31 volumio go-librespot[13537]: time="2026-01-28T07:03:31+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:31 volumio go-librespot[13537]: time="2026-01-28T07:03:31+07:00" level=debug msg="completed challenge" Jan 28 07:03:31 volumio go-librespot[13537]: time="2026-01-28T07:03: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 07:03:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:32 volumio volumio[13197]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 07:03:32 volumio volumio[13197]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 07:03:32 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:32 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:32 volumio volumio[13197]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 07:03:32 volumio volumio[13197]: info: MyVolumio login type: Token Jan 28 07:03:32 volumio volumio[13197]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 07:03:32 volumio volumio[13197]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 07:03:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 07:03:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:34 volumio volumio[13197]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 07:03:34 volumio volumio[13197]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 07:03:34 volumio volumio[13197]: info: Streaming services startup Jan 28 07:03:34 volumio volumio[13197]: info: Starting Streaming Daemon Jan 28 07:03:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:34 volumio go-librespot[13558]: go-librespot daemon starting... Jan 28 07:03:34 volumio sudo[13560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 07:03:34 volumio volumio[13197]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 07:03:34 volumio sudo[13560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03:34+07:00" level=debug msg="app state loaded" Jan 28 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:34 volumio sudo[13560]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:34 volumio volumio[13197]: info: Initializing connection to go-librespot Websocket Jan 28 07:03:34 volumio volumio[13197]: error: Cannot start Volumio Streaming Daemon Jan 28 07:03:34 volumio volumio[13197]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 07:03:34 volumio volumio[13197]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03:34+07:00" level=debug msg="new websocket client" Jan 28 07:03:34 volumio volumio[13197]: info: Connection to go-librespot Websocket established Jan 28 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03: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 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03: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 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03: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 07:03:34 volumio go-librespot[13564]: time="2026-01-28T07:03:34+07:00" level=info msg="zeroconf server listening on port 36555" Jan 28 07:03:35 volumio go-librespot[13564]: time="2026-01-28T07:03:35+07:00" level=debug msg="obtained new client token: AAAPRmngK+K3dQBRbXhHb+z18N9Kzk3iM/SY1qD3o+dOHWtviMnuLrlDgrwm01UHyPV+T7opW9GjCyYtFZt+/xMhU/iEvZkYGZGtRQHf3msvKCf4gdNweLV1nJWyM/kz6BAcGoErEc75pxvpHlPF2vplIhPo3zB8O4jOLmJDw+I55bb0r2pb20LHWtW6n40SYzjzkwqKr6P8vIHhdU19rmCHatdkCr7QCWmHkNtpIGSg/0P/+nVMAWnm" Jan 28 07:03:35 volumio go-librespot[13564]: time="2026-01-28T07:03:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:35 volumio go-librespot[13564]: time="2026-01-28T07:03:35+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:35 volumio go-librespot[13564]: time="2026-01-28T07:03:35+07:00" level=debug msg="completed challenge" Jan 28 07:03:35 volumio go-librespot[13564]: time="2026-01-28T07:03: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 07:03:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:35 volumio volumio[13197]: info: Connection to go-librespot Websocket closed Jan 28 07:03:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:35 volumio volumio[13197]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 07:03:36 volumio volumio[13197]: info: MyVolumio token set successfully Jan 28 07:03:36 volumio volumio[13197]: info: MYVOLUMIO: Adding device Jan 28 07:03:36 volumio volumio[13197]: info: MYVOLUMIO: Evaluating Server Jan 28 07:03:36 volumio volumio[13197]: info: MyVolumio status changed Jan 28 07:03:36 volumio volumio[13197]: info: Streaming services startup Jan 28 07:03:36 volumio volumio[13197]: info: Starting Streaming Daemon Jan 28 07:03:36 volumio volumio[13197]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 07:03:36 volumio volumio[13197]: info: Removing audio output: Jan 28 07:03:36 volumio volumio[13197]: info: Stoppping Tunnel 1 Jan 28 07:03:36 volumio sudo[13595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 07:03:36 volumio sudo[13595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:36 volumio sudo[13598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 07:03:36 volumio sudo[13598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:36 volumio sudo[13595]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:37 volumio volumio[13197]: error: Cannot start Volumio Streaming Daemon Jan 28 07:03:37 volumio volumio[13197]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 07:03:37 volumio volumio[13197]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 07:03:37 volumio sudo[13598]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:37 volumio volumio[13197]: info: Setting Geolocation for MyVolumio to as1 Jan 28 07:03:37 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:37 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:37 volumio volumio[13197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:37 volumio volumio[13197]: info: Remote SSH Stopped Jan 28 07:03:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:37 volumio volumio[13197]: info: Getting Spotify volume Jan 28 07:03:37 volumio volumio[13197]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:03:37 volumio volumio[13197]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:03:37 volumio volumio[13197]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 07:03:37 volumio volumio[13197]: errno: -111, Jan 28 07:03:37 volumio volumio[13197]: code: 'ECONNREFUSED', Jan 28 07:03:37 volumio volumio[13197]: syscall: 'connect', Jan 28 07:03:37 volumio volumio[13197]: address: '127.0.0.1', Jan 28 07:03:37 volumio volumio[13197]: port: 9879, Jan 28 07:03:37 volumio volumio[13197]: response: undefined Jan 28 07:03:37 volumio volumio[13197]: } Jan 28 07:03:37 volumio volumio[13197]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:03:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 07:03:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:38 volumio go-librespot[13613]: go-librespot daemon starting... Jan 28 07:03:38 volumio go-librespot[13614]: time="2026-01-28T07:03:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:38 volumio go-librespot[13614]: time="2026-01-28T07:03:38+07:00" level=debug msg="app state loaded" Jan 28 07:03:38 volumio go-librespot[13614]: time="2026-01-28T07:03:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:39 volumio sudo[13623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 07:02' Jan 28 07:03:39 volumio sudo[13623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+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 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+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 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+07:00" level=info msg="zeroconf server listening on port 45021" Jan 28 07:03:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+07:00" level=debug msg="obtained new client token: AADNL7yaodtNnLFhWDnf5Dl7Q8azAITwXCIxCXI2SOOwUIEfradnJhBArioFWXUlbQT5WQ4SRklRrCbZJykqdVt6NFcw8J9i7xnMi1ip4fArk5ZEChGF1C7yqNcDkZJlYcCUgNY/IDuCPVuyFHY/H5SjPMbeM8yjEp6erjhppMBPjWxDjLf9R9C5o7+eaLB7KCLrsnCdHDLjElVMnBD6Vxe3SzW4GfceeJkrgB/eNwqB8VQNk0kuubpjaAQ=" Jan 28 07:03:39 volumio sudo[13623]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:39 volumio volumio-remote-updater[628]: [2026-01-28 07:03:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 07:03:39 volumio volumio-remote-updater[628]: [2026-01-28 07:03:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 07:03:39 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03:39+07:00" level=debug msg="completed challenge" Jan 28 07:03:39 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 07:03:39 volumio systemd[1]: volumio.service: Consumed 1min 186ms CPU time. Jan 28 07:03:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 07:03:39 volumio go-librespot[13614]: time="2026-01-28T07:03: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 07:03:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 07:03:39 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9771. Jan 28 07:03:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 07:03:39 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 07:03:39 volumio systemd[1]: volumio.service: Consumed 1min 186ms CPU time. Jan 28 07:03:39 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 07:03:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 07:03:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 07:03:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:43 volumio go-librespot[13650]: go-librespot daemon starting... Jan 28 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+07:00" level=debug msg="app state loaded" Jan 28 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:43 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:03:43 volumio volumio[13635]: info: ----- Volumio3 ---- Jan 28 07:03:43 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:03:43 volumio volumio[13635]: info: ----- System startup ---- Jan 28 07:03:43 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03: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-gew1.spotify.com:80]" Jan 28 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+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 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+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 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+07:00" level=info msg="zeroconf server listening on port 40973" Jan 28 07:03:43 volumio go-librespot[13651]: time="2026-01-28T07:03:43+07:00" level=debug msg="obtained new client token: AABFzOv946mFIVdgIsEI5Lg/ebgFKTcQr+2XEi4+D7pUwAPvSO1GM8XYOwldROfKZz1ByNOOHgsMbq8PdtBxvuF9OzY1R62P+Ns9lP1pDIFSMJArukbCtf+AUd7oPpe6pI9AiXezx82qLPynKyapv9l3xQt4aTuxvB/jxI2IbArGUB8tROLv0khoYv/If3749NEB7TdnLiJU6a6wLOdEVWSfflKRh/OYh07DBw4sSMSLeX15vSf8PpOw4/E=" Jan 28 07:03:44 volumio go-librespot[13651]: time="2026-01-28T07:03:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:44 volumio go-librespot[13651]: time="2026-01-28T07:03:44+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:44 volumio go-librespot[13651]: time="2026-01-28T07:03:44+07:00" level=debug msg="completed challenge" Jan 28 07:03:44 volumio go-librespot[13651]: time="2026-01-28T07:03:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:03:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:44 volumio volumio-remote-updater[628]: [2026-01-28 07:03:44] [connect] Successful connection Jan 28 07:03:44 volumio volumio[13635]: info: MYVOLUMIO Environment detected Jan 28 07:03:44 volumio volumio[13635]: info: Plugin folders cleanup Jan 28 07:03:44 volumio volumio[13635]: info: Scanning into folder /volumio/app/plugins/ Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category audio_interface Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category miscellanea Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category music_service Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category plugins.json Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category system_controller Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category user_interface Jan 28 07:03:44 volumio volumio[13635]: info: Scanning into folder /data/plugins/ Jan 28 07:03:44 volumio volumio[13635]: info: Scanning category music_service Jan 28 07:03:44 volumio volumio[13635]: info: Plugin folders cleanup completed Jan 28 07:03:44 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:03:44 volumio volumio[13635]: info: ----- Core plugins startup ---- Jan 28 07:03:44 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:03:45 volumio volumio[13635]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 07:03:45 volumio volumio[13635]: info: Adding plugin upnp to MyMusic Plugins Jan 28 07:03:45 volumio volumio[13635]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 07:03:45 volumio volumio[13635]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 07:03:45 volumio volumio[13635]: info: Loading plugins from folder /data/plugins/ Jan 28 07:03:45 volumio volumio[13635]: info: Loading plugin "system"... Jan 28 07:03:45 volumio volumio[13635]: info: Loading plugin "appearance"... Jan 28 07:03:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:46 volumio volumio[13635]: info: Loading plugin "network"... Jan 28 07:03:46 volumio volumio[13635]: info: Refreshing Cached IP Addresses Jan 28 07:03:47 volumio sudo[13671]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:03:47 volumio sudo[13671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:47 volumio sudo[13673]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:03:47 volumio sudo[13673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:47 volumio sudo[13671]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "services"... Jan 28 07:03:47 volumio sudo[13673]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "alsa_controller"... Jan 28 07:03:47 volumio sudo[13681]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 07:03:47 volumio sudo[13681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:47 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "wizard"... Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "networkfs"... Jan 28 07:03:47 volumio volumio[13635]: info: Starting Udev Watcher for removable devices Jan 28 07:03:47 volumio volumio[13635]: info: Ignoring mount for partition: boot Jan 28 07:03:47 volumio volumio[13635]: info: Ignoring mount for partition: volumio Jan 28 07:03:47 volumio volumio[13635]: info: Ignoring mount for partition: volumio_data Jan 28 07:03:47 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "volumio_command_line_client"... Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "upnp"... Jan 28 07:03:47 volumio volumio[13635]: info: [1769558627383] Starting Upmpd Daemon Jan 28 07:03:47 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "my_music"... Jan 28 07:03:47 volumio volumio[13635]: info: Loading plugin "mpd"... Jan 28 07:03:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 07:03:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:47 volumio go-librespot[13704]: go-librespot daemon starting... Jan 28 07:03:47 volumio go-librespot[13705]: time="2026-01-28T07:03:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:47 volumio go-librespot[13705]: time="2026-01-28T07:03:47+07:00" level=debug msg="app state loaded" Jan 28 07:03:47 volumio go-librespot[13705]: time="2026-01-28T07:03:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:48 volumio volumio[13635]: info: Loading plugin "upnp_browser"... Jan 28 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+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 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+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 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+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 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+07:00" level=info msg="zeroconf server listening on port 37383" Jan 28 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+07:00" level=debug msg="obtained new client token: AADGvVf/wXJvRqB8s8W1IIgvXrCZvhB6RMK02hcYtCR01SwAD8WbdajZZAeamPNfRof4MCm6p69AU23ujDJ32yzVuXPh/4Y4YBPnb+HNrgwV5mcaVHjIzP6UYfCnU+5tAMjxX0LAqWXcBk7g7yyqxeUxa++LF6bozWI+SqcvDsW31xkqDq1XaYCAsXffKIVMpoAEUrX5tV2RV3eYeNU0U87fKaTLYDdS3c6gbTz29amdHxSh7AUcsJZEc2k=" Jan 28 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03:48+07:00" level=debug msg="completed challenge" Jan 28 07:03:48 volumio go-librespot[13705]: time="2026-01-28T07:03: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 07:03:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:49 volumio sudo[13681]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:51 volumio volumio[13635]: info: Starting UPNP Browser Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "alarm-clock"... Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "airplay_emulation"... Jan 28 07:03:51 volumio volumio[13635]: info: Starting Shairport Sync Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "last_100"... Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "webradio"... Jan 28 07:03:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "i2s_dacs"... Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "volumiodiscovery"... Jan 28 07:03:51 volumio volumio[13635]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:51 volumio volumio[13635]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:51 volumio node[13635]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:51 volumio volumio[13635]: *** WARNING *** For more information see Jan 28 07:03:51 volumio volumio[13635]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:51 volumio volumio[13635]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:51 volumio volumio[13635]: *** WARNING *** For more information see Jan 28 07:03:51 volumio node[13635]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:51 volumio node[13635]: *** WARNING *** For more information see Jan 28 07:03:51 volumio node[13635]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:03:51 volumio node[13635]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:03:51 volumio node[13635]: *** WARNING *** For more information see Jan 28 07:03:51 volumio volumio[13635]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 07:03:51 volumio volumio[13635]: info: Discovery: Started advertising with name: Volumio Jan 28 07:03:51 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:03:51 volumio volumio[13635]: info: Loading plugin "spop"... Jan 28 07:03:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 07:03:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:52 volumio go-librespot[13714]: go-librespot daemon starting... Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=debug msg="app state loaded" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=info msg="zeroconf server listening on port 35123" Jan 28 07:03:52 volumio go-librespot[13715]: time="2026-01-28T07:03:52+07:00" level=debug msg="obtained new client token: AAC/4UEPgGwDW+cT7zDxn0sgyaTmx9g8ptQAD3JADCZKITeEyY4A/aup8I6syVs+ZD5iB1OubgMIId6tuIMHDrZCLIhwPq8yLArWzzzwhVYReKNz/LyrPJj78AMPITVkMbcuP784dWkKgOqqLW9Ui9mCTHU2Z7P09eagfoEVZxjYBQj2B1BX9dOUuH8DBAX7DPrKPbQxIn5YnFmDLpy9IhVBaja7RHXwDk1CUFJoXYgjZXCJ6krub0K6ofA=" Jan 28 07:03:53 volumio go-librespot[13715]: time="2026-01-28T07:03:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:53 volumio go-librespot[13715]: time="2026-01-28T07:03:53+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:53 volumio go-librespot[13715]: time="2026-01-28T07:03:53+07:00" level=debug msg="completed challenge" Jan 28 07:03:53 volumio go-librespot[13715]: time="2026-01-28T07:03:53+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 07:03:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:53 volumio volumio[13635]: info: Loading plugin "ytcr"... Jan 28 07:03:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:56 volumio volumio[13635]: info: Loading plugin "ytmusic"... Jan 28 07:03:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 07:03:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:03:56 volumio go-librespot[13722]: go-librespot daemon starting... Jan 28 07:03:56 volumio go-librespot[13723]: time="2026-01-28T07:03:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:03:56 volumio go-librespot[13723]: time="2026-01-28T07:03:56+07:00" level=debug msg="app state loaded" Jan 28 07:03:56 volumio go-librespot[13723]: time="2026-01-28T07:03:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=info msg="zeroconf server listening on port 46457" Jan 28 07:03:57 volumio volumio-remote-updater[628]: [2026-01-28 07:03:57] [connect] Successful connection Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="obtained new client token: AAA7y2/JJ9+EljopxXtjJ7oTdiTloQMDUxaYDiBDP2lErwMepWSay/KDptecyN2ub2Np9VSgoLNNP972P1rIqk7bALVJmlqm2HCNEH7w0OWOhVIblmqPC1qaUm0m6C8M6TF5UVSlPvPD0NXWeQUuk28kd9zHREdWvxk5jSJ012IOL+083T6aI49noDJdkZSZo+ptiFIJEr4zAapRnwJqFLvvExMD0iYA9ZiMoWaElaAyTmCgK7EmwA23Z0s=" Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "outputs"... Jan 28 07:03:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "albumart"... Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:03:57 volumio volumio[13635]: info: Plugin example_plugin is not enabled Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "inputs"... Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "updater_comm"... Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="completed keyexchange" Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+07:00" level=debug msg="completed challenge" Jan 28 07:03:57 volumio go-librespot[13723]: time="2026-01-28T07:03:57+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 07:03:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:03:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:03:57 volumio volumio[13635]: info: Plugin mpdemulation is not enabled Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "rest_api"... Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "websocket"... Jan 28 07:03:57 volumio volumio[13635]: info: Starting Socket.io Server version 1.7.4 Jan 28 07:03:57 volumio volumio[13635]: info: Loading plugin "RoonBridge"... Jan 28 07:03:58 volumio volumio[13635]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 07:03:58 volumio volumio[13635]: info: Loading i18n strings for locale en Jan 28 07:03:58 volumio volumio[13635]: Updating browse sources language Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::initPlayerControls Jan 28 07:03:58 volumio volumio[13746]: Forking 3 albumart workers Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:03:58 volumio volumio[13635]: Express server listening on port 3000 Jan 28 07:03:58 volumio volumio[13635]: [Metrics] WebUI: 16s 140.31ms Jan 28 07:03:58 volumio volumio[13635]: info: CoreStateMachine::resetVolumioState Jan 28 07:03:58 volumio volumio[13635]: info: CoreStateMachine::getcurrentVolume Jan 28 07:03:58 volumio volumio[13635]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:03:58 volumio sudo[13788]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:03:58 volumio sudo[13788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:58 volumio sudo[13788]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:58 volumio sudo[13790]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:03:58 volumio sudo[13790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:58 volumio sudo[13790]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:58 volumio volumio[13635]: info: Volumio Network Manager: Network status updated: 1 Jan 28 07:03:59 volumio volumio[13635]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::pushState Jan 28 07:03:59 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::updateTrackBlock Jan 28 07:03:59 volumio volumio[13635]: info: CorePlayQueue::getTrackBlock Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:03:59 volumio volumio-remote-updater[628]: [2026-01-28 07:03:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769558637 101 Jan 28 07:03:59 volumio volumio[13635]: 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 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:59 volumio volumio[13635]: info: Reloading queue from file Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::setRepeat null single undefined Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::pushState Jan 28 07:03:59 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::setRandom null Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::pushState Jan 28 07:03:59 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:03:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:03:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:03:59 volumio volumio[13635]: info: Setting Device type: Raspberry PI Jan 28 07:03:59 volumio volumio[13635]: info: Completed loading Core Plugins Jan 28 07:03:59 volumio volumio[13635]: info: Preparing to generate the ALSA configuration file Jan 28 07:03:59 volumio volumio[13635]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:03:59 volumio volumio[13635]: info: CoreStateMachine::pushState Jan 28 07:03:59 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::volumioPushState Jan 28 07:03:59 volumio volumio[13635]: info: Asound.conf file unchanged, so no further update is needed Jan 28 07:03:59 volumio volumio[13635]: info: Output device has changed, restarting MPD Jan 28 07:03:59 volumio volumio[13635]: info: Output device has changed, restarting Shairport Sync Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:03:59 volumio sudo[13807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 07:03:59 volumio sudo[13807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:59 volumio sudo[13809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:03:59 volumio sudo[13809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:59 volumio volumio[13635]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:03:59 volumio volumio[13635]: info: ___________ START PLUGINS ___________ Jan 28 07:03:59 volumio sudo[13809]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:59 volumio volumio[13635]: info: ControllerMpd::onStart: Initializing MPD Jan 28 07:03:59 volumio volumio[13635]: info: Creating MPD Configuration file Jan 28 07:03:59 volumio sudo[13811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:03:59 volumio sudo[13811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:59 volumio sudo[13820]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:03:59 volumio sudo[13820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:03:59 volumio sudo[13807]: pam_unix(sudo:session): session closed for user root Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:03:59 volumio volumio[13635]: info: [1769558639957] CoreMusicLibrary::Adding element Media Servers Jan 28 07:03:59 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:03:59 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 07:03:59 volumio sudo[13820]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:00 volumio sudo[13823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:04:00 volumio sudo[13823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:00 volumio volumio[13635]: info: UPNP Browser: Client initialized successfully Jan 28 07:04:00 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:04:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:04:00 volumio systemd[1]: mpd.service: Consumed 7.385s CPU time. Jan 28 07:04:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:04:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:04:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:00 volumio volumio[13635]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:04:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:04:00 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:04:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:04:00 volumio volumio[13635]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:04:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:04:00 volumio volumio[13635]: info: [1769558640338] CoreMusicLibrary::Adding element Last_100 Jan 28 07:04:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:04:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:04:00 volumio volumio[13635]: info: [1769558640351] CoreMusicLibrary::Adding element Webradio Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:04:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:04:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:04:00 volumio volumio[13635]: info: Initializing BBC Radios Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:00 volumio volumio[13635]: info: Creating Spotify config file Jan 28 07:04:00 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 07:04:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:00 volumio go-librespot[13850]: go-librespot daemon starting... Jan 28 07:04:00 volumio sudo[13836]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 07:04:00 volumio sudo[13836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 07:04:00 volumio sudo[13836]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:00 volumio go-librespot[13851]: time="2026-01-28T07:04:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:04:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:01 volumio volumio[13635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:04:01 volumio volumio[13635]: info: [1769558641547] CoreMusicLibrary::Adding element YouTube Music Jan 28 07:04:01 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:04:01 volumio volumio[13635]: Cannot find translation for source YouTube Music Jan 28 07:04:01 volumio volumio[13635]: info: Volumio Calling Home Jan 28 07:04:01 volumio sudo[13862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 07:04:01 volumio sudo[13862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:01 volumio go-librespot[13851]: time="2026-01-28T07:04:01+07:00" level=info msg="zeroconf server listening on port 34549" Jan 28 07:04:01 volumio sudo[13862]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:02 volumio volumio[13758]: Starting albumart workers Jan 28 07:04:02 volumio volumio[13756]: Starting albumart workers Jan 28 07:04:02 volumio volumio[13757]: Starting albumart workers Jan 28 07:04:02 volumio volumio[13635]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:04:02 volumio volumio[13635]: info: Discovery: Found device Volumio Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::volumioGetState Jan 28 07:04:02 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:02 volumio volumio[13635]: info: MPD Permissions set Jan 28 07:04:02 volumio volumio[13635]: info: MPD Permissions set Jan 28 07:04:02 volumio volumio[13635]: info: Upmpdcli Daemon Started Jan 28 07:04:02 volumio volumio[13635]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:04:02 volumio volumio[13635]: info: Discovery: Found device Volumio Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::volumioGetState Jan 28 07:04:02 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:02 volumio volumio[13635]: info: Spotify config file written Jan 28 07:04:02 volumio sudo[13868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 07:04:02 volumio sudo[13868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:02 volumio volumio[13635]: 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 07:04:02 volumio volumio[13635]: info: Volumio called home Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:02 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:02 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 07:04:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:02 volumio go-librespot[13876]: go-librespot daemon starting... Jan 28 07:04:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:03 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:03 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:04:03 volumio volumio[13635]: info: No need to fix Spotify hosts Jan 28 07:04:03 volumio sudo[13868]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=debug msg="app state loaded" Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:04:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:04:03 volumio go-librespot[13881]: time="2026-01-28T07:04:03+07:00" level=info msg="zeroconf server listening on port 45331" Jan 28 07:04:04 volumio go-librespot[13881]: time="2026-01-28T07:04:04+07:00" level=debug msg="obtained new client token: AAAMZp/z1WqrPR5cvFZUGqGkRiOYtK7KHs0PfqYEn/bjXPJ6LgaJc4joWZGskEbKPnl5y0cb7l+fqywi6OBmYY/3p6Ayz1nC1aOYoEiw3K0rSZNZa+CqAEGVfrT9REWnEJtsJ11xwwc/Vm4+FyZCjeD7UbYrv7G6chNfdw//k9G6nOCZ9Dw+vtrzmLlvQeFnZr6wV2hXKYbYZw7rpE8DuyYGXGeozL2XvleLxbtxNXN0zTl+8oMtZbYe" Jan 28 07:04:04 volumio go-librespot[13881]: time="2026-01-28T07:04:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:04:04 volumio go-librespot[13881]: time="2026-01-28T07:04:04+07:00" level=debug msg="completed keyexchange" Jan 28 07:04:04 volumio go-librespot[13881]: time="2026-01-28T07:04:04+07:00" level=debug msg="completed challenge" Jan 28 07:04:04 volumio go-librespot[13881]: time="2026-01-28T07:04: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 07:04:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:04:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:04:04 volumio volumio[13635]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:04:04 volumio volumio[13635]: SPOTIFY: BQB_pVPn-KGknpa-lTJdKdhZqkE2faJqRtl8QTJTR9BzMguW1oVeW-x-b6LDHKs_kAwcO9kqux6gajwpHGwpLNrSy7XiryY1pjhkHMeJoIJwS7C0xsiM1CUjoWqM6q09aNoku1BSkjJ3xHEtHV_DQVuZQ4-TnpD0N1bj-PciUsDZ5OZxKzQ2pYIRdxvAfNm5ceHVAPEfmjtV6zmxVCaEULBl0wjIffj4bKZKZmVda0UwNI5fyo1BTBqTPa9Nmj6gncYGPRZVuTA3MRUrelVqQkoay1A6sbzwXZkb9gpm_yy28t2J1Q9FsR_X Jan 28 07:04:04 volumio volumio[13635]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:04:04 volumio volumio[13635]: info: New Spotify access token = BQB_pVPn-KGknpa-lTJdKdhZqkE2faJqRtl8QTJTR9BzMguW1oVeW-x-b6LDHKs_kAwcO9kqux6gajwpHGwpLNrSy7XiryY1pjhkHMeJoIJwS7C0xsiM1CUjoWqM6q09aNoku1BSkjJ3xHEtHV_DQVuZQ4-TnpD0N1bj-PciUsDZ5OZxKzQ2pYIRdxvAfNm5ceHVAPEfmjtV6zmxVCaEULBl0wjIffj4bKZKZmVda0UwNI5fyo1BTBqTPa9Nmj6gncYGPRZVuTA3MRUrelVqQkoay1A6sbzwXZkb9gpm_yy28t2J1Q9FsR_X Jan 28 07:04:04 volumio volumio[13635]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 07:04:04 volumio volumio[13635]: info: Starting Shairport Sync Jan 28 07:04:04 volumio volumio[13635]: info: Starting Shairport Sync Jan 28 07:04:04 volumio volumio[13635]: info: Starting Shairport Sync Jan 28 07:04:04 volumio sudo[13908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:04:04 volumio sudo[13908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:04 volumio sudo[13910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:04:04 volumio sudo[13910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:04:04 volumio sudo[13913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:04:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:04:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:04:04 volumio systemd[1]: shairport-sync.service: Consumed 2.367s CPU time. Jan 28 07:04:04 volumio sudo[13913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:04:05 volumio sudo[13908]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:04:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:04:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:04:05 volumio volumio[13635]: info: Shairport-Sync Started Jan 28 07:04:05 volumio volumio[13635]: Error adding Membership: Error: addMembership EINVAL Jan 28 07:04:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:04:05 volumio sudo[13913]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:05 volumio sudo[13910]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:05 volumio volumio[13635]: info: CoreCommandRouter::volumioGetState Jan 28 07:04:05 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:05 volumio volumio[13635]: info: Shairport-Sync Started Jan 28 07:04:05 volumio volumio[13635]: info: Shairport-Sync Started Jan 28 07:04:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:05 volumio volumio[13635]: 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 07:04:05 volumio volumio[13635]: info: Spotify Successfully logged in Jan 28 07:04:05 volumio volumio[13635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:04:05 volumio volumio[13635]: info: [1769558645601] CoreMusicLibrary::Adding element Spotify Jan 28 07:04:05 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:04:05 volumio volumio[13635]: Cannot find translation for source YouTube Music Jan 28 07:04:05 volumio volumio[13635]: Cannot find translation for source Spotify Jan 28 07:04:06 volumio volumio[13635]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 07:04:06 volumio volumio[13635]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:04:06 volumio volumio[13635]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:04:06 volumio volumio[13635]: info: CoreCommandRouter::volumioGetState Jan 28 07:04:06 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:06 volumio volumio[13635]: info: CoreStateMachine::pushState Jan 28 07:04:06 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:06 volumio volumio[13635]: info: CoreCommandRouter::volumioPushState Jan 28 07:04:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 07:04:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:07 volumio go-librespot[13951]: go-librespot daemon starting... Jan 28 07:04:07 volumio volumio[13635]: info: go-librespot daemon successfully initialized Jan 28 07:04:07 volumio go-librespot[13952]: time="2026-01-28T07:04:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:04:07 volumio go-librespot[13952]: time="2026-01-28T07:04:07+07:00" level=debug msg="app state loaded" Jan 28 07:04:07 volumio go-librespot[13952]: time="2026-01-28T07:04:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:04:08 volumio mpd[13858]: 2026-01-28T07:04:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 07:04:08 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 07:04:08 volumio sudo[13823]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:08 volumio sudo[13811]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+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 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+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 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+07:00" level=info msg="zeroconf server listening on port 33459" Jan 28 07:04:08 volumio volumio[13635]: error: MPD error: The expression evaluated to a falsy value: Jan 28 07:04:08 volumio volumio[13635]: assert.ok(self.idling) Jan 28 07:04:08 volumio volumio[13635]: error: The expression evaluated to a falsy value: Jan 28 07:04:08 volumio volumio[13635]: assert.ok(self.idling) Jan 28 07:04:08 volumio volumio[13635]: info: MPD running with PID13858 Jan 28 07:04:08 volumio volumio[13635]: ,establishing connection Jan 28 07:04:08 volumio volumio[13635]: error: updateQueue error: null Jan 28 07:04:08 volumio volumio[13635]: info: Completed starting Core Plugins Jan 28 07:04:08 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:04:08 volumio volumio[13635]: info: ----- MyVolumio plugins startup ---- Jan 28 07:04:08 volumio volumio[13635]: info: ------------------------------------------- Jan 28 07:04:08 volumio volumio[13635]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+07:00" level=debug msg="obtained new client token: AAD8Of2+lRezhK4XUKU8+9VE9kICLS+o5k5ZYE83Ucwi17YN7bFmxxMY6T/33duX8q269gfxPk0iBC1gJusLZ5ECp5DjeID7XXORKr+5sLuoMKz0O6gmPxcMYeqx62vY/B7Y42SCRzaJB1d/blAQh4siN17wrT+dtG9rViP1K7Qdmyr2Bqo7tHLllk1BxIgcyWlWeVbxYK5R+QTKgwjQsYULDnupBZAqZOJj4ROwHYnxX3wWk8ENKbIb59A=" Jan 28 07:04:08 volumio volumio[13635]: error: updateQueue error: null Jan 28 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+07:00" level=debug msg="completed keyexchange" Jan 28 07:04:08 volumio go-librespot[13952]: time="2026-01-28T07:04:08+07:00" level=debug msg="completed challenge" Jan 28 07:04:09 volumio go-librespot[13952]: time="2026-01-28T07:04:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:04:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:04:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:04:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:10 volumio volumio[13635]: info: Initializing connection to go-librespot Websocket Jan 28 07:04:10 volumio volumio[13635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:04:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 07:04:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:12 volumio go-librespot[13963]: go-librespot daemon starting... Jan 28 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04:12+07:00" level=debug msg="app state loaded" Jan 28 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04: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 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04: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 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04: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 07:04:12 volumio go-librespot[13964]: time="2026-01-28T07:04:12+07:00" level=info msg="zeroconf server listening on port 43661" Jan 28 07:04:13 volumio go-librespot[13964]: time="2026-01-28T07:04:13+07:00" level=debug msg="obtained new client token: AADjw+y/5WV3VIgE1inQoPg4HAtjULpBEAjsE958Lo3CKxDfS5N6+9Ukc1/8vs+UcpIUig5z+LkYKz5Ur4ym6TzG+jkp39tzzKPlqD0yD1Mgw9gHArKsE+UIMo6CmZp8rE6irrY+42G9J146kZIP5LU6zQqyWE4hcfUDU1ZkRkEOR0AP4X/Vfursk96DZmNQ80mPUP1twfpPBXyLD8CTqUbnH1SJS/SKGTZ9T3UPcPIYGXH8yzi65B7y" Jan 28 07:04:13 volumio go-librespot[13964]: time="2026-01-28T07:04:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:04:13 volumio go-librespot[13964]: time="2026-01-28T07:04:13+07:00" level=debug msg="completed keyexchange" Jan 28 07:04:13 volumio go-librespot[13964]: time="2026-01-28T07:04:13+07:00" level=debug msg="completed challenge" Jan 28 07:04:13 volumio volumio[13635]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 07:04:13 volumio go-librespot[13964]: time="2026-01-28T07:04: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 07:04:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:04:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:04:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:13 volumio volumio[13635]: info: Initializing connection to go-librespot Websocket Jan 28 07:04:13 volumio volumio[13635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:04:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 07:04:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:16 volumio go-librespot[13971]: go-librespot daemon starting... Jan 28 07:04:16 volumio go-librespot[13972]: time="2026-01-28T07:04:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:04:16 volumio go-librespot[13972]: time="2026-01-28T07:04:16+07:00" level=debug msg="app state loaded" Jan 28 07:04:16 volumio go-librespot[13972]: time="2026-01-28T07:04:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:04:16 volumio volumio[13635]: info: Initializing connection to go-librespot Websocket Jan 28 07:04:16 volumio go-librespot[13972]: time="2026-01-28T07:04:16+07:00" level=debug msg="new websocket client" Jan 28 07:04:16 volumio volumio[13635]: info: Connection to go-librespot Websocket established Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+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 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+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 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+07:00" level=info msg="zeroconf server listening on port 36443" Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+07:00" level=debug msg="obtained new client token: AADVBf9q+5y95XTvPFfUTkW/JfO5p28DZr+0rTZ5mqcRiZGUNirTZmeDM2CxFBzjkW4OMJchiRyenZie+p7K3FKtmqc6m28RQsNPha1lWxz9VQN92PzzLGPPjcvpOzL5O4WC5HHH3ZqiOU4y63Pcqj2tr1d0s6MOQfkaMBoCJnQYcS5XD/up/ABLo6y9zomMaLK7eoNrhUcUJu5MtaI7+G5GrYxzyuUNX0C2uvdgV2L3FFegRtoW+fbP" Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:04:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+07:00" level=debug msg="completed keyexchange" Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04:17+07:00" level=debug msg="completed challenge" Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 07:04:17 volumio volumio[13635]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 07:04:17 volumio go-librespot[13972]: time="2026-01-28T07:04: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 07:04:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:04:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:04:19 volumio volumio[13635]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 07:04:19 volumio volumio[13635]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 07:04:19 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:19 volumio volumio[13635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:04:19 volumio volumio[13635]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 07:04:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:19 volumio volumio[13635]: info: MyVolumio login type: Token Jan 28 07:04:19 volumio volumio[13635]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 07:04:19 volumio volumio[13635]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 07:04:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 07:04:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:04:20 volumio go-librespot[13995]: go-librespot daemon starting... Jan 28 07:04:20 volumio go-librespot[13996]: time="2026-01-28T07:04:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:04:20 volumio go-librespot[13996]: time="2026-01-28T07:04:20+07:00" level=debug msg="app state loaded" Jan 28 07:04:20 volumio go-librespot[13996]: time="2026-01-28T07:04:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:04:21 volumio volumio[13635]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 07:04:21 volumio volumio[13635]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 07:04:21 volumio volumio[13635]: info: Streaming services startup Jan 28 07:04:21 volumio volumio[13635]: info: Starting Streaming Daemon Jan 28 07:04:21 volumio sudo[14005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 07:04:21 volumio sudo[14005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:04:21 volumio volumio[13635]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 07:04:21 volumio sudo[14005]: pam_unix(sudo:session): session closed for user root Jan 28 07:04:21 volumio volumio[13635]: info: Getting Spotify volume Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04: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 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04: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 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04: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 07:04:21 volumio volumio[13635]: info: Connection to go-librespot Websocket closed Jan 28 07:04:21 volumio volumio[13635]: error: Cannot start Volumio Streaming Daemon Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04:21+07:00" level=info msg="zeroconf server listening on port 37883" Jan 28 07:04:21 volumio volumio[13635]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 07:04:21 volumio volumio[13635]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 07:04:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:21 volumio volumio[13635]: 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 07:04:21 volumio volumio[13635]: info: CoreCommandRouter::volumioGetState Jan 28 07:04:21 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:21 volumio volumio[13635]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 07:04:21 volumio volumio[13635]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 07:04:21 volumio volumio[13635]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 07:04:21 volumio volumio[13635]: info: Aligning Spotify Volume to Volumio Volume Jan 28 07:04:21 volumio volumio[13635]: info: CoreCommandRouter::volumioGetState Jan 28 07:04:21 volumio volumio[13635]: info: CorePlayQueue::getTrack 0 Jan 28 07:04:21 volumio volumio[13635]: info: Setting Spotify Volume from Volumio: 100 Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04:21+07:00" level=debug msg="obtained new client token: AAAeSWB9/xQYaJMXy+eKkixkwsaLG0jzFLgpUOAJ2EVAUjUl4yxd45nyd4yfvGXTWY5/vULiF5WonVvRRnE9mGFk6YUJ4zljIclxF5bZr2C3slgwF8AVQcI/8jZ29PKykiLy91fltQfL/CQ6L8LuuQdxRqQhYNrX1JZ59MF5pxou8uU50QtThmaYh8cQyoYyhz4uVYwVrETbcnrfNwC96BnZeFOSIO+p373nP9awG9mzondtyfTclKCdo2g=" Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04:21+07:00" level=debug msg="completed keyexchange" Jan 28 07:04:21 volumio go-librespot[13996]: time="2026-01-28T07:04:21+07:00" level=debug msg="completed challenge" Jan 28 07:04:22 volumio go-librespot[13996]: time="2026-01-28T07:04: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 07:04:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:04:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:04:22 volumio volumio[13635]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:04:22 volumio volumio[13635]: Error: socket hang up Jan 28 07:04:22 volumio volumio[13635]: at connResetException (node:internal/errors:720:14) Jan 28 07:04:22 volumio volumio[13635]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 07:04:22 volumio volumio[13635]: at Socket.emit (node:events:526:35) Jan 28 07:04:22 volumio volumio[13635]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 07:04:22 volumio volumio[13635]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 07:04:22 volumio volumio[13635]: code: 'ECONNRESET', Jan 28 07:04:22 volumio volumio[13635]: response: undefined Jan 28 07:04:22 volumio volumio[13635]: } Jan 28 07:04:22 volumio volumio[13635]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:04:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:04:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:04:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:04:23 volumio sudo[14025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 07:03' Jan 28 07:04:23 volumio sudo[14025]: 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"