Jan 26 22:37:00 volumio sudo[4449]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 22:37:00 volumio sudo[4449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:00 volumio sudo[4449]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:00 volumio sudo[4451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 22:37:00 volumio sudo[4451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "services"... Jan 26 22:37:00 volumio sudo[4451]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "alsa_controller"... Jan 26 22:37:00 volumio sudo[4460]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 22:37:00 volumio sudo[4460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37: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 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37: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 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37: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 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37:00+07:00" level=info msg="zeroconf server listening on port 34879" Jan 26 22:37:00 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "wizard"... Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "networkfs"... Jan 26 22:37:00 volumio volumio[4405]: info: Starting Udev Watcher for removable devices Jan 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37:00+07:00" level=debug msg="obtained new client token: AAB8AeXpTQHrRjeE1fO+87ah7seUG2jdMctyq9Ob34HprkOvUyOGKK8l7GLxb3/t3pAJh6BKSR1jchyBfoUxkOEyi560o5Lk2WvnbsJEh22HlQzhPf4WY8WB7U8Omfo4JC1/8r7Uov7Jh2NV9ERl3Yd2LM99Z3TqOL0izNN+Xlt0KL+DuzrY+Eghkba/otqqUlrJtJbTYCwO0n7PeFylpNi7WhgDHIaWCKzp4jCb7lECFJhZc8aNan/jyj4=" Jan 26 22:37:00 volumio volumio[4405]: info: Ignoring mount for partition: boot Jan 26 22:37:00 volumio volumio[4405]: info: Ignoring mount for partition: volumio Jan 26 22:37:00 volumio volumio[4405]: info: Ignoring mount for partition: volumio_data Jan 26 22:37:00 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "volumio_command_line_client"... Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "upnp"... Jan 26 22:37:00 volumio volumio[4405]: info: [1769441820384] Starting Upmpd Daemon Jan 26 22:37:00 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "my_music"... Jan 26 22:37:00 volumio volumio[4405]: info: Loading plugin "mpd"... Jan 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37:00+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37:00+07:00" level=debug msg="completed challenge" Jan 26 22:37:00 volumio go-librespot[4441]: time="2026-01-26T22:37: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 26 22:37:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:01 volumio volumio[4405]: info: Loading plugin "upnp_browser"... Jan 26 22:37:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:02 volumio sudo[4460]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 22:37:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:03 volumio go-librespot[4483]: go-librespot daemon starting... Jan 26 22:37:03 volumio go-librespot[4484]: time="2026-01-26T22:37:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:03 volumio go-librespot[4484]: time="2026-01-26T22:37:03+07:00" level=debug msg="app state loaded" Jan 26 22:37:03 volumio go-librespot[4484]: time="2026-01-26T22:37:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:03 volumio volumio[4405]: info: Starting UPNP Browser Jan 26 22:37:03 volumio volumio[4405]: info: Loading plugin "alarm-clock"... Jan 26 22:37:04 volumio volumio[4405]: info: Loading plugin "airplay_emulation"... Jan 26 22:37:04 volumio volumio[4405]: info: Starting Shairport Sync Jan 26 22:37:04 volumio volumio[4405]: info: Loading plugin "last_100"... Jan 26 22:37:04 volumio volumio[4405]: info: Loading plugin "webradio"... Jan 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37: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 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37: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 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37: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 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37:04+07:00" level=info msg="zeroconf server listening on port 37057" Jan 26 22:37:04 volumio volumio[4405]: info: Loading plugin "i2s_dacs"... Jan 26 22:37:04 volumio volumio[4405]: info: Loading plugin "volumiodiscovery"... Jan 26 22:37:04 volumio volumio[4405]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:04 volumio volumio[4405]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:04 volumio node[4405]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:04 volumio volumio[4405]: *** WARNING *** For more information see Jan 26 22:37:04 volumio volumio[4405]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:04 volumio volumio[4405]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:04 volumio volumio[4405]: *** WARNING *** For more information see Jan 26 22:37:04 volumio node[4405]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:04 volumio node[4405]: *** WARNING *** For more information see Jan 26 22:37:04 volumio node[4405]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:04 volumio node[4405]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:04 volumio node[4405]: *** WARNING *** For more information see Jan 26 22:37:04 volumio volumio[4405]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 22:37:04 volumio volumio[4405]: info: Discovery: Started advertising with name: Volumio Jan 26 22:37:04 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:37:04 volumio volumio[4405]: info: Loading plugin "spop"... Jan 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37:04+07:00" level=debug msg="obtained new client token: AACh5pXqSjTHZiU5uL6U+s7Prfcu64QPnH9OT3RfpZHnkj3Zs65JrdtnpQktB7L8xb9a53oZS0ZqwyWwnPMVq57n6DQpA3uHsZPcT/loUO1bqpy8RNtxOeCWByZf4OW+Hu6JI2vDoN890QvFHWYZ84Q/dIKtcssUxpVdu8AZfOOCSwcOkH1ILEudfJ3wO41HsFCi9QNI28KDzGLQWPSKCmM9YduSM3HNQ9zzAOLOO7Pzh3Vl1G3imE2wkYc=" Jan 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37:04+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:04 volumio go-librespot[4484]: time="2026-01-26T22:37:04+07:00" level=debug msg="completed challenge" Jan 26 22:37:05 volumio go-librespot[4484]: time="2026-01-26T22:37: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 26 22:37:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:06 volumio volumio[4405]: info: Loading plugin "ytcr"... Jan 26 22:37:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 22:37:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:08 volumio go-librespot[4493]: go-librespot daemon starting... Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37:08+07:00" level=debug msg="app state loaded" Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 22:37:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:08 volumio go-librespot[4494]: time="2026-01-26T22:37:08+07:00" level=info msg="zeroconf server listening on port 44329" Jan 26 22:37:09 volumio volumio[4405]: info: Loading plugin "ytmusic"... Jan 26 22:37:09 volumio go-librespot[4494]: time="2026-01-26T22:37:09+07:00" level=debug msg="obtained new client token: AAAnvhZ+eX+pzdx0pKofBSvKNb5u1zE8RRSLc2SZk+iQ1MqEo+ouWR/6kBHcncfrupjcYhCUyPx3dowLg3vLb5N5p5VLGUj5oU1/JH/YmlbaDLa4tSs60BJX2xVYEkJYzwvqa5tnSQjdi6ui6vtz8a7SDc7zJ82xxZWParqLU5VB8u6ULHOnAuvOa7UxeFMyMyU2dLOEuWKjN06oeccFzf0xk2/h/4SfNeLHHK4MqfIvwZMeJX3fH5os" Jan 26 22:37:09 volumio go-librespot[4494]: time="2026-01-26T22:37:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:09 volumio go-librespot[4494]: time="2026-01-26T22:37:09+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:09 volumio go-librespot[4494]: time="2026-01-26T22:37:09+07:00" level=debug msg="completed challenge" Jan 26 22:37:09 volumio go-librespot[4494]: time="2026-01-26T22:37: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 26 22:37:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:10 volumio volumio-remote-updater[628]: [2026-01-26 22:37:10] [connect] Successful connection Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "outputs"... Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "albumart"... Jan 26 22:37:10 volumio volumio[4405]: info: Plugin example_plugin is not enabled Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "inputs"... Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "updater_comm"... Jan 26 22:37:10 volumio volumio[4405]: info: Plugin mpdemulation is not enabled Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "rest_api"... Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "websocket"... Jan 26 22:37:10 volumio volumio[4405]: info: Starting Socket.io Server version 1.7.4 Jan 26 22:37:10 volumio volumio[4405]: info: Loading plugin "RoonBridge"... Jan 26 22:37:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:11 volumio volumio[4405]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 22:37:11 volumio volumio[4405]: info: Loading i18n strings for locale en Jan 26 22:37:11 volumio volumio[4405]: Updating browse sources language Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::initPlayerControls Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:37:11 volumio volumio[4405]: Express server listening on port 3000 Jan 26 22:37:11 volumio volumio[4405]: [Metrics] WebUI: 15s 899.66ms Jan 26 22:37:11 volumio volumio[4516]: Forking 3 albumart workers Jan 26 22:37:11 volumio volumio[4405]: info: CoreStateMachine::resetVolumioState Jan 26 22:37:11 volumio volumio[4405]: info: CoreStateMachine::getcurrentVolume Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:37:11 volumio sudo[4544]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 22:37:11 volumio sudo[4534]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 22:37:11 volumio sudo[4534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:11 volumio volumio[4405]: info: Volumio Network Manager: Network status updated: 1 Jan 26 22:37:11 volumio sudo[4544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:11 volumio sudo[4534]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:11 volumio sudo[4544]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:11 volumio volumio[4405]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:37:11 volumio volumio[4405]: info: CoreStateMachine::pushState Jan 26 22:37:11 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:11 volumio volumio[4405]: info: CoreStateMachine::updateTrackBlock Jan 26 22:37:11 volumio volumio[4405]: info: CorePlayQueue::getTrackBlock Jan 26 22:37:11 volumio volumio[4405]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:37:11 volumio volumio-remote-updater[628]: [2026-01-26 22:37:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769441830 101 Jan 26 22:37:12 volumio volumio[4405]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:12 volumio volumio[4405]: info: Reloading queue from file Jan 26 22:37:12 volumio volumio[4405]: info: CoreStateMachine::setRepeat null single undefined Jan 26 22:37:12 volumio volumio[4405]: info: CoreStateMachine::pushState Jan 26 22:37:12 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:12 volumio volumio[4405]: info: CoreStateMachine::setRandom null Jan 26 22:37:12 volumio volumio[4405]: info: CoreStateMachine::pushState Jan 26 22:37:12 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:12 volumio volumio[4405]: info: Setting Device type: Raspberry PI Jan 26 22:37:12 volumio volumio[4405]: info: Completed loading Core Plugins Jan 26 22:37:12 volumio volumio[4405]: info: Preparing to generate the ALSA configuration file Jan 26 22:37:12 volumio volumio[4405]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:37:12 volumio volumio[4405]: info: CoreStateMachine::pushState Jan 26 22:37:12 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:12 volumio volumio[4405]: info: Asound.conf file unchanged, so no further update is needed Jan 26 22:37:12 volumio volumio[4405]: info: Output device has changed, restarting MPD Jan 26 22:37:12 volumio sudo[4577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 22:37:12 volumio volumio[4405]: info: Output device has changed, restarting Shairport Sync Jan 26 22:37:12 volumio sudo[4577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:12 volumio sudo[4579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 22:37:12 volumio sudo[4579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:12 volumio sudo[4579]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:12 volumio volumio[4405]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:37:12 volumio sudo[4581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 22:37:12 volumio sudo[4581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:12 volumio volumio[4405]: info: ___________ START PLUGINS ___________ Jan 26 22:37:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 22:37:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:12 volumio volumio[4405]: info: ControllerMpd::onStart: Initializing MPD Jan 26 22:37:12 volumio volumio[4405]: info: Creating MPD Configuration file Jan 26 22:37:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:12 volumio go-librespot[4589]: go-librespot daemon starting... Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:12 volumio volumio[4405]: info: [1769441832739] CoreMusicLibrary::Adding element Media Servers Jan 26 22:37:12 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:12 volumio sudo[4577]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:12 volumio go-librespot[4594]: time="2026-01-26T22:37:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:12 volumio go-librespot[4594]: time="2026-01-26T22:37:12+07:00" level=debug msg="app state loaded" Jan 26 22:37:12 volumio go-librespot[4594]: time="2026-01-26T22:37:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:12 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 22:37:12 volumio volumio[4405]: info: UPNP Browser: Client initialized successfully Jan 26 22:37:12 volumio sudo[4591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 22:37:12 volumio sudo[4591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:12 volumio sudo[4591]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:12 volumio sudo[4593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 22:37:12 volumio sudo[4593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:13 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 22:37:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 22:37:13 volumio systemd[1]: mpd.service: Consumed 7.481s CPU time. Jan 26 22:37:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 22:37:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 22:37:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:13 volumio volumio[4405]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 22:37:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 22:37:13 volumio volumio[4405]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:13 volumio volumio[4405]: info: [1769441833197] CoreMusicLibrary::Adding element Last_100 Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:13 volumio volumio[4405]: info: [1769441833232] CoreMusicLibrary::Adding element Webradio Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:37:13 volumio volumio[4405]: info: Initializing BBC Radios Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37: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 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37: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 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37: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 26 22:37:13 volumio volumio[4405]: info: Creating Spotify config file Jan 26 22:37:13 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37:13+07:00" level=info msg="zeroconf server listening on port 40887" Jan 26 22:37:13 volumio sudo[4611]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 22:37:13 volumio sudo[4611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 22:37:13 volumio sudo[4611]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37:13+07:00" level=debug msg="obtained new client token: AAA13SCwFlibI637VAvfpLGVOzyApFZh2iplgSIvKakhjm6B7bp413Fhyy0yJ4mGJye8+3rKQeaUaLGigpxRP65ldfBUu6b/Cc/Skscbv0OdjSfIyI8XnUevD/+xLbaojh9ioEn6tKzbNQisag8VT09YmeOzU+127c3HGGxed4QE6cCbEP/R9tPcEX+iFvUliz+ai2A6WfXCOuS7ZtYUhD642yBQVzL1XNMHQ4heyxLCmcZiKNhIS1o0+2I=" Jan 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37:13+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 26 22:37:13 volumio go-librespot[4594]: time="2026-01-26T22:37:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 22:37:14 volumio go-librespot[4594]: time="2026-01-26T22:37:14+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:14 volumio go-librespot[4594]: time="2026-01-26T22:37:14+07:00" level=debug msg="completed challenge" Jan 26 22:37:14 volumio go-librespot[4594]: time="2026-01-26T22:37: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 26 22:37:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:14 volumio volumio[4529]: Starting albumart workers Jan 26 22:37:14 volumio volumio[4405]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:14 volumio volumio[4405]: info: [1769441834792] CoreMusicLibrary::Adding element YouTube Music Jan 26 22:37:14 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:14 volumio volumio[4405]: Cannot find translation for source YouTube Music Jan 26 22:37:14 volumio volumio[4405]: info: Volumio Calling Home Jan 26 22:37:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:14 volumio sudo[4630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 22:37:14 volumio sudo[4630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:14 volumio volumio[4531]: Starting albumart workers Jan 26 22:37:15 volumio sudo[4630]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:15 volumio volumio[4532]: Starting albumart workers Jan 26 22:37:15 volumio volumio[4405]: info: MPD Permissions set Jan 26 22:37:15 volumio volumio[4405]: info: MPD Permissions set Jan 26 22:37:15 volumio volumio[4405]: info: Upmpdcli Daemon Started Jan 26 22:37:15 volumio volumio[4405]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 22:37:15 volumio volumio[4405]: info: Discovery: Found device Volumio Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::volumioGetState Jan 26 22:37:15 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:15 volumio volumio[4405]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 22:37:15 volumio volumio[4405]: info: Discovery: Found device Volumio Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::volumioGetState Jan 26 22:37:15 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:15 volumio volumio[4405]: info: Volumio called home Jan 26 22:37:15 volumio volumio[4405]: info: Spotify config file written Jan 26 22:37:15 volumio volumio[4405]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:15 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio sudo[4636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 22:37:16 volumio sudo[4636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:16 volumio volumio[4405]: info: No need to fix Spotify hosts Jan 26 22:37:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:16 volumio go-librespot[4648]: go-librespot daemon starting... Jan 26 22:37:16 volumio sudo[4636]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:16 volumio go-librespot[4649]: time="2026-01-26T22:37:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:16 volumio go-librespot[4649]: time="2026-01-26T22:37:16+07:00" level=debug msg="app state loaded" Jan 26 22:37:16 volumio go-librespot[4649]: time="2026-01-26T22:37:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=info msg="zeroconf server listening on port 43541" Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=debug msg="obtained new client token: AACdyqGvBQjBa/P2d4LxUsoWlTA+w24Aes5UeAPFzZtpomaW7dQ7Mehzx9kNHJxGCXQDgEqogI7Td98qUoN0m698007IJRyzEibmQf5wGaxg15h2d1RnRX3eFrXRa5pRxbZX5pvo1OKeosO6W/9Y3m7incafm6U90/7y0Py3D67SYF6X4hwpHxVI8r4vCpJZm3Jt8EE0zGG8/rm6wXbMa8sxWwhd2/56TQZhHWV4Jf0pl3BmL7QTfwIzAoo=" Jan 26 22:37:17 volumio volumio[4405]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:37:17 volumio volumio[4405]: SPOTIFY: BQCF3ldf6lmt-NhfycoQwTAWe5wlz4EXnHbSQyh52nDYBoYC5K-TzMGQDQ4fpf_pTBvzqe0heH4GWKTH_zJdFld2BYpp1rfYmvaPbChYUWGsian4yfS3lI9pAUKQgSQ8Wgi1Q5TZnfxRqaUnze2ca9F8RE9KOOM-YHEeZyoqltVe7T9s-_gF96JktLbCB5hmZe7Rqu3JiGagUTGD2lRByTiret6dzA6tD141N3RWhn6HA6FMEkP88Gm3vDbKERvq9unfJLlrrcViG1WPIZSgVlS9pUCXxLX2Mpr9HRuNMXRsAaIIR9OYpds1 Jan 26 22:37:17 volumio volumio[4405]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:37:17 volumio volumio[4405]: info: New Spotify access token = BQCF3ldf6lmt-NhfycoQwTAWe5wlz4EXnHbSQyh52nDYBoYC5K-TzMGQDQ4fpf_pTBvzqe0heH4GWKTH_zJdFld2BYpp1rfYmvaPbChYUWGsian4yfS3lI9pAUKQgSQ8Wgi1Q5TZnfxRqaUnze2ca9F8RE9KOOM-YHEeZyoqltVe7T9s-_gF96JktLbCB5hmZe7Rqu3JiGagUTGD2lRByTiret6dzA6tD141N3RWhn6HA6FMEkP88Gm3vDbKERvq9unfJLlrrcViG1WPIZSgVlS9pUCXxLX2Mpr9HRuNMXRsAaIIR9OYpds1 Jan 26 22:37:17 volumio volumio[4405]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=debug msg="completed challenge" Jan 26 22:37:17 volumio volumio[4405]: info: Starting Shairport Sync Jan 26 22:37:17 volumio volumio[4405]: info: Starting Shairport Sync Jan 26 22:37:17 volumio volumio[4405]: info: Starting Shairport Sync Jan 26 22:37:17 volumio go-librespot[4649]: time="2026-01-26T22:37:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:37:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:17 volumio sudo[4676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:37:17 volumio sudo[4676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:17 volumio sudo[4678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:37:17 volumio sudo[4678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:17 volumio sudo[4680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:37:17 volumio sudo[4680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 22:37:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 22:37:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:37:17 volumio systemd[1]: shairport-sync.service: Consumed 2.361s CPU time. Jan 26 22:37:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:37:18 volumio sudo[4676]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:18 volumio volumio[4405]: info: Shairport-Sync Started Jan 26 22:37:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 22:37:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 22:37:18 volumio volumio[4405]: Error adding Membership: Error: addMembership EINVAL Jan 26 22:37:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:37:18 volumio volumio[4405]: info: CoreCommandRouter::volumioGetState Jan 26 22:37:18 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:37:18 volumio sudo[4678]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:18 volumio sudo[4680]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:18 volumio volumio[4405]: info: Shairport-Sync Started Jan 26 22:37:18 volumio volumio[4405]: info: Shairport-Sync Started Jan 26 22:37:18 volumio volumio[4405]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 26 22:37:18 volumio volumio[4405]: info: Spotify Successfully logged in Jan 26 22:37:18 volumio volumio[4405]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:18 volumio volumio[4405]: info: [1769441838466] CoreMusicLibrary::Adding element Spotify Jan 26 22:37:18 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:18 volumio volumio[4405]: Cannot find translation for source YouTube Music Jan 26 22:37:18 volumio volumio[4405]: Cannot find translation for source Spotify Jan 26 22:37:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:19 volumio volumio[4405]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 22:37:19 volumio volumio[4405]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:37:19 volumio volumio[4405]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:37:19 volumio volumio[4405]: info: CoreCommandRouter::volumioGetState Jan 26 22:37:19 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:19 volumio volumio[4405]: info: CoreStateMachine::pushState Jan 26 22:37:19 volumio volumio[4405]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:19 volumio volumio[4405]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:20 volumio volumio[4405]: info: go-librespot daemon successfully initialized Jan 26 22:37:20 volumio mpd[4628]: 2026-01-26T22:37:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 22:37:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 22:37:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 22:37:20 volumio sudo[4593]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:20 volumio sudo[4581]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:21 volumio go-librespot[4718]: go-librespot daemon starting... Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=debug msg="app state loaded" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:21 volumio volumio[4405]: error: MPD error: The expression evaluated to a falsy value: Jan 26 22:37:21 volumio volumio[4405]: assert.ok(self.idling) Jan 26 22:37:21 volumio volumio[4405]: error: The expression evaluated to a falsy value: Jan 26 22:37:21 volumio volumio[4405]: assert.ok(self.idling) Jan 26 22:37:21 volumio volumio[4405]: error: updateQueue error: null Jan 26 22:37:21 volumio volumio[4405]: info: MPD running with PID4628 Jan 26 22:37:21 volumio volumio[4405]: ,establishing connection Jan 26 22:37:21 volumio volumio[4405]: info: Completed starting Core Plugins Jan 26 22:37:21 volumio volumio[4405]: info: ------------------------------------------- Jan 26 22:37:21 volumio volumio[4405]: info: ----- MyVolumio plugins startup ---- Jan 26 22:37:21 volumio volumio[4405]: info: ------------------------------------------- Jan 26 22:37:21 volumio volumio[4405]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 22:37:21 volumio volumio[4405]: error: updateQueue error: null Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=info msg="zeroconf server listening on port 34291" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=debug msg="obtained new client token: AADLt/ZqEoWqSYAns1KOnwxPmLU1l7F+EJ3sKIMtyICyTytkPrRSlcsLpuldlwAgknesKBsU/8WOp0kyo5hnrYJGhNfs8tWtRHVOUxO3orGy2rZkIFuxwj2LFa+i7NtcTR4JRXoqN8iq0T0kHFB++7yflUk+HXNE3ocKETePvlHWny59z2nMoe80AAMt3WeO6WQKRjfs1YTyODEdHgpms8ShtQ6tJJA5FCPzFsK0zAm5IPmRggISemvpr0M=" Jan 26 22:37:21 volumio go-librespot[4721]: time="2026-01-26T22:37:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:22 volumio go-librespot[4721]: time="2026-01-26T22:37:22+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:22 volumio go-librespot[4721]: time="2026-01-26T22:37:22+07:00" level=debug msg="completed challenge" Jan 26 22:37:22 volumio go-librespot[4721]: time="2026-01-26T22:37: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 26 22:37:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:23 volumio volumio[4405]: info: Initializing connection to go-librespot Websocket Jan 26 22:37:23 volumio volumio[4405]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:37:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 22:37:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:25 volumio go-librespot[4728]: go-librespot daemon starting... Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=debug msg="app state loaded" Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:25 volumio go-librespot[4729]: time="2026-01-26T22:37:25+07:00" level=info msg="zeroconf server listening on port 39999" Jan 26 22:37:26 volumio volumio[4405]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 22:37:26 volumio go-librespot[4729]: time="2026-01-26T22:37:26+07:00" level=debug msg="obtained new client token: AABlUsZVPGV2Cwz5BG+PA3HHya0xIYarzrnFlxDf9DZL/h9gpgYiPVQDDAidhcfQmxpnM8u8ddtfeRzvFLhEmsw9SPDFr1Je41aWa/puprQhMcvrcNK0YtMZj9vGWhLAiR1iIF88hfX17AWxfN2JdvVLmZNcTT7ZOoG0UCyB6NUH8fR2KugIJd1GXBPArgJsOzpQ94IanQJ50MNJC9T4p/KKclwn/m61ioOJlZpdNLNexNq/OGhKQiz/" Jan 26 22:37:26 volumio go-librespot[4729]: time="2026-01-26T22:37:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:26 volumio go-librespot[4729]: time="2026-01-26T22:37:26+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:26 volumio go-librespot[4729]: time="2026-01-26T22:37:26+07:00" level=debug msg="completed challenge" Jan 26 22:37:26 volumio go-librespot[4729]: time="2026-01-26T22:37: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 26 22:37:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:26 volumio volumio[4405]: info: Initializing connection to go-librespot Websocket Jan 26 22:37:26 volumio volumio[4405]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:37:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 26 22:37:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:29 volumio go-librespot[4737]: go-librespot daemon starting... Jan 26 22:37:29 volumio go-librespot[4738]: time="2026-01-26T22:37:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:29 volumio go-librespot[4738]: time="2026-01-26T22:37:29+07:00" level=debug msg="app state loaded" Jan 26 22:37:29 volumio go-librespot[4738]: time="2026-01-26T22:37:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:29 volumio volumio[4405]: info: Initializing connection to go-librespot Websocket Jan 26 22:37:29 volumio go-librespot[4738]: time="2026-01-26T22:37:29+07:00" level=debug msg="new websocket client" Jan 26 22:37:29 volumio volumio[4405]: info: Connection to go-librespot Websocket established Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=info msg="zeroconf server listening on port 43255" Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 22:37:30 volumio volumio[4405]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=debug msg="obtained new client token: AAC2PwDd/50+mmi1YaSGqSXFmionHEK3gyOiBSYkPrIuLPdbEWXo4bGBbGwdxNpAnTbeViNui3l8IXfhccCtVK8ExIOxJFbSAiqCDmARds7gBsXoP5N43SCy8nhrsczZ67XcfEZZNJD5N8Nj5hTPiE8B60Oic808z5ZMo82M0wKEEDeSi4vG8tt+c7dv4GF1J0VfDb0nUJp/ThBPq+KGg/GEfT4mdcdaHqcGUEYkN3TDbBuXv9xOEeJbeoY=" Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=debug msg="completed challenge" Jan 26 22:37:30 volumio go-librespot[4738]: time="2026-01-26T22:37:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:37:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:32 volumio volumio[4405]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 22:37:32 volumio volumio[4405]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 22:37:32 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:32 volumio volumio[4405]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:32 volumio volumio[4405]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 22:37:32 volumio volumio[4405]: info: MyVolumio login type: Token Jan 26 22:37:32 volumio volumio[4405]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 22:37:32 volumio volumio[4405]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 22:37:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:33 volumio volumio[4405]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 22:37:33 volumio volumio[4405]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 22:37:33 volumio volumio[4405]: info: Streaming services startup Jan 26 22:37:33 volumio volumio[4405]: info: Starting Streaming Daemon Jan 26 22:37:33 volumio sudo[4760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 22:37:33 volumio sudo[4760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:33 volumio volumio[4405]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 22:37:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 26 22:37:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:34 volumio sudo[4760]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:34 volumio go-librespot[4766]: go-librespot daemon starting... Jan 26 22:37:34 volumio volumio[4405]: info: Getting Spotify volume Jan 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37:34+07:00" level=debug msg="app state loaded" Jan 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:34 volumio volumio[4405]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:37:34 volumio volumio[4405]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:37:34 volumio volumio[4405]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 22:37:34 volumio volumio[4405]: errno: -111, Jan 26 22:37:34 volumio volumio[4405]: code: 'ECONNREFUSED', Jan 26 22:37:34 volumio volumio[4405]: syscall: 'connect', Jan 26 22:37:34 volumio volumio[4405]: address: '127.0.0.1', Jan 26 22:37:34 volumio volumio[4405]: port: 9879, Jan 26 22:37:34 volumio volumio[4405]: response: undefined Jan 26 22:37:34 volumio volumio[4405]: } Jan 26 22:37:34 volumio volumio[4405]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37: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 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37: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 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37: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 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37:34+07:00" level=info msg="zeroconf server listening on port 36093" Jan 26 22:37:34 volumio go-librespot[4767]: time="2026-01-26T22:37:34+07:00" level=debug msg="obtained new client token: AACPKD66PKADtQT6cVIFrFqdUMHDw0HQbfmJ3xazrBIZxVfblW+QRAfnkouvw34oN1KBrHxnZde3ORjC8MO2D6OMHyfVuKIKgwa+kWnOOsa5e2wmt9sm3Cszjkec0iFkFShzssoqfaM4F+0MPg+ppl402eLYZVeBw+cmmFjNUqEj7OeIJsOaVkXgTpVboANp3+9Kr8kHkCK7dLme4Rr2XIjVVr1CmCzaAhSFW8zKR7PnmZW/+wzfsPqs9jo=" Jan 26 22:37:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:35 volumio go-librespot[4767]: time="2026-01-26T22:37:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:35 volumio go-librespot[4767]: time="2026-01-26T22:37:35+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:35 volumio go-librespot[4767]: time="2026-01-26T22:37:35+07:00" level=debug msg="completed challenge" Jan 26 22:37:35 volumio go-librespot[4767]: time="2026-01-26T22:37: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 26 22:37:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:35 volumio sudo[4790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 22:36' Jan 26 22:37:35 volumio sudo[4790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:35 volumio sudo[4790]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:36 volumio volumio-remote-updater[628]: [2026-01-26 22:37:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 26 22:37:36 volumio volumio-remote-updater[628]: [2026-01-26 22:37:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 26 22:37:36 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:36 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 22:37:36 volumio systemd[1]: volumio.service: Consumed 1min 8.935s CPU time. Jan 26 22:37:36 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 22:37:36 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7643. Jan 26 22:37:36 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 22:37:36 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 22:37:36 volumio systemd[1]: volumio.service: Consumed 1min 8.935s CPU time. Jan 26 22:37:36 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 22:37:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 26 22:37:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:38 volumio go-librespot[4813]: go-librespot daemon starting... Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=debug msg="app state loaded" Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:38 volumio go-librespot[4814]: time="2026-01-26T22:37:38+07:00" level=info msg="zeroconf server listening on port 38019" Jan 26 22:37:39 volumio go-librespot[4814]: time="2026-01-26T22:37:39+07:00" level=debug msg="obtained new client token: AACMfHTVOYt/6n8AGMTcXXLVtpIRWQ48LZZAhRHBJYrWF2dMEtSLHDNb7mU9PMGzp6Kgl6jRSeWdFYMglgt6bZX+K8VM0IiAS6RVSspyDZobSMWy66e42CojjkGaW+z/ogxR/Ia6bz+PQp6Az+8Kiqs74+H3ej7IM6F1aX4neH5Sg/h/wjmZ8A00x6FGwmXk6uvPyUI7P1ytm+9ADQr3T4f58m7IZY0fVLm4pDQVXniYV7ov0BcqzCFR" Jan 26 22:37:39 volumio go-librespot[4814]: time="2026-01-26T22:37:39+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 26 22:37:39 volumio go-librespot[4814]: time="2026-01-26T22:37:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 22:37:39 volumio go-librespot[4814]: time="2026-01-26T22:37:39+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:39 volumio go-librespot[4814]: time="2026-01-26T22:37:39+07:00" level=debug msg="completed challenge" Jan 26 22:37:39 volumio go-librespot[4814]: time="2026-01-26T22:37:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:37:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:39 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:37:39 volumio volumio[4803]: info: ----- Volumio3 ---- Jan 26 22:37:39 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:37:39 volumio volumio[4803]: info: ----- System startup ---- Jan 26 22:37:39 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:37:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:41 volumio volumio-remote-updater[628]: [2026-01-26 22:37:41] [connect] Successful connection Jan 26 22:37:41 volumio volumio[4803]: info: MYVOLUMIO Environment detected Jan 26 22:37:41 volumio volumio[4803]: info: Plugin folders cleanup Jan 26 22:37:41 volumio volumio[4803]: info: Scanning into folder /volumio/app/plugins/ Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category audio_interface Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category miscellanea Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category music_service Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category plugins.json Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category system_controller Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category user_interface Jan 26 22:37:41 volumio volumio[4803]: info: Scanning into folder /data/plugins/ Jan 26 22:37:41 volumio volumio[4803]: info: Scanning category music_service Jan 26 22:37:41 volumio volumio[4803]: info: Plugin folders cleanup completed Jan 26 22:37:41 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:37:41 volumio volumio[4803]: info: ----- Core plugins startup ---- Jan 26 22:37:41 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:37:41 volumio volumio[4803]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 22:37:41 volumio volumio[4803]: info: Adding plugin upnp to MyMusic Plugins Jan 26 22:37:41 volumio volumio[4803]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 22:37:41 volumio volumio[4803]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 22:37:41 volumio volumio[4803]: info: Loading plugins from folder /data/plugins/ Jan 26 22:37:41 volumio volumio[4803]: info: Loading plugin "system"... Jan 26 22:37:41 volumio volumio[4803]: info: Loading plugin "appearance"... Jan 26 22:37:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 26 22:37:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:42 volumio go-librespot[4833]: go-librespot daemon starting... Jan 26 22:37:42 volumio go-librespot[4834]: time="2026-01-26T22:37:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:42 volumio go-librespot[4834]: time="2026-01-26T22:37:42+07:00" level=debug msg="app state loaded" Jan 26 22:37:42 volumio go-librespot[4834]: time="2026-01-26T22:37:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=info msg="zeroconf server listening on port 43553" Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "network"... Jan 26 22:37:43 volumio volumio[4803]: info: Refreshing Cached IP Addresses Jan 26 22:37:43 volumio sudo[4842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 22:37:43 volumio sudo[4842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "services"... Jan 26 22:37:43 volumio sudo[4842]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="obtained new client token: AACHRUUMfN2L6+KJLDA1+Jp2wuVvN5fBmYkCUIch35cT9Fjos1wxKouNpG2JPTNsoadfNXL6cix/fysXcJNSFyZknIb89LelrRQvcsDP6k8Zzt5a+licYQDoBObnQgbvD9UIp1kVaFuCr71BWnIg8zkWJo7JhCKkkOiO4/eAd/ZRD8OcgXQCssDD/ca2qH2Nxim25b8/1CtptUAZYSVEz4h1hPVcKtsAQVZQPuDJ1Y24gMu2lgQVdREJtJU=" Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "alsa_controller"... Jan 26 22:37:43 volumio sudo[4844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 22:37:43 volumio sudo[4844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:43 volumio sudo[4844]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:43 volumio sudo[4852]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 22:37:43 volumio sudo[4852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:43 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "wizard"... Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "networkfs"... Jan 26 22:37:43 volumio volumio[4803]: info: Starting Udev Watcher for removable devices Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=debug msg="completed challenge" Jan 26 22:37:43 volumio volumio[4803]: info: Ignoring mount for partition: boot Jan 26 22:37:43 volumio volumio[4803]: info: Ignoring mount for partition: volumio Jan 26 22:37:43 volumio volumio[4803]: info: Ignoring mount for partition: volumio_data Jan 26 22:37:43 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "volumio_command_line_client"... Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "upnp"... Jan 26 22:37:43 volumio volumio[4803]: info: [1769441863904] Starting Upmpd Daemon Jan 26 22:37:43 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "my_music"... Jan 26 22:37:43 volumio go-librespot[4834]: time="2026-01-26T22:37:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:37:43 volumio volumio[4803]: info: Loading plugin "mpd"... Jan 26 22:37:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:44 volumio volumio[4803]: info: Loading plugin "upnp_browser"... Jan 26 22:37:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:46 volumio sudo[4852]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 26 22:37:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:47 volumio go-librespot[4876]: go-librespot daemon starting... Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=debug msg="app state loaded" Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:47 volumio volumio[4803]: info: Starting UPNP Browser Jan 26 22:37:47 volumio volumio[4803]: info: Loading plugin "alarm-clock"... Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=info msg="zeroconf server listening on port 36481" Jan 26 22:37:47 volumio volumio[4803]: info: Loading plugin "airplay_emulation"... Jan 26 22:37:47 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:37:47 volumio volumio[4803]: info: Loading plugin "last_100"... Jan 26 22:37:47 volumio volumio[4803]: info: Loading plugin "webradio"... Jan 26 22:37:47 volumio go-librespot[4877]: time="2026-01-26T22:37:47+07:00" level=debug msg="obtained new client token: AACcd3EeUteOeFBvSJW3uqVCcE2abuYWAZsKQQJb5RUm7UMCxYi6R/rH0gS4/yiYqAiAFUx+GC+0zmUAi1eX5VlqAuouEJTaU+m+NMJlPcrKTq7OHbvE50l6OP6zcHAwdf0dWDDBrTsqt5OTE8jOnAGc7UfACrLKm0GUvKdqrl1sOOIgDly5SRBWRuh+4yrM5WqUGnj0FlSssahsbnyYrdYiIpjLZ6W4zSi7Cea8671KHFcQQhHzjKfzS3s=" Jan 26 22:37:48 volumio go-librespot[4877]: time="2026-01-26T22:37:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:48 volumio volumio[4803]: info: Loading plugin "i2s_dacs"... Jan 26 22:37:48 volumio volumio[4803]: info: Loading plugin "volumiodiscovery"... Jan 26 22:37:48 volumio go-librespot[4877]: time="2026-01-26T22:37:48+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:48 volumio go-librespot[4877]: time="2026-01-26T22:37:48+07:00" level=debug msg="completed challenge" Jan 26 22:37:48 volumio volumio[4803]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:48 volumio volumio[4803]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:48 volumio volumio[4803]: *** WARNING *** For more information see Jan 26 22:37:48 volumio volumio[4803]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:48 volumio volumio[4803]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:48 volumio volumio[4803]: *** WARNING *** For more information see Jan 26 22:37:48 volumio node[4803]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:48 volumio node[4803]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:48 volumio node[4803]: *** WARNING *** For more information see Jan 26 22:37:48 volumio node[4803]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 22:37:48 volumio node[4803]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:37:48 volumio node[4803]: *** WARNING *** For more information see Jan 26 22:37:48 volumio volumio[4803]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 22:37:48 volumio volumio[4803]: info: Discovery: Started advertising with name: Volumio Jan 26 22:37:48 volumio go-librespot[4877]: time="2026-01-26T22:37:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:37:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:48 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:37:48 volumio volumio[4803]: info: Loading plugin "spop"... Jan 26 22:37:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:50 volumio volumio[4803]: info: Loading plugin "ytcr"... Jan 26 22:37:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 26 22:37:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:51 volumio go-librespot[4888]: go-librespot daemon starting... Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=debug msg="app state loaded" Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:51 volumio go-librespot[4889]: time="2026-01-26T22:37:51+07:00" level=info msg="zeroconf server listening on port 45915" Jan 26 22:37:52 volumio go-librespot[4889]: time="2026-01-26T22:37:52+07:00" level=debug msg="obtained new client token: AAAn/0zPKEN4biBNk0lz0C3b8RZwSUhA9dY5icqcygdCBLdLXjkQd9NuEUbD/EwASkJ3jNwPIc+f6bAZf0VLi35ZLnxE6Wfaf6Qd5R/b+Qswq9KJ0sqRRWyiW+x9nwn7lzlEu0M6YDZR0MC5Z5Ho5t77HwsQvi6804aQUMicZZ4NW6StIptoQE3GuDXx3VN4MyMExaMe7U4MMts7gcq13WSsY3jv6RstBSwcLByZP6BrhW45HhuLBGPh" Jan 26 22:37:52 volumio go-librespot[4889]: time="2026-01-26T22:37:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:52 volumio go-librespot[4889]: time="2026-01-26T22:37:52+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:52 volumio go-librespot[4889]: time="2026-01-26T22:37:52+07:00" level=debug msg="completed challenge" Jan 26 22:37:52 volumio go-librespot[4889]: time="2026-01-26T22:37:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:37:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:52 volumio volumio[4803]: info: Loading plugin "ytmusic"... Jan 26 22:37:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:53 volumio volumio-remote-updater[628]: [2026-01-26 22:37:53] [connect] Successful connection Jan 26 22:37:53 volumio volumio[4803]: info: Loading plugin "outputs"... Jan 26 22:37:53 volumio volumio[4803]: info: Loading plugin "albumart"... Jan 26 22:37:53 volumio volumio[4803]: info: Plugin example_plugin is not enabled Jan 26 22:37:53 volumio volumio[4803]: info: Loading plugin "inputs"... Jan 26 22:37:53 volumio volumio[4803]: info: Loading plugin "updater_comm"... Jan 26 22:37:54 volumio volumio[4803]: info: Plugin mpdemulation is not enabled Jan 26 22:37:54 volumio volumio[4803]: info: Loading plugin "rest_api"... Jan 26 22:37:54 volumio volumio[4803]: info: Loading plugin "websocket"... Jan 26 22:37:54 volumio volumio[4803]: info: Starting Socket.io Server version 1.7.4 Jan 26 22:37:54 volumio volumio[4803]: info: Loading plugin "RoonBridge"... Jan 26 22:37:54 volumio volumio[4803]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 22:37:54 volumio volumio[4803]: info: Loading i18n strings for locale en Jan 26 22:37:54 volumio volumio[4803]: Updating browse sources language Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:54 volumio volumio[4911]: Forking 3 albumart workers Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::initPlayerControls Jan 26 22:37:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:54 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:37:55 volumio volumio[4803]: Express server listening on port 3000 Jan 26 22:37:55 volumio volumio[4803]: [Metrics] WebUI: 16s 23.19ms Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::resetVolumioState Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::getcurrentVolume Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:37:55 volumio sudo[4953]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 22:37:55 volumio sudo[4953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:55 volumio volumio[4803]: info: Volumio Network Manager: Network status updated: 1 Jan 26 22:37:55 volumio sudo[4956]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 22:37:55 volumio sudo[4956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:55 volumio sudo[4953]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:55 volumio sudo[4956]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 26 22:37:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:37:55 volumio go-librespot[4963]: go-librespot daemon starting... Jan 26 22:37:55 volumio volumio[4803]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::pushState Jan 26 22:37:55 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::updateTrackBlock Jan 26 22:37:55 volumio volumio[4803]: info: CorePlayQueue::getTrackBlock Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:37:55 volumio go-librespot[4964]: time="2026-01-26T22:37:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:37:55 volumio volumio-remote-updater[628]: [2026-01-26 22:37:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769441873 101 Jan 26 22:37:55 volumio go-librespot[4964]: time="2026-01-26T22:37:55+07:00" level=debug msg="app state loaded" Jan 26 22:37:55 volumio go-librespot[4964]: time="2026-01-26T22:37:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:37:55 volumio volumio[4803]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:55 volumio volumio[4803]: info: Reloading queue from file Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::setRepeat null single undefined Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::pushState Jan 26 22:37:55 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::setRandom null Jan 26 22:37:55 volumio volumio[4803]: info: CoreStateMachine::pushState Jan 26 22:37:55 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:55 volumio volumio[4803]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:55 volumio volumio[4803]: info: Setting Device type: Raspberry PI Jan 26 22:37:56 volumio volumio[4803]: info: Completed loading Core Plugins Jan 26 22:37:56 volumio volumio[4803]: info: Preparing to generate the ALSA configuration file Jan 26 22:37:56 volumio volumio[4803]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:37:56 volumio volumio[4803]: info: CoreStateMachine::pushState Jan 26 22:37:56 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::volumioPushState Jan 26 22:37:56 volumio volumio[4803]: info: Asound.conf file unchanged, so no further update is needed Jan 26 22:37:56 volumio volumio[4803]: info: Output device has changed, restarting MPD Jan 26 22:37:56 volumio sudo[4980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 22:37:56 volumio volumio[4803]: info: Output device has changed, restarting Shairport Sync Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:56 volumio sudo[4980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:56 volumio sudo[4982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 22:37:56 volumio sudo[4982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:56 volumio sudo[4982]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:56 volumio sudo[4984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 22:37:56 volumio sudo[4984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:37:56 volumio volumio[4803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:37:56 volumio volumio[4803]: info: ___________ START PLUGINS ___________ Jan 26 22:37:56 volumio sudo[4980]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=info msg="zeroconf server listening on port 41451" Jan 26 22:37:56 volumio volumio[4803]: info: ControllerMpd::onStart: Initializing MPD Jan 26 22:37:56 volumio volumio[4803]: info: Creating MPD Configuration file Jan 26 22:37:56 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 22:37:56 volumio sudo[4993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 22:37:56 volumio sudo[4993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:56 volumio sudo[4993]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:56 volumio volumio[4803]: info: [1769441876650] CoreMusicLibrary::Adding element Media Servers Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:56 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 22:37:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 22:37:56 volumio systemd[1]: mpd.service: Consumed 7.412s CPU time. Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="obtained new client token: AABGXnVB6CFSWuiTYV+sk60xYzRM1n5gvUlHvGMtyO7lGMvf2rtd7rVC17SlC/dvv2XpCiVWUeAUNBidpnBt32MryTCYH7a1v+L5IYFNxILt3csDvOpM/SfljidG31oWe6cZ8XnWsXz4crp0+4c9xtv331LqGhxzYJUvyMJDugkFoRQFmjMnpzgCVEo3XAODUMr6Db4ukDmjM7vlrAFcOmc0NrsXpsCIbcHq/ILXSS04I04DHawpNS9cvJQ=" Jan 26 22:37:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 22:37:56 volumio volumio[4803]: info: UPNP Browser: Client initialized successfully Jan 26 22:37:56 volumio sudo[4995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 22:37:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 22:37:56 volumio sudo[4995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:37:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 22:37:56 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 22:37:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 22:37:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 22:37:56 volumio volumio[4803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:56 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="completed keyexchange" Jan 26 22:37:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 22:37:56 volumio go-librespot[4964]: time="2026-01-26T22:37:56+07:00" level=debug msg="completed challenge" Jan 26 22:37:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:57 volumio volumio[4803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:57 volumio volumio[4803]: info: [1769441877009] CoreMusicLibrary::Adding element Last_100 Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:57 volumio go-librespot[4964]: time="2026-01-26T22:37: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 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:57 volumio volumio[4803]: info: [1769441877026] CoreMusicLibrary::Adding element Webradio Jan 26 22:37:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:37:57 volumio volumio[4803]: info: Initializing BBC Radios Jan 26 22:37:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:37:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:37:57 volumio volumio[4803]: info: Creating Spotify config file Jan 26 22:37:57 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:37:57 volumio sudo[5009]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 22:37:57 volumio sudo[5009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 22:37:57 volumio sudo[5009]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:58 volumio volumio[4922]: Starting albumart workers Jan 26 22:37:58 volumio volumio[4923]: Starting albumart workers Jan 26 22:37:58 volumio volumio[4921]: Starting albumart workers Jan 26 22:37:58 volumio volumio[4803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:37:58 volumio volumio[4803]: info: [1769441878673] CoreMusicLibrary::Adding element YouTube Music Jan 26 22:37:58 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:37:58 volumio volumio[4803]: Cannot find translation for source YouTube Music Jan 26 22:37:58 volumio volumio[4803]: info: Volumio Calling Home Jan 26 22:37:58 volumio sudo[5026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 22:37:58 volumio sudo[5026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:37:58 volumio sudo[5026]: pam_unix(sudo:session): session closed for user root Jan 26 22:37:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:37:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:37:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:37:59 volumio volumio[4803]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 22:37:59 volumio volumio[4803]: info: Discovery: Found device Volumio Jan 26 22:37:59 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:37:59 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:59 volumio volumio[4803]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 22:37:59 volumio volumio[4803]: info: Discovery: Found device Volumio Jan 26 22:37:59 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:37:59 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:37:59 volumio volumio[4803]: info: MPD Permissions set Jan 26 22:37:59 volumio volumio[4803]: info: MPD Permissions set Jan 26 22:37:59 volumio volumio[4803]: info: Upmpdcli Daemon Started Jan 26 22:37:59 volumio volumio[4803]: info: Volumio called home Jan 26 22:37:59 volumio volumio[4803]: info: Spotify config file written Jan 26 22:38:00 volumio volumio[4803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 22:38:00 volumio sudo[5032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio sudo[5032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 26 22:38:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:00 volumio go-librespot[5051]: go-librespot daemon starting... Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio sudo[5032]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=debug msg="app state loaded" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: No need to fix Spotify hosts Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=info msg="zeroconf server listening on port 40601" Jan 26 22:38:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="obtained new client token: AABTwi+ousoO6i4yNTyQqU+CABJ5ZIi4BisLvT3D/G9lheWXmJ58t0Zmx7yz/EI0b/C5l82dCulXrCBju+o5xH1KlSDBiWEomlqU/ETJH2AT15ZMSdcF9S2pv4ohjrBMJDq4MISTBaxDdQibqtTnT4ImRWy2QdWi2KqDpfZfgf6x+CiUYjX9O2/Fhd9sbsoA+0fpcF4xpNS17ce5nzH4T05UJ8ESvrrX3rgyy78ZsC8gTp8Phe5ge0+S" Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:01 volumio volumio[4803]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:38:01 volumio volumio[4803]: SPOTIFY: BQBZwN1SD4lRBq1zjr5GpiolnI_DhxifqvetZchkJGzyL1m4fAj5pSmGtVbUW53JEyoeWEQTNaNeXDFukyBCHaHxuXXFjWtK-I7tlmHvHrkzxc8E2pZwEvYFH7FbOYK-6Muxj4rfX-UJJmLr4H1pKwFhlBC4X-illwpOns2hrxgwWDIa-ooDnbp8s3gQp31PagoESrBihDsPg9xZ9arppGPWOSdtGr7mrvKD79r3RNlpPDKuKbRVjHXW0uGd7rFmikVmScZKSridyBsCaPjHadLd8EtbyzmFFNLPlLOrp2GHtH55hX1YUQ1f Jan 26 22:38:01 volumio volumio[4803]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:38:01 volumio volumio[4803]: info: New Spotify access token = BQBZwN1SD4lRBq1zjr5GpiolnI_DhxifqvetZchkJGzyL1m4fAj5pSmGtVbUW53JEyoeWEQTNaNeXDFukyBCHaHxuXXFjWtK-I7tlmHvHrkzxc8E2pZwEvYFH7FbOYK-6Muxj4rfX-UJJmLr4H1pKwFhlBC4X-illwpOns2hrxgwWDIa-ooDnbp8s3gQp31PagoESrBihDsPg9xZ9arppGPWOSdtGr7mrvKD79r3RNlpPDKuKbRVjHXW0uGd7rFmikVmScZKSridyBsCaPjHadLd8EtbyzmFFNLPlLOrp2GHtH55hX1YUQ1f Jan 26 22:38:01 volumio volumio[4803]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="completed challenge" Jan 26 22:38:01 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:38:01 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:38:01 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:01 volumio sudo[5072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:01 volumio sudo[5072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:01 volumio sudo[5076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:01 volumio sudo[5076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:01 volumio sudo[5074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:01 volumio sudo[5074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 22:38:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 22:38:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:01 volumio systemd[1]: shairport-sync.service: Consumed 2.426s CPU time. Jan 26 22:38:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:01 volumio sudo[5074]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:01 volumio sudo[5076]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:01 volumio sudo[5072]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:02 volumio volumio[4803]: info: Shairport-Sync Started Jan 26 22:38:02 volumio volumio[4803]: Error adding Membership: Error: addMembership EINVAL Jan 26 22:38:02 volumio volumio[4803]: info: Shairport-Sync Started Jan 26 22:38:02 volumio volumio[4803]: info: Shairport-Sync Started Jan 26 22:38:02 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:02 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:02 volumio volumio[4803]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 26 22:38:02 volumio volumio[4803]: info: Spotify Successfully logged in Jan 26 22:38:02 volumio volumio[4803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:02 volumio volumio[4803]: info: [1769441882293] CoreMusicLibrary::Adding element Spotify Jan 26 22:38:02 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:02 volumio volumio[4803]: Cannot find translation for source YouTube Music Jan 26 22:38:02 volumio volumio[4803]: Cannot find translation for source Spotify Jan 26 22:38:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:03 volumio volumio[4803]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 22:38:03 volumio volumio[4803]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:38:03 volumio volumio[4803]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:38:03 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:03 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:03 volumio volumio[4803]: info: CoreStateMachine::pushState Jan 26 22:38:03 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:03 volumio volumio[4803]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:04 volumio volumio[4803]: info: go-librespot daemon successfully initialized Jan 26 22:38:04 volumio mpd[5024]: 2026-01-26T22:38:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 22:38:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 22:38:04 volumio sudo[4984]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:04 volumio sudo[4995]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 26 22:38:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:04 volumio go-librespot[5114]: go-librespot daemon starting... Jan 26 22:38:04 volumio go-librespot[5117]: time="2026-01-26T22:38:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:04 volumio go-librespot[5117]: time="2026-01-26T22:38:04+07:00" level=debug msg="app state loaded" Jan 26 22:38:04 volumio go-librespot[5117]: time="2026-01-26T22:38:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:04 volumio volumio[4803]: error: MPD error: The expression evaluated to a falsy value: Jan 26 22:38:04 volumio volumio[4803]: assert.ok(self.idling) Jan 26 22:38:04 volumio volumio[4803]: error: The expression evaluated to a falsy value: Jan 26 22:38:04 volumio volumio[4803]: assert.ok(self.idling) Jan 26 22:38:04 volumio volumio[4803]: error: updateQueue error: null Jan 26 22:38:04 volumio volumio[4803]: info: MPD running with PID5024 Jan 26 22:38:04 volumio volumio[4803]: ,establishing connection Jan 26 22:38:04 volumio volumio[4803]: info: Completed starting Core Plugins Jan 26 22:38:04 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:38:04 volumio volumio[4803]: info: ----- MyVolumio plugins startup ---- Jan 26 22:38:04 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:38:04 volumio volumio[4803]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 22:38:04 volumio volumio[4803]: error: updateQueue error: null Jan 26 22:38:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=info msg="zeroconf server listening on port 33675" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="obtained new client token: AABFc/+IzRqn/3y30PmU/zYGKLUlLToMXt0Yreuz7NhXly12NcmPve4JEJQYQwnzpf/obvJIKCmA2FPkG6SBz1D0672Sh+oUxV+gNOxUjwVaaYv6lJCIXB1HzZyVPmeNYEUBkCdiItQwv1D77hHNgAipxzY2jnG89E5G31Xmhl+ZWTABKuBglthh0cpFFxlj/J41kRl/khtHqdc4alOmlDCRMKqQ4dZNxn7mme8fKPL+sOyIvwz+Ptx2q2Q=" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="completed challenge" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38: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 26 22:38:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:07 volumio volumio[4803]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:07 volumio volumio[4803]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:38:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 26 22:38:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:08 volumio go-librespot[5124]: go-librespot daemon starting... Jan 26 22:38:08 volumio go-librespot[5125]: time="2026-01-26T22:38:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:08 volumio go-librespot[5125]: time="2026-01-26T22:38:08+07:00" level=debug msg="app state loaded" Jan 26 22:38:08 volumio go-librespot[5125]: time="2026-01-26T22:38:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38: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 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38: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 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38: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 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=info msg="zeroconf server listening on port 44789" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="obtained new client token: AAAhtesP63SEICMiWygz7c5lDtnzBW9FzB5hDjFbCM6Nays47VH87VwZSJ/YOxCVE+sR3mlL0OMsx3XZ58upV5zEgFmhdo4teqwGM2vWTznBIELJuzMusxyR9F4EFp2rPMzmJAuYIHvKrExaitnU6NilHvzQj9ps+55ADNG6DGbCrwtyF/dj//w8Wzb9lG2/iQg+jzyWDYPqMiIcUglXy1Vt0GZr9d2Y4uy5z3PkDoZaoX2hoySa/y1ViGc=" Jan 26 22:38:09 volumio volumio[4803]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="completed challenge" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38: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 26 22:38:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:10 volumio volumio[4803]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:10 volumio volumio[4803]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:38:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 26 22:38:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:13 volumio go-librespot[5132]: go-librespot daemon starting... Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=debug msg="app state loaded" Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:13 volumio volumio[4803]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=debug msg="new websocket client" Jan 26 22:38:13 volumio volumio[4803]: info: Connection to go-librespot Websocket established Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38: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 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38: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 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38: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 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=info msg="zeroconf server listening on port 35189" Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="obtained new client token: AAAy/mky1Pma5Gq0HuhSfR7gAg5rJ8fUFRAl2rU/ET666qQ5BWRYTio0cjRUUAHTS/FoJBi9VgFhRBYz8cAUAJN5baf6/6K5T1x53yRLW3XeHYfRWKrcq8Hzbk8u5J2YFLb0SmXtA/9t7k+fxsyWVDojfimuOQB5l2YsFScQ05ujgOoohq5K5pVi9uJG6uIglm90y3bvg1y2y84WEwUoT3yFbzoFMHk+O/knj8YgKHs73KFpf4J0KH/YpII=" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="completed challenge" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38: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 26 22:38:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 22:38:15 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:15 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:15 volumio volumio[4803]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 22:38:15 volumio volumio[4803]: info: MyVolumio login type: Token Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 22:38:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:17 volumio volumio[4803]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 22:38:17 volumio volumio[4803]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 22:38:17 volumio volumio[4803]: info: Streaming services startup Jan 26 22:38:17 volumio volumio[4803]: info: Starting Streaming Daemon Jan 26 22:38:17 volumio sudo[5156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 22:38:17 volumio sudo[5156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:17 volumio volumio[4803]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 22:38:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 26 22:38:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:17 volumio go-librespot[5162]: go-librespot daemon starting... Jan 26 22:38:17 volumio go-librespot[5163]: time="2026-01-26T22:38:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:17 volumio go-librespot[5163]: time="2026-01-26T22:38:17+07:00" level=debug msg="app state loaded" Jan 26 22:38:17 volumio sudo[5156]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:17 volumio go-librespot[5163]: time="2026-01-26T22:38:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:17 volumio volumio[4803]: info: Getting Spotify volume Jan 26 22:38:17 volumio volumio[4803]: info: Connection to go-librespot Websocket closed Jan 26 22:38:17 volumio volumio[4803]: error: Cannot start Volumio Streaming Daemon Jan 26 22:38:17 volumio volumio[4803]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 22:38:17 volumio volumio[4803]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 22:38:17 volumio volumio[4803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 22:38:18 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:18 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:18 volumio volumio[4803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 22:38:18 volumio volumio[4803]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 22:38:18 volumio volumio[4803]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 22:38:18 volumio volumio[4803]: info: Aligning Spotify Volume to Volumio Volume Jan 26 22:38:18 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:18 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:18 volumio volumio[4803]: info: Setting Spotify Volume from Volumio: 100 Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=info msg="zeroconf server listening on port 45405" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="obtained new client token: AAD7q/jWORBZALjTx+Fj71CVJDDtaCZ73FA1diWWNvdoMQvZUCEd/ycaMii26PDEn6vSDwwBnogcr1h5stxpncsRh2OBXifkGBJXZq8rcTcSNSFXlsmT4o1Ba2E7KnUWB/cH2H+LINZSds9Ok7JvMnQL1FUr0d30L1huGMqnCLSuIgp3fjrK177m9fgfb/0cde7wgp4XVKvnRoLu1XcMamaHWxeSO+VoAdihjqOkQbnv8IrfpPnrpA2lubo=" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:18 volumio volumio[4803]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="completed challenge" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:18 volumio volumio[4803]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:38:18 volumio volumio[4803]: Error: socket hang up Jan 26 22:38:18 volumio volumio[4803]: at connResetException (node:internal/errors:720:14) Jan 26 22:38:18 volumio volumio[4803]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 22:38:18 volumio volumio[4803]: at Socket.emit (node:events:526:35) Jan 26 22:38:18 volumio volumio[4803]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 22:38:18 volumio volumio[4803]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 22:38:18 volumio volumio[4803]: code: 'ECONNRESET', Jan 26 22:38:18 volumio volumio[4803]: response: undefined Jan 26 22:38:18 volumio volumio[4803]: } Jan 26 22:38:18 volumio volumio[4803]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:38:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:20 volumio sudo[5191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 22:37' Jan 26 22:38:20 volumio sudo[5191]: 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"