Mar 04 20:13:00 volumio go-librespot[27024]: time="2026-03-04T20:13:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:00 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:00.423+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 20:13:02 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:02 volumio volumio[27011]: info: ----- Volumio3 ---- Mar 04 20:13:02 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:02 volumio volumio[27011]: info: ----- System startup ---- Mar 04 20:13:02 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 20:13:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:03 volumio go-librespot[27038]: go-librespot daemon starting... Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="app state loaded" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:03 volumio volumio-remote-updater[708]: [2026-03-04 20:13:03] [connect] Successful connection Mar 04 20:13:03 volumio volumio[27011]: info: MYVOLUMIO Environment detected Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:03 volumio volumio[27011]: info: Plugin folders cleanup Mar 04 20:13:03 volumio volumio[27011]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category audio_interface Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category miscellanea Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category music_service Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=info msg="zeroconf server listening on port 44351" Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category plugins.json Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category system_controller Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category user_interface Mar 04 20:13:03 volumio volumio[27011]: info: Scanning into folder /data/plugins/ Mar 04 20:13:03 volumio volumio[27011]: info: Scanning category music_service Mar 04 20:13:03 volumio volumio[27011]: info: Plugin folders cleanup completed Mar 04 20:13:03 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:03 volumio volumio[27011]: info: ----- Core plugins startup ---- Mar 04 20:13:03 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:03 volumio volumio[27011]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:13:03 volumio volumio[27011]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:13:03 volumio volumio[27011]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:13:03 volumio volumio[27011]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:13:03 volumio volumio[27011]: info: Loading plugins from folder /data/plugins/ Mar 04 20:13:03 volumio volumio[27011]: info: Loading plugin "system"... Mar 04 20:13:03 volumio volumio[27011]: info: Loading plugin "appearance"... Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="obtained new client token: AABBDW8qWHhTgDZx3fp4KxN4CSCMu91LDFfPh1R+7VHOHyKK+h9tXJ5H39YIzqOpwhwSzLASVbmoWDku2aN/VXF5d+Pg5G0Rz5fObZlSmcTi9/uFEShFNvaW3pPA3SNV13Uafy1pr67XWGsVmqwLf95UWwq1DfRPUFwNO+pfGZVnlzfEZupeV8/ISWPAiQXfQUFM6/zsBWtmtiem6XK5agPht3bEw/8KBq3yzSvVJQ2AoFGk/03+lN7OyA==" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:03 volumio go-librespot[27039]: time="2026-03-04T20:13:03+01:00" level=debug msg="completed challenge" Mar 04 20:13:04 volumio go-librespot[27039]: time="2026-03-04T20:13:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:04 volumio bluealsa[1006]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 04 20:13:04 volumio bluealsa[1006]: ../src/ba-transport.c:319: New A2DP transport: 15 Mar 04 20:13:04 volumio bluealsa[1006]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:1021 W:1024 Mar 04 20:13:04 volumio bluealsa[1006]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 04 20:13:04 volumio bluealsa[1006]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Mar 04 20:13:04 volumio bluealsa[1006]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 16 Mar 04 20:13:04 volumio bluealsa[1006]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Mar 04 20:13:04 volumio bluealsa[1006]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: SCO packet for unknown connection handle 65 Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:04 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:05 volumio volumio[27011]: info: Loading plugin "network"... Mar 04 20:13:05 volumio volumio[27011]: info: Refreshing Cached IP Addresses Mar 04 20:13:05 volumio sudo[27055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:13:05 volumio sudo[27055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:05 volumio volumio[27011]: info: Loading plugin "services"... Mar 04 20:13:05 volumio sudo[27055]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:05 volumio sudo[27057]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:13:05 volumio volumio[27011]: info: Loading plugin "volumio5onboarding"... Mar 04 20:13:05 volumio sudo[27057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:06 volumio sudo[27057]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:06 volumio sudo[27064]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:13:06 volumio sudo[27064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "alsa_controller"... Mar 04 20:13:06 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "wizard"... Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "networkfs"... Mar 04 20:13:06 volumio volumio[27011]: info: Starting Udev Watcher for removable devices Mar 04 20:13:06 volumio volumio[27011]: info: Ignoring mount for partition: boot Mar 04 20:13:06 volumio volumio[27011]: info: Ignoring mount for partition: volumio Mar 04 20:13:06 volumio volumio[27011]: info: Ignoring mount for partition: volumio_data Mar 04 20:13:06 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "upnp"... Mar 04 20:13:06 volumio volumio[27011]: info: [1772651586340] Starting Upmpd Daemon Mar 04 20:13:06 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "my_music"... Mar 04 20:13:06 volumio volumio[27011]: info: Loading plugin "mpd"... Mar 04 20:13:06 volumio sudo[27064]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:07 volumio volumio[27011]: info: Loading plugin "upnp_browser"... Mar 04 20:13:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 20:13:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:07 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:07.171+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 04 20:13:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:07 volumio go-librespot[27089]: go-librespot daemon starting... Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=debug msg="app state loaded" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=info msg="zeroconf server listening on port 34153" Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio kernel: Bluetooth: hci0: Frame reassembly failed (-84) Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=debug msg="obtained new client token: AADt76f6ZleCBRsFf8F9dNyIJgu//Ynu9Pf3xAkZoBjvSBW3U1e1EXZu36n5vII3BDGE3UaQLXBdGBMsTO79La1T1Eo7q1hn74Er04xg6xbfd7Oe3E2mNtatzsWW7/nVERL6nDocJboKVAxt22p6AP4cV9SMTENMADdYAIUo6SXJtZtX9fnNDhNFjYnzEvgc5J6eft9pH937YJoRTpTeJuyLqHMzpbVILgjHj5EPe5jBp7lRXshZHeT11A==" Mar 04 20:13:07 volumio go-librespot[27090]: time="2026-03-04T20:13:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:08 volumio go-librespot[27090]: time="2026-03-04T20:13:08+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:08 volumio go-librespot[27090]: time="2026-03-04T20:13:08+01:00" level=debug msg="completed challenge" Mar 04 20:13:08 volumio go-librespot[27090]: time="2026-03-04T20:13:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:10 volumio volumio[27011]: info: Starting UPNP Browser Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "alarm-clock"... Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "airplay_emulation"... Mar 04 20:13:10 volumio volumio[27011]: info: Starting Shairport Sync Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "last_100"... Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "webradio"... Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "i2s_dacs"... Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "volumiodiscovery"... Mar 04 20:13:10 volumio volumio[27011]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:13:10 volumio volumio[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:13:10 volumio volumio[27011]: *** WARNING *** For more information see Mar 04 20:13:10 volumio volumio[27011]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:13:10 volumio volumio[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:13:10 volumio volumio[27011]: *** WARNING *** For more information see Mar 04 20:13:10 volumio node[27011]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:13:10 volumio node[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:13:10 volumio node[27011]: *** WARNING *** For more information see Mar 04 20:13:10 volumio node[27011]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:13:10 volumio node[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:13:10 volumio node[27011]: *** WARNING *** For more information see Mar 04 20:13:10 volumio volumio[27011]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:13:10 volumio volumio[27011]: info: Discovery: Started advertising with name: Volumio Mar 04 20:13:10 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:13:10 volumio volumio[27011]: info: Loading plugin "spop"... Mar 04 20:13:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 20:13:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:11 volumio go-librespot[27100]: go-librespot daemon starting... Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="app state loaded" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:11 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:11.426+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:34072->127.0.0.1:3000: i/o timeout" Mar 04 20:13:11 volumio bluealsa[1006]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 04 20:13:11 volumio bluealsa[1006]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 16 Mar 04 20:13:11 volumio bluealsa[1006]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Mar 04 20:13:11 volumio bluealsa[1006]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=info msg="zeroconf server listening on port 43985" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="obtained new client token: AAAyNPi8CIdkKV3x44bn/8p9D3mYyoxQoWaSlCN6qNYX8dPrixB8LC2oGEL2+o+OENg8oROlB3Tj05uYr2Itq67Bm4ffkmKfUHnapya+isxngUCdNs0j+d35BirVBqX1UxlAx5DWIc6XFNSP+jIq3KW+CSrzSbi6lU8iTt46TGNPgjJnvQDHb4BhQ8Ep75aLNev2YGTcMYZ/60j0ES3O9alnBDglMABjD6eaY/d1j8AnTZim11KuA0o3dw==" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:11 volumio go-librespot[27101]: time="2026-03-04T20:13:11+01:00" level=debug msg="completed challenge" Mar 04 20:13:12 volumio go-librespot[27101]: time="2026-03-04T20:13:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:12 volumio volumio[27011]: info: Loading plugin "outputs"... Mar 04 20:13:12 volumio volumio[27011]: info: Loading plugin "albumart"... Mar 04 20:13:12 volumio volumio[27011]: info: Plugin example_plugin is not enabled Mar 04 20:13:12 volumio volumio[27011]: info: Loading plugin "inputs"... Mar 04 20:13:12 volumio volumio[27011]: info: Loading plugin "updater_comm"... Mar 04 20:13:13 volumio volumio[27011]: info: Plugin mpdemulation is not enabled Mar 04 20:13:13 volumio volumio[27011]: info: Loading plugin "rest_api"... Mar 04 20:13:13 volumio volumio[27011]: info: Loading plugin "websocket"... Mar 04 20:13:13 volumio volumio[27011]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:13:13 volumio volumio[27011]: info: Loading i18n strings for locale nl Mar 04 20:13:13 volumio volumio[27011]: Updating browse sources language Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::initPlayerControls Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: Express server listening on port 3000 Mar 04 20:13:13 volumio volumio[27011]: [Metrics] WebUI: 12s 223.73ms Mar 04 20:13:13 volumio volumio[27011]: info: CoreStateMachine::resetVolumioState Mar 04 20:13:13 volumio volumio[27011]: info: CoreStateMachine::getcurrentVolume Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:13:13 volumio volumio[27011]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:13:13 volumio volumio[27109]: Forking 3 albumart workers Mar 04 20:13:13 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:13:13 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:13 volumio volumio[27011]: info: Reloading queue from file Mar 04 20:13:13 volumio volumio[27011]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:14 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::updateTrackBlock Mar 04 20:13:14 volumio volumio[27011]: info: CorePlayQueue::getTrackBlock Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::setRepeat false single undefined Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:14 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::setRandom undefined Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:14 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:14 volumio volumio[27011]: info: Setting Device type: Raspberry PI Mar 04 20:13:14 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Mar 04 20:13:14 volumio volumio[27011]: info: Completed loading Core Plugins Mar 04 20:13:14 volumio volumio[27011]: info: Preparing to generate the ALSA configuration file Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:13:14 volumio volumio[27011]: info: Discovery: Getting this device information Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:14 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:13:14 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 20:13:14 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Mar 04 20:13:14 volumio volumio[27011]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:13:14 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:14 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:14 volumio volumio[27011]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:13:14 volumio volumio[27011]: info: Output device has changed, restarting MPD Mar 04 20:13:14 volumio volumio[27011]: info: Output device has changed, restarting Shairport Sync Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:14 volumio sudo[27164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:13:14 volumio sudo[27164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:14 volumio sudo[27164]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:14 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:13:14 volumio volumio[27011]: info: ___________ START PLUGINS ___________ Mar 04 20:13:14 volumio sudo[27166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:13:14 volumio sudo[27166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:14 volumio volumio[27011]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:13:14 volumio volumio[27011]: info: Creating MPD Configuration file Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:13:14 volumio volumio[27011]: info: [1772651594833] CoreMusicLibrary::Adding element Media Servers Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:14 volumio sudo[27174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 20:13:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:13:14 volumio sudo[27176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:13:14 volumio sudo[27176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:14 volumio sudo[27174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:14 volumio volumio[27011]: info: UPNP Browser: Client initialized successfully Mar 04 20:13:14 volumio sudo[27176]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:14 volumio sudo[27178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:13:14 volumio sudo[27178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:14 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:15 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:15 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:13:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:13:15 volumio systemd[1]: mpd.service: Consumed 6.772s CPU time. Mar 04 20:13:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 04 20:13:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:15 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:13:15 volumio volumio[27011]: info: [1772651595140] CoreMusicLibrary::Adding element Last_100 Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:15 volumio go-librespot[27190]: go-librespot daemon starting... Mar 04 20:13:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:13:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:13:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:13:15 volumio volumio[27011]: info: [1772651595193] CoreMusicLibrary::Adding element Webradio Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:13:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:13:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:13:15 volumio sudo[27174]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:15 volumio volumio[27011]: info: Initializing BBC Radios Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=debug msg="app state loaded" Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:15 volumio volumio[27011]: info: Creating Spotify config file Mar 04 20:13:15 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:15 volumio sudo[27198]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:13:15 volumio sudo[27198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:13:15 volumio sudo[27198]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:15 volumio volumio-remote-updater[708]: [2026-03-04 20:13:15] [connect] Successful connection Mar 04 20:13:15 volumio go-librespot[27191]: time="2026-03-04T20:13:15+01:00" level=info msg="zeroconf server listening on port 40561" Mar 04 20:13:16 volumio go-librespot[27191]: time="2026-03-04T20:13:16+01:00" level=debug msg="obtained new client token: AADv1gtPqyvsTVqi7aRbxVAIgHI2DKQoe/CFQ999Q1o7020uzyjdEWK7TQU2z40pQNPo+wirNKwArD2/bONom+sU0JstIQL1VfG3llVqaNB4ri8ROUlilAtQQHxs2beZjgsSCCR9rLMzeEtM/qrrRUd4JN5cNUI5iYaUeQCsZtdJp4M76JrbcnQgCirUqaPkgQr0gwpQL4Dq2BdHGAY1vPIT1SzDOpqNUsR0OdZEFU5lLErClJoRSPo=" Mar 04 20:13:16 volumio go-librespot[27191]: time="2026-03-04T20:13:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:16 volumio go-librespot[27191]: time="2026-03-04T20:13:16+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:16 volumio go-librespot[27191]: time="2026-03-04T20:13:16+01:00" level=debug msg="completed challenge" Mar 04 20:13:16 volumio go-librespot[27191]: time="2026-03-04T20:13:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:16 volumio volumio[27011]: info: Volumio Calling Home Mar 04 20:13:16 volumio volumio[27126]: Starting albumart workers Mar 04 20:13:17 volumio volumio[27127]: Starting albumart workers Mar 04 20:13:17 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:17.169+01:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Mar 04 20:13:17 volumio volumio[27124]: Starting albumart workers Mar 04 20:13:17 volumio volumio[27011]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:13:17 volumio volumio[27011]: info: Discovery: Found device Volumio Mar 04 20:13:17 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:17 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:17 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:13:18 volumio volumio[27011]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:13:18 volumio volumio[27011]: info: Discovery: Found device Volumio Mar 04 20:13:18 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:18 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:18 volumio sudo[27234]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:13:18 volumio sudo[27234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:18 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:13:18 volumio sudo[27236]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:13:18 volumio sudo[27236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:18 volumio sudo[27234]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:18 volumio sudo[27236]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:18 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145:3000 from 192.168.178.147 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Mar 04 20:13:18 volumio volumio[27011]: info: MPD Permissions set Mar 04 20:13:18 volumio volumio[27011]: info: MPD Permissions set Mar 04 20:13:18 volumio volumio-remote-updater[708]: [2026-03-04 20:13:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772651595 101 Mar 04 20:13:18 volumio volumio[27011]: 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: 6 Mar 04 20:13:18 volumio volumio[27011]: info: Volumio called home Mar 04 20:13:18 volumio volumio[27011]: info: Spotify config file written Mar 04 20:13:18 volumio sudo[27247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:13:18 volumio sudo[27247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:19 volumio go-librespot[27261]: go-librespot daemon starting... Mar 04 20:13:19 volumio sudo[27247]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=debug msg="app state loaded" Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:19 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 04 20:13:19 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:19 volumio volumio[27011]: info: No need to fix Spotify hosts Mar 04 20:13:19 volumio volumio[27011]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=info msg="zeroconf server listening on port 46825" Mar 04 20:13:19 volumio volumio[27011]: info: Starting Shairport Sync Mar 04 20:13:19 volumio volumio[27011]: info: Starting Shairport Sync Mar 04 20:13:19 volumio volumio[27011]: info: Starting Shairport Sync Mar 04 20:13:19 volumio sudo[27282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:13:19 volumio sudo[27282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:19 volumio sudo[27286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 20:13:19 volumio sudo[27286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:19 volumio sudo[27284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:13:19 volumio sudo[27284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=debug msg="obtained new client token: AAALSAwP3MixxAbMMzn0C0LlwzKNfP/OZXdmlrqBmkl+ZqlzhijvevjQC75ivPEx2FOZaWvkXBCQ0HgWvLC4tFMPrcLmbqKHU1ptwxZ83TVnT7LqAme4s6f92SBP1nKWBwUFJmAVUfLjQ6A5kEPV2oQiiw568J78WNKlMjzuDqNYCIKbUNKpgwGr+lAdDuuyJGyPx4yhYcZ+Oms7Uej6RjC9HLD9aCE0tSeprr6B4NYCXEY1Gl7/8tslzg==" Mar 04 20:13:19 volumio sudo[27289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:13:19 volumio sudo[27289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:19 volumio go-librespot[27262]: time="2026-03-04T20:13:19+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 20:13:19 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 04 20:13:19 volumio volumio[27011]: info: Received Get System Info Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:13:19 volumio volumio[27011]: info: Discovery: Getting this device information Mar 04 20:13:19 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:20 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:20 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:13:20 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:20 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:20 volumio go-librespot[27262]: time="2026-03-04T20:13:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 20:13:20 volumio volumio[27011]: info: Listing playlists Mar 04 20:13:20 volumio volumio[27011]: info: CoreCommandRouter::volumioGetQueue Mar 04 20:13:20 volumio volumio[27011]: info: CoreStateMachine::getQueue Mar 04 20:13:20 volumio volumio[27011]: info: CorePlayQueue::getQueue Mar 04 20:13:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:13:20 volumio go-librespot[27262]: time="2026-03-04T20:13:20+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:20 volumio go-librespot[27262]: time="2026-03-04T20:13:20+01:00" level=debug msg="completed challenge" Mar 04 20:13:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:13:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:13:20 volumio systemd[1]: shairport-sync.service: Consumed 2.169s CPU time. Mar 04 20:13:20 volumio sudo[27289]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:20 volumio go-librespot[27262]: time="2026-03-04T20:13:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:13:20 volumio sudo[27282]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:20 volumio sudo[27284]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:20 volumio sudo[27286]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:20 volumio volumio[27011]: info: Upmpdcli Daemon Started Mar 04 20:13:20 volumio volumio[27011]: info: Shairport-Sync Started Mar 04 20:13:20 volumio volumio[27011]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:13:20 volumio volumio[27011]: info: Shairport-Sync Started Mar 04 20:13:20 volumio volumio[27011]: info: Shairport-Sync Started Mar 04 20:13:20 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:20 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:22 volumio mpd[27215]: 2026-03-04T20:13:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:13:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:13:22 volumio sudo[27166]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:22 volumio sudo[27178]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:22 volumio volumio[27011]: info: Completed starting Core Plugins Mar 04 20:13:22 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:22 volumio volumio[27011]: info: ----- MyVolumio plugins startup ---- Mar 04 20:13:22 volumio volumio[27011]: info: ------------------------------------------- Mar 04 20:13:22 volumio volumio[27011]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:13:22 volumio volumio[27011]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:13:22 volumio volumio[27011]: assert.ok(self.idling) Mar 04 20:13:22 volumio volumio[27011]: error: The expression evaluated to a falsy value: Mar 04 20:13:22 volumio volumio[27011]: assert.ok(self.idling) Mar 04 20:13:22 volumio volumio[27011]: info: MPD running with PID27215 Mar 04 20:13:22 volumio volumio[27011]: ,establishing connection Mar 04 20:13:22 volumio volumio[27011]: error: updateQueue error: null Mar 04 20:13:22 volumio volumio[27011]: info: go-librespot daemon successfully initialized Mar 04 20:13:22 volumio volumio[27011]: error: updateQueue error: null Mar 04 20:13:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 04 20:13:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:23 volumio go-librespot[27312]: go-librespot daemon starting... Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=debug msg="app state loaded" Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:23 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:23.712+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.147:56938 @ 0x24a6720" latency=24.107962ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=info msg="zeroconf server listening on port 43513" Mar 04 20:13:23 volumio go-librespot[27313]: time="2026-03-04T20:13:23+01:00" level=debug msg="obtained new client token: AADSc7EkIg6Ot+n63l5Wn6DdjMaYfLlZNtSCXn3Hqm6MfRp1SN74mbtgR6N95L+phWe4Nq5JESdVj2fRUfWpQXCzVjDC9+nT7rmgav/GfyrP7hO4iEbOi+BhLajYIXJLEJUPjge5Hp44YlUVTh3r+l8ABRimLWsW8hP2MugoAxAbJU3Pn7MlgdM/8BrzRci02zzVjudrWIMFZef2USUqKolJX2fQ4LjdTTvay3Ap33C/ozRWScnycD4hdQ==" Mar 04 20:13:24 volumio go-librespot[27313]: time="2026-03-04T20:13:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:24 volumio go-librespot[27313]: time="2026-03-04T20:13:24+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:24 volumio go-librespot[27313]: time="2026-03-04T20:13:24+01:00" level=debug msg="completed challenge" Mar 04 20:13:24 volumio go-librespot[27313]: time="2026-03-04T20:13:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:24 volumio sudo[27322]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:13:24 volumio sudo[27322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:24 volumio sudo[27324]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:13:24 volumio sudo[27324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:24 volumio sudo[27322]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:24 volumio sudo[27324]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:24 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 04 20:13:24 volumio sudo[27328]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:13:24 volumio sudo[27328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:24 volumio sudo[27328]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:24 volumio sudo[27330]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:13:24 volumio sudo[27330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:24 volumio sudo[27330]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:24 volumio volumio[27011]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:24 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 04 20:13:24 volumio volumio[27011]: info: Received Get System Info Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:13:24 volumio volumio[27011]: info: Discovery: Getting this device information Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:24 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:24 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:24 volumio volumio[27011]: info: Listing playlists Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 04 20:13:24 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 20:13:25 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:25 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 20:13:26 volumio volumio[27011]: info: Received Get System Info Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:13:26 volumio volumio[27011]: info: Discovery: Getting this device information Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:26 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:13:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Mar 04 20:13:27 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 20:13:27 volumio volumio[27011]: info: Received Get System Info Mar 04 20:13:27 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:13:27 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:13:27 volumio volumio[27011]: info: Discovery: Getting this device information Mar 04 20:13:27 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:27 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:27 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:13:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 04 20:13:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:27 volumio go-librespot[27347]: go-librespot daemon starting... Mar 04 20:13:27 volumio volumio[27011]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=debug msg="app state loaded" Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:27 volumio go-librespot[27348]: time="2026-03-04T20:13:27+01:00" level=info msg="zeroconf server listening on port 37131" Mar 04 20:13:28 volumio go-librespot[27348]: time="2026-03-04T20:13:28+01:00" level=debug msg="obtained new client token: AABqE6Vcn9KNENqFwfdkXvD+uvXuopt8aN6W5rsLZJsYH9+5bzYZ4Hxt/BC9iLYHVOppwx6cljuVdqngmL/G3ydAyYDN6cte4kk7Xsb5qA8DzPhPgC9p3WV1ZDpBdwSYZYZk3FxjRLgbgu/H4W0AciZUCl/olKPyVzJUIDOQ2O70yNdsfywzcwb4xHMNSccRclTG9RvUSJfyF1lsllOsC+vdOHswGG3SrrHn/rZehva2VbVRSuTn6O8=" Mar 04 20:13:28 volumio go-librespot[27348]: time="2026-03-04T20:13:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:28 volumio go-librespot[27348]: time="2026-03-04T20:13:28+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:28 volumio go-librespot[27348]: time="2026-03-04T20:13:28+01:00" level=debug msg="completed challenge" Mar 04 20:13:28 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Mar 04 20:13:28 volumio go-librespot[27348]: time="2026-03-04T20:13:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:28 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:28 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:30 volumio volumio[27011]: info: CoreCommandRouter::volumioGetQueue Mar 04 20:13:30 volumio volumio[27011]: info: CoreStateMachine::getQueue Mar 04 20:13:30 volumio volumio[27011]: info: CorePlayQueue::getQueue Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:13:30 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:13:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 04 20:13:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:31 volumio go-librespot[27356]: go-librespot daemon starting... Mar 04 20:13:31 volumio go-librespot[27357]: time="2026-03-04T20:13:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:31 volumio go-librespot[27357]: time="2026-03-04T20:13:31+01:00" level=debug msg="app state loaded" Mar 04 20:13:31 volumio go-librespot[27357]: time="2026-03-04T20:13:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:31 volumio go-librespot[27357]: time="2026-03-04T20:13:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:31 volumio go-librespot[27357]: time="2026-03-04T20:13:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:31 volumio go-librespot[27357]: time="2026-03-04T20:13:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:32 volumio go-librespot[27357]: time="2026-03-04T20:13:32+01:00" level=info msg="zeroconf server listening on port 40901" Mar 04 20:13:32 volumio go-librespot[27357]: time="2026-03-04T20:13:32+01:00" level=debug msg="obtained new client token: AAB/HsxrAgcQBlOWZgYeQgpB6Eqxnb2H0qqQz0m7tA8MBo0sbXQVy+NkPYOOj1hgIwFmJrcqFqcrkauwo/nZc3az2PitukrMfZPi5GVXvq3FDMUGrIl+p8yK1VH9HiFRwzn6U4KoMHv1id+OmfsvkPqpRfUPn/3u3NXNraFreSohTToHcYjwO+ifAnKs37u6WXSzPIVPD7rFHBl0Aozw5yFo7dfH+tihLWCz3yr1vaeeRpC+ALuQ6Vs=" Mar 04 20:13:32 volumio go-librespot[27357]: time="2026-03-04T20:13:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:32 volumio go-librespot[27357]: time="2026-03-04T20:13:32+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:32 volumio go-librespot[27357]: time="2026-03-04T20:13:32+01:00" level=debug msg="completed challenge" Mar 04 20:13:32 volumio go-librespot[27357]: time="2026-03-04T20:13:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:32 volumio volumio[27011]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:13:32 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:13:32 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:32 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:32 volumio volumio[27011]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:13:32 volumio volumio[27011]: info: MyVolumio login type: Token Mar 04 20:13:32 volumio volumio[27011]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:13:32 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:13:34 volumio volumio[27011]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:13:34 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:13:34 volumio volumio[27011]: info: Streaming services startup Mar 04 20:13:34 volumio volumio[27011]: info: Starting Streaming Daemon Mar 04 20:13:34 volumio sudo[27367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:13:34 volumio volumio[27011]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:13:34 volumio sudo[27367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:34 volumio sudo[27367]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:34 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 04 20:13:34 volumio volumio[27011]: error: Cannot start Volumio Streaming Daemon Mar 04 20:13:34 volumio volumio[27011]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:13:34 volumio volumio[27011]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:13:34 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:35 volumio volumio[27011]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 20:13:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 04 20:13:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:35 volumio go-librespot[27373]: go-librespot daemon starting... Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=debug msg="app state loaded" Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:35 volumio volumio[27011]: info: MyVolumio token set successfully Mar 04 20:13:35 volumio volumio[27011]: info: MYVOLUMIO: Adding device Mar 04 20:13:35 volumio volumio[27011]: info: MYVOLUMIO: Evaluating Server Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:35 volumio go-librespot[27374]: time="2026-03-04T20:13:35+01:00" level=info msg="zeroconf server listening on port 43005" Mar 04 20:13:36 volumio go-librespot[27374]: time="2026-03-04T20:13:36+01:00" level=debug msg="obtained new client token: AABQlEyOdlIKzMf6mG6ZyUWCMhPQGC1cXaQqpHrasj25la592kSxRKYkIsZiogFvD5O3AHtYC1R89AM95y2/9VDkIQvK1BIsjY3TGPw5eKdCNCIr4BobBmOc+Kr0D3lE7BckwqyYxnu0JHRS+S8yDCLzK5rKw0sKApPVFPGNzfOJ6ivXE7CA9zymLdrgGAR9fqqw5fQ0kAi7fAylzX74KAu/ficO38uNcrg51w/nOzPXbjvX8VsRdOY=" Mar 04 20:13:36 volumio go-librespot[27374]: time="2026-03-04T20:13:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:36 volumio go-librespot[27374]: time="2026-03-04T20:13:36+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:36 volumio go-librespot[27374]: time="2026-03-04T20:13:36+01:00" level=debug msg="completed challenge" Mar 04 20:13:36 volumio volumio[27011]: info: MyVolumio Plan changed: premium Mar 04 20:13:36 volumio volumio[27011]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 04 20:13:36 volumio volumio[27011]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 20:13:36 volumio volumio[27011]: info: Removing audio output: Mar 04 20:13:36 volumio go-librespot[27374]: time="2026-03-04T20:13:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:36 volumio volumio[27011]: info: MYVOLUMIO: Adding device Mar 04 20:13:36 volumio volumio[27011]: info: MYVOLUMIO: Evaluating Server Mar 04 20:13:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:36 volumio volumio[27011]: info: Remote config written successfully Mar 04 20:13:36 volumio volumio[27011]: info: Starting Tunnel 1 Mar 04 20:13:36 volumio volumio[27011]: info: Starting Tunnel Connection Checker Mar 04 20:13:36 volumio volumio[27011]: info: Completed starting MyVolumio Plugin Mar 04 20:13:36 volumio volumio[27011]: info: MYVolumio Device enabled Mar 04 20:13:36 volumio volumio[27011]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 04 20:13:36 volumio volumio[27011]: info: MyVolumio status changed Mar 04 20:13:36 volumio volumio[27011]: info: Streaming services startup Mar 04 20:13:36 volumio volumio[27011]: info: Starting Streaming Daemon Mar 04 20:13:36 volumio sudo[27434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:13:36 volumio sudo[27434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:36 volumio volumio[27011]: info: Setting Geolocation for MyVolumio to eu5 Mar 04 20:13:36 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:36 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:36 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:36 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 04 20:13:36 volumio sudo[27434]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:36 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 04 20:13:37 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 04 20:13:37 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 04 20:13:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 04 20:13:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:39 volumio go-librespot[27436]: go-librespot daemon starting... Mar 04 20:13:39 volumio go-librespot[27437]: time="2026-03-04T20:13:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:39 volumio go-librespot[27437]: time="2026-03-04T20:13:39+01:00" level=debug msg="app state loaded" Mar 04 20:13:39 volumio go-librespot[27437]: time="2026-03-04T20:13:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:39 volumio volumio[27011]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 04 20:13:39 volumio sudo[27445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 04 20:13:39 volumio sudo[27445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:39 volumio sudo[27445]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:39 volumio volumio[27011]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 04 20:13:39 volumio volumio[27011]: info: MRS: MultiRoom plugin initialized Mar 04 20:13:39 volumio volumio[27011]: info: MRS: STOPPING SNAPCLIENT Mar 04 20:13:39 volumio volumio[27011]: info: MRS: Snap server stop Mar 04 20:13:39 volumio volumio[27011]: info: MRS: STOPPING volumioStreaming Mar 04 20:13:39 volumio sudo[27462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 04 20:13:39 volumio sudo[27462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:39 volumio sudo[27465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 04 20:13:39 volumio sudo[27465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:39 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 04 20:13:39 volumio sudo[27467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 04 20:13:39 volumio sudo[27467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:39 volumio sudo[27470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 04 20:13:39 volumio sudo[27470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:40 volumio sudo[27462]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:40 volumio sudo[27470]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=info msg="zeroconf server listening on port 34277" Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 04 20:13:40 volumio sudo[27465]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:40 volumio sudo[27467]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="obtained new client token: AACRiSptfk29106NTto8eym6J4+ZLt4sRwSQtfi/mpg/l9pvfed/IKUB1bV6KcwL22bECRJCbwalaPL83jpQsYXWuxO+UbJyVsPv+89LWS3efzvMGLHDGvtWnBRpNZX97znbu83j3tnOEaL97s07iDVvYfV9FKprs2PMtugh+i68uwsTbywQKDy5aAiksNKD3j6bKq39fjR8D0T/HSIQ75cS31EdADyZaAHHwnJKc14nF73GCZNuNRk=" Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 04 20:13:40 volumio volumio[27011]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=debug msg="completed challenge" Mar 04 20:13:40 volumio volumio[27011]: info: Preparing to generate the ALSA configuration file Mar 04 20:13:40 volumio go-librespot[27437]: time="2026-03-04T20:13:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:40 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:40 volumio volumio[27011]: info: Updating MyVolumio device info Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: Setting Geolocation for MyVolumio to eu5 Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 20:13:40 volumio volumio[27011]: info: Reading ALSA contributions from plugins. Mar 04 20:13:40 volumio volumio[27011]: info: Successfully Added MyVolumio device Mar 04 20:13:40 volumio volumio[27011]: info: MRS: Removed streaming files Mar 04 20:13:40 volumio volumio[27011]: info: MRS: volumioStreaming STOPPED Mar 04 20:13:40 volumio volumio[27011]: info: MRS: SNAPSERVER STOPPED Mar 04 20:13:40 volumio volumio[27011]: info: MRS: SNAPCLIENT STOPPED Mar 04 20:13:40 volumio volumio[27011]: error: Cannot start Volumio Streaming Daemon Mar 04 20:13:40 volumio volumio[27011]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:13:40 volumio volumio[27011]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:13:40 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:40 volumio volumio[27011]: info: Asound.conf file written Mar 04 20:13:40 volumio sudo[27478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 20:13:40 volumio sudo[27478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:40 volumio sudo[27478]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:40 volumio volumio[27011]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 04 20:13:40 volumio volumio[27011]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 04 20:13:40 volumio volumio[27011]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 20:13:40 volumio volumio[27011]: No state is present for card vc4hdmi Mar 04 20:13:40 volumio volumio[27011]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 20:13:40 volumio volumio[27011]: Found hardware: "vc4-hdmi" "" "" "" "" Mar 04 20:13:40 volumio volumio[27011]: Hardware is initialized using a generic method Mar 04 20:13:40 volumio volumio[27011]: No state is present for card vc4hdmi Mar 04 20:13:40 volumio volumio[27011]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Mar 04 20:13:40 volumio volumio[27011]: info: Output device has changed, restarting MPD Mar 04 20:13:40 volumio volumio[27011]: info: Output device has changed, restarting Shairport Sync Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:40 volumio sudo[27484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:13:40 volumio sudo[27484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:40 volumio sudo[27484]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:40 volumio sudo[27486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:13:40 volumio sudo[27486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:40 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:13:40 volumio volumio[27011]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 20:13:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:41 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 04 20:13:41 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [FUNC] onStart Mar 04 20:13:41 volumio volumio[27011]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Mar 04 20:13:41 volumio volumio[27011]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Mar 04 20:13:41 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Mar 04 20:13:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:13:41 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 04 20:13:41 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 04 20:13:41 volumio volumio[27011]: info: MRS: Pushing multiroomSync output for this device Mar 04 20:13:41 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:41 volumio volumio[27011]: info: Adding audio output: Mar 04 20:13:41 volumio volumio[27011]: info: Adding audio output: Mar 04 20:13:41 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:13:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:13:41 volumio systemd[1]: mpd.service: Consumed 6.753s CPU time. Mar 04 20:13:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:13:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:13:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:13:41 volumio volumio[27011]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 20:13:41 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:41 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 04 20:13:41 volumio volumio[27011]: info: Adding METAVOLUMIO REST API Endpoints Mar 04 20:13:41 volumio volumio[27011]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 04 20:13:41 volumio volumio[27011]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 04 20:13:41 volumio volumio[27011]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 04 20:13:41 volumio volumio[27011]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 04 20:13:41 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 04 20:13:41 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 04 20:13:41 volumio volumio[27011]: info: Preparing CD Folders Mar 04 20:13:41 volumio volumio[27011]: info: Adding CD REST API Endpoints Mar 04 20:13:41 volumio volumio[27011]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 04 20:13:41 volumio bluetoothd[941]: Path / reserved for Adv Monitor app :1.442 Mar 04 20:13:41 volumio volumio[27011]: info: Starting UDEV Watcher for CD Mar 04 20:13:41 volumio volumio[27011]: info: Detecting CD presence with UDEV Mar 04 20:13:41 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 04 20:13:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:13:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:13:41 volumio bluetoothd[941]: Adv Monitor app :1.442 disconnected from D-Bus Mar 04 20:13:41 volumio sudo[27501]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:13:41 volumio sudo[27501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:13:41 volumio sudo[27501]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 04 20:13:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:43 volumio go-librespot[27507]: go-librespot daemon starting... Mar 04 20:13:43 volumio go-librespot[27508]: time="2026-03-04T20:13:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:43 volumio go-librespot[27508]: time="2026-03-04T20:13:43+01:00" level=debug msg="app state loaded" Mar 04 20:13:43 volumio go-librespot[27508]: time="2026-03-04T20:13:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=info msg="zeroconf server listening on port 45731" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="obtained new client token: AAAYEqZFp9EQ6Sx6vGlMibXG4LPP11Gxs2s6USHSdOBn2jnvH4+KiTMBPmFfBSh9PW44GSmQBxhjZH2gGm4WD3/BnbEN7Cglf9jZ4pcKcBoQ/rkjiABEVkQJNg0MDjDvvEOsMXOyG238jShDwJEAMVKNf5jKkH4nQMeP+TiDtUa/TN1rTm7CP/bgU/L7uXrVdx5tqcijwbo0sUf5pVey7EDJ+gYZ2OYCZlc+udn+VZc4IbcoQD2ep1fdQw==" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=debug msg="completed challenge" Mar 04 20:13:44 volumio go-librespot[27508]: time="2026-03-04T20:13:44+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:46 volumio volumio[27011]: warn: [cd-plugin] cdspeedctl: device or media not ready Mar 04 20:13:46 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 04 20:13:46 volumio volumio[27011]: info: Adding inputs REST Endpoints Mar 04 20:13:46 volumio volumio[27011]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 04 20:13:46 volumio volumio[27011]: info: Scanning Audio Inputs Mar 04 20:13:46 volumio volumio[27011]: info: Checking against Known Cards name Mar 04 20:13:46 volumio volumio[27011]: info: Adding Server instance for streaming Mar 04 20:13:46 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 04 20:13:46 volumio volumio[27011]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 04 20:13:46 volumio volumio[27011]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 04 20:13:46 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 04 20:13:46 volumio volumio[27011]: info: Refreshing TIDAL token Mar 04 20:13:46 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 04 20:13:46 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 04 20:13:46 volumio volumio[27011]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 04 20:13:46 volumio volumio[27011]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Mar 04 20:13:46 volumio volumio[27011]: info: QobuzConnect: Starting Qobuz Connect socket and service Mar 04 20:13:46 volumio sudo[27519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 20:13:46 volumio sudo[27519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:46 volumio volumio[27011]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Mar 04 20:13:46 volumio volumio[27011]: info: Stopping AccessToken refresher cron for QOBUZ Mar 04 20:13:46 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Mar 04 20:13:46 volumio sudo[27526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Mar 04 20:13:46 volumio sudo[27526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:46 volumio systemd[1]: vtcs.service: Killing process 24436 (vtcs) with signal SIGKILL. Mar 04 20:13:46 volumio systemd[1]: vtcs.service: Deactivated successfully. Mar 04 20:13:46 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Mar 04 20:13:46 volumio systemd[1]: vtcs.service: Consumed 1.201s CPU time. Mar 04 20:13:46 volumio sudo[27519]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:46 volumio volumio[27011]: info: AccessToken refresher cron started for QOBUZ Mar 04 20:13:46 volumio volumio[27011]: info: Adding QOBUZ REST API Endpoints Mar 04 20:13:46 volumio sudo[27526]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:46 volumio volumio[27011]: info: MRS: Getting audio outputs on start Mar 04 20:13:46 volumio volumio[27011]: info: MRS: Requesting all other devices output Mar 04 20:13:46 volumio volumio[27011]: info: Updating MyVolumio device info Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:46 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:46 volumio sudo[27543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Mar 04 20:13:46 volumio sudo[27543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:46 volumio volumio[27011]: info: Successfully Updated MyVolumio device Mar 04 20:13:46 volumio mpd[27506]: 2026-03-04T20:13:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:13:46 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:13:46 volumio sudo[27486]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:46 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Mar 04 20:13:46 volumio qobuz-connect[24376]: 20260304 20:13:46.883 [24376.24376] INFO SampleApp: Stopping Local configuration server Mar 04 20:13:46 volumio volumio[27011]: info: Successfully Added MyVolumio device Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 20:13:46 volumio volumio[27011]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 04 20:13:46 volumio volumio[27011]: info: Received Get System Version Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:13:46 volumio volumio[27011]: info: Received Get System Info Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:13:46 volumio volumio[27011]: info: Discovery: Getting this device information Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:46 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:13:46 volumio volumio[27011]: info: Preload queue cleared Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 04 20:13:46 volumio volumio[27011]: info: CoreStateMachine::ClearQueue Mar 04 20:13:46 volumio volumio[27011]: info: CoreStateMachine::stop Mar 04 20:13:46 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:46 volumio volumio[27011]: info: CorePlayQueue::clearPlayQueue Mar 04 20:13:46 volumio volumio[27011]: info: CorePlayQueue::saveQueue Mar 04 20:13:46 volumio volumio[27011]: info: CoreCommandRouter::volumioPushQueue Mar 04 20:13:46 volumio volumio[27011]: info: CoreStateMachine::addQueueItems Mar 04 20:13:46 volumio volumio[27011]: info: CorePlayQueue::addQueueItems Mar 04 20:13:46 volumio volumio[27011]: info: Preload queue cleared Mar 04 20:13:46 volumio volumio[27011]: info: Adding Item to queue: tidal://mymusic/albums/dateadded/2420806 Mar 04 20:13:46 volumio volumio[27011]: info: Exploding uri tidal://mymusic/albums/dateadded/2420806 in service tidal Mar 04 20:13:46 volumio volumio[27011]: info: Refreshing TIDAL token Mar 04 20:13:47 volumio volumio[27011]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Mar 04 20:13:47 volumio volumio[27011]: info: MPD Permissions set Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 20:13:47 volumio sudo[27548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 04 20:13:47 volumio sudo[27548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:47 volumio sudo[27548]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:47 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:47 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [_watchMediaPlayer] Binding activePlayer for path: /org/bluez/hci0/dev_C0_D5_E2_9C_B7_BA/avrcp/player0 Mar 04 20:13:47 volumio volumio[27011]: ------------------------------------ BT MESSAGE: activePlayer bound: /org/bluez/hci0/dev_C0_D5_E2_9C_B7_BA/avrcp/player0 Mar 04 20:13:47 volumio volumio[27011]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::volumioStop Mar 04 20:13:47 volumio volumio[27011]: info: CoreStateMachine::stop Mar 04 20:13:47 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:47 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Mar 04 20:13:47 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 04 20:13:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:47 volumio volumio[27011]: info: Access Token successfully retrieved Mar 04 20:13:47 volumio volumio[27011]: error: updateQueue error: null Mar 04 20:13:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:47 volumio go-librespot[27564]: go-librespot daemon starting... Mar 04 20:13:47 volumio go-librespot[27565]: time="2026-03-04T20:13:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:47 volumio go-librespot[27565]: time="2026-03-04T20:13:47+01:00" level=debug msg="app state loaded" Mar 04 20:13:47 volumio go-librespot[27565]: time="2026-03-04T20:13:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:47 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Mar 04 20:13:47 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 20:13:47 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 20:13:47 volumio volumio[27011]: error: Hi Res Audio Failed Login: [object Object] Mar 04 20:13:47 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 20:13:47 volumio sudo[27543]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:47 volumio volumio[27011]: info: Starting Shairport Sync Mar 04 20:13:47 volumio sudo[27573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 04 20:13:47 volumio sudo[27573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:47 volumio volumio[27011]: info: MRS: Found cast device: Chromecast-84d0dcfc86c31e08fb7722859cd1fe00 Mar 04 20:13:47 volumio volumio[27011]: info: Adding audio output: Mar 04 20:13:48 volumio sudo[27575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:13:48 volumio sudo[27575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:48 volumio autossh[24387]: received signal to exit (15) Mar 04 20:13:48 volumio systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Mar 04 20:13:48 volumio volumio-remote-updater[708]: Test mode disabled Mar 04 20:13:48 volumio volumio-remote-updater[708]: Alpha mode disabled Mar 04 20:13:48 volumio volumio-remote-updater[708]: Alpha legacy test mode disabled Mar 04 20:13:48 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 04 20:13:48 volumio systemd[1]: sshtunnel.service: Deactivated successfully. Mar 04 20:13:48 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 20:13:48 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 04 20:13:48 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 20:13:48 volumio sudo[27573]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:48 volumio autossh[27581]: port set to 0, monitoring disabled Mar 04 20:13:48 volumio autossh[27581]: starting ssh (count 1) Mar 04 20:13:48 volumio autossh[27581]: ssh child pid is 27584 Mar 04 20:13:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:13:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:13:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:13:48 volumio systemd[1]: shairport-sync.service: Consumed 1.984s CPU time. Mar 04 20:13:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:13:48 volumio sudo[27575]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:48 volumio volumio[27011]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 20:13:48 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=info msg="zeroconf server listening on port 33785" Mar 04 20:13:48 volumio volumio[27011]: info: Executing endpoint qc_getconfig Mar 04 20:13:48 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="obtained new client token: AADOLurcIGXKCJfgjQtH5AWpLLqClMsDtohUmepEoggh9yf3YwsfCXheIVAxBM1X2ST0Szri6X/ldPBE9Smg4CjnEZSFgIqJzPlsCmaXK5vN1SCmVTjogbTRQ9ggMaePmz7+U4U2QMccC//zH6wBJ6t9iDSQr3wdf/xIY33IEXDvD2PPAQWCTeO5A+Xluw2fx2/JGPFWmPa6o/itJ8nP3yd3WnmbiXEV52oOKXHM5t9xG+hE+P118qBjsg==" Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.548 [27572.27572] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Mar 04 20:13:48 volumio volumio[27011]: info: Remote SSH Started Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.565 [27572.27572] INFO VolumeManager: [0x15a408]: Setting new playback volume: 75 Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.568 [27572.27572] INFO VolumeManager: [0x15a408]: Setting new mute state: 0 Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.568 [27572.27572] INFO QobuzConnect: [0x15add8]: Client initialized! Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.568 [27572.27572] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Mar 04 20:13:48 volumio volumiossh-tunnel[27584]: Warning: Permanently added '[eu5.myvolumio.org]:2222' (RSA) to the list of known hosts. Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.631 [27572.27572] INFO LocalConfigManager: [0x159ce8]: Starting Local Configuration server Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.632 [27572.27572] INFO SampleApp: Starting Local configuration server Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.632 [27572.27572] INFO SampleApp: Connected to UNIX socket client 0x144818 Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=debug msg="completed challenge" Mar 04 20:13:48 volumio qobuz-connect[27572]: 20260304 20:13:48.699 [27572.27572] INFO SampleApp: Playback volume changed: 75 Mar 04 20:13:48 volumio go-librespot[27565]: time="2026-03-04T20:13:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:49 volumio volumio[27011]: info: Successfully retrieved User Session From TIDAL Mar 04 20:13:49 volumio volumio[27011]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Mar 04 20:13:49 volumio volumio[27011]: info: QobuzConnect: QOBUZ Connect daemon connected Mar 04 20:13:49 volumio volumio[27011]: info: Successfully Updated MyVolumio device Mar 04 20:13:49 volumio volumio[27011]: info: Shairport-Sync Started Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:49 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Mar 04 20:13:49 volumio volumio[27011]: info: Successfully retrieved User Subscription From TIDAL Mar 04 20:13:49 volumio volumio[27011]: info: Adding TIDAL to Browse Sources Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:13:49 volumio volumio[27011]: info: [1772651629254] CoreMusicLibrary::Adding element TIDAL Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:13:49 volumio volumio[27011]: Cannot find translation for source TIDAL Mar 04 20:13:49 volumio volumio[27011]: info: Adding TIDAL REST API Endpoints Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:49 volumio volumio[27011]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 20:13:49 volumio volumio[27011]: info: explodeTIDALUri took 1342 milliseconds Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioPushQueue Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::saveQueue Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::updateTrackBlock Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrackBlock Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioPlay Mar 04 20:13:49 volumio volumio[27011]: verbose: UNSET VOLATILE: Service: bluetooth Mar 04 20:13:49 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Mar 04 20:13:49 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Mar 04 20:13:49 volumio volumio[27011]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::play index 0 Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:49 volumio volumio[27011]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::stop Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::resetVolumioState Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::getcurrentVolume Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::play index undefined Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioStop Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::stop Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::startPlaybackTimer Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:49 volumio volumio[27011]: info: [1772651629662] ControllerTidal::clearAddPlayTrack Mar 04 20:13:49 volumio volumio[27011]: info: Getting stream with soundQuality LOSSLESS Mar 04 20:13:49 volumio volumio[27011]: info: TidalConnect service stoped! Mar 04 20:13:49 volumio volumio[27011]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:49 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:49 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::updateTrackBlock Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrackBlock Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:13:49 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:49.820+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_STOPPED positionMs=0 volume=5 Mar 04 20:13:49 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:49.824+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:49 volumio volumio[27011]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:13:49 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:49 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:49 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:49 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:49 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:49 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:49.981+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_STOPPED positionMs=274 volume=5 Mar 04 20:13:49 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:49.982+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:50 volumio volumio[27011]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 20:13:50 volumio volumio[27011]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 20:13:50 volumio volumio[27011]: info: getStreamUrl took 382 milliseconds Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand stop Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand stop took 3 milliseconds Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand clear Mar 04 20:13:50 volumio volumio[27011]: info: Mar 04 20:13:50 volumio volumio[27011]: ---------------------------- MPD announces system playlist update Mar 04 20:13:50 volumio volumio[27011]: info: Ignoring MPD Status Update Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand clear took 5 milliseconds Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ0NGI5NWQxNDUwNGU5ZjQzNjMyMTA4OGNkZDY0MTI0ZC5tcDQ/0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==" Mar 04 20:13:50 volumio volumio[27011]: error: updateQueue error: null Mar 04 20:13:50 volumio volumio[27011]: info: Mar 04 20:13:50 volumio volumio[27011]: ---------------------------- MPD announces system playlist update Mar 04 20:13:50 volumio volumio[27011]: info: Ignoring MPD Status Update Mar 04 20:13:50 volumio volumio[27011]: info: ------------------------------ 28ms Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ0NGI5NWQxNDUwNGU5ZjQzNjMyMTA4OGNkZDY0MTI0ZC5tcDQ/0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==" took 24 milliseconds Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand play Mar 04 20:13:50 volumio volumio[27011]: info: ------------------------------ 12ms Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand play took 7 milliseconds Mar 04 20:13:50 volumio sudo[27618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 20:13:50 volumio sudo[27618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:13:50 volumio volumio[27011]: info: Mar 04 20:13:50 volumio volumio[27011]: ---------------------------- MPD announces state update: player Mar 04 20:13:50 volumio volumio[27011]: info: ControllerMpd::getState Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand status Mar 04 20:13:50 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:50 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:50 volumio volumio[27011]: info: Mar 04 20:13:50 volumio volumio[27011]: ---------------------------- MPD announces state update: player Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand status took 88 milliseconds Mar 04 20:13:50 volumio volumio[27011]: info: ControllerMpd::getState Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand status Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::parseState Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand status took 12 milliseconds Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand playlistinfo took 8 milliseconds Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::parseState Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 04 20:13:50 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::parseTrackInfo Mar 04 20:13:50 volumio volumio[27011]: info: ControllerMpd::pushState Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::servicePushState Mar 04 20:13:50 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:50 volumio volumio[27011]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":282,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ0NGI5NWQxNDUwNGU5ZjQzNjMyMTA4OGNkZDY0MTI0ZC5tcDQ/0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==","trackType":"tidal"} Mar 04 20:13:50 volumio volumio[27011]: verbose: CURRENT POSITION 0 Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::syncState stateService play Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::syncState currentStatus stop Mar 04 20:13:50 volumio sudo[27618]: pam_unix(sudo:session): session closed for user root Mar 04 20:13:50 volumio volumio[27011]: info: ------------------------------ 160ms Mar 04 20:13:50 volumio volumio[27011]: info: sendMpdCommand playlistinfo took 50 milliseconds Mar 04 20:13:50 volumio volumio[27011]: verbose: ControllerMpd::parseTrackInfo Mar 04 20:13:50 volumio volumio[27011]: info: ControllerMpd::pushState Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::servicePushState Mar 04 20:13:50 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:50 volumio volumio[27011]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1100,"duration":282,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"651 Kbps","isStreaming":false,"title":"0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ0NGI5NWQxNDUwNGU5ZjQzNjMyMTA4OGNkZDY0MTI0ZC5tcDQ/0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==","trackType":"tidal"} Mar 04 20:13:50 volumio volumio[27011]: verbose: CURRENT POSITION 0 Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::syncState stateService play Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::syncState currentStatus play Mar 04 20:13:50 volumio volumio[27011]: info: Received an update from plugin. extracting info from payload Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:50 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:50 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:50 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:50 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:50 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:50 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:50 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:50.461+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_PLAYING positionMs=0 volume=5 Mar 04 20:13:50 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:50.471+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:50 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:50.479+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_PLAYING positionMs=0 volume=5 Mar 04 20:13:50 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:50.479+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:50 volumio volumio[27011]: info: ------------------------------ 373ms Mar 04 20:13:51 volumio volumio[27011]: info: Executing endpoint tc_getconfig Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 04 20:13:51 volumio vtcs[27626]: STARTING TidalConnect services, version: 1.6.1 Mar 04 20:13:51 volumio vtcs[27626]: STARTED TidalConnect services. Mar 04 20:13:51 volumio volumio[27011]: info: Executing endpoint tc_connect Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 04 20:13:51 volumio volumio[27011]: info: Connecting to TidalConnect Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::servicePushState Mar 04 20:13:51 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:51 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:51 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:51 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:51 volumio volumio[27011]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::servicePushState Mar 04 20:13:51 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:51 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:51 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:51 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:51 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:13:51 volumio volumio[27011]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Mar 04 20:13:51 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:51.207+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_PLAYING positionMs=957 volume=5 Mar 04 20:13:51 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:51.209+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:51 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:51.216+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_PLAYING positionMs=957 volume=5 Mar 04 20:13:51 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:51.217+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 04 20:13:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:51 volumio go-librespot[27643]: go-librespot daemon starting... Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="app state loaded" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=info msg="zeroconf server listening on port 43003" Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::volumioGetBrowseSources Mar 04 20:13:52 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="obtained new client token: AAAqgNf6ahCmlqs7mxR4nKMvynFPE01E+fqloburamFa6p7aPbq8ucmHciGe5Box5AYAgrHRXcZqdOLnJ5yWkpMAJJ3nmmSI/YMukCdw7vewSr5L8Q2xdMQJJ76BaIsBf2nXPayLbic5F29Jf0bZtuO2QqyDCu/aNK/Xkbud9B7uCG5TTSqeOnHRC1aAmlMvplu1gS0Vmukt7amzK2OqpN9PP+AWNgZbZb1l3lFeNtDLZfRQ6BS+GMLvLg==" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:52 volumio go-librespot[27644]: time="2026-03-04T20:13:52+01:00" level=debug msg="completed challenge" Mar 04 20:13:53 volumio go-librespot[27644]: time="2026-03-04T20:13:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:53 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:53 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:53 volumio volumio[27011]: info: TidalConnect service started! Mar 04 20:13:53 volumio volumio[27011]: [Metrics] CommandRouter: 51s 220.96ms Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::volumiosetStartupVolume Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:13:53 volumio volumio[27011]: info: VolumeController:: Setting startup Volume 5 Mar 04 20:13:53 volumio volumio[27011]: info: VolumeController::SetAlsaVolume5 Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::Close All Modals sent Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::Close All Modals sent Mar 04 20:13:53 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:13:53 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:13:53 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:13:53 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:53.441+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_PLAYING positionMs=2972 volume=5 Mar 04 20:13:53 volumio volumio5-onboarding[2437]: time=2026-03-04T20:13:53.442+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:13:53 volumio volumio[27011]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Mar 04 20:13:53 volumio volumio[27011]: ALSA lib ./src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Mar 04 20:13:53 volumio volumio[27011]: aplay: main:831: audio open error: Device or resource busy Mar 04 20:13:53 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 04 20:13:54 volumio volumio[27011]: info: browseTIDALUri took 83 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: Preload queue cleared Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420807 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420808 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420809 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420810 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420811 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420812 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420813 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420814 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420815 Mar 04 20:13:54 volumio volumio[27011]: info: Preloading song: tidal://song/2420816 Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420807 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420808 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: Executing endpoint getSimilarAlbums Mar 04 20:13:54 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420809 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420810 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420811 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 213 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: Executing endpoint metavolumio Mar 04 20:13:54 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 04 20:13:54 volumio volumio[27011]: info: Executing endpoint metavolumio Mar 04 20:13:54 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 04 20:13:54 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 04 20:13:54 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 20:13:54 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420812 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420813 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 367 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420814 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420815 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 233 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: Exploding uri tidal://song/2420816 in service tidal Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 305 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 570 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 247 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 474 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 395 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 351 milliseconds Mar 04 20:13:54 volumio volumio[27011]: info: explodeTIDALUri took 379 milliseconds Mar 04 20:13:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 04 20:13:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:13:56 volumio go-librespot[27654]: go-librespot daemon starting... Mar 04 20:13:56 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:56 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="app state loaded" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=info msg="zeroconf server listening on port 46781" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="obtained new client token: AADb2KA/plw0mBqny6AXRKZYEI90sZVyh46AK+pF9ChQbQbMac2HMhVRDg4n29BuXb0CZwkeVDvB3kEHtcI5KEzV1Z7/rXHW2QkiqLcgdALZ4V8D3RpkjcWHiOx1AeP5dJBIKi2tuQ5OiLUzoJAS93roxTSfc+UO9FfBoX3fxyFy2My7VWZzc8vrBA5NAeIkZ2SDteVeVt8tHPsjsABM6XqWRHV1R2//SO7652b8Tk6vlcuWxomNdGKhRA==" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="completed keyexchange" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=debug msg="completed challenge" Mar 04 20:13:56 volumio go-librespot[27655]: time="2026-03-04T20:13:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:13:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:13:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:13:59 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:13:59 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:14:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 04 20:14:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:00 volumio go-librespot[27676]: go-librespot daemon starting... Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="app state loaded" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:14:00 volumio volumio[27011]: info: CoreCommandRouter::volumioPause Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::pause Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::stPlaybackTimer Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::servicePause Mar 04 20:14:00 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:14:00 volumio volumio[27011]: info: CoreCommandRouter::servicePause Mar 04 20:14:00 volumio volumio[27011]: info: [1772651640304] ControllerTidal::pause Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 04 20:14:00 volumio volumio[27011]: info: ControllerMpd::pause Mar 04 20:14:00 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand pause Mar 04 20:14:00 volumio volumio[27011]: info: Mar 04 20:14:00 volumio volumio[27011]: ---------------------------- MPD announces state update: player Mar 04 20:14:00 volumio volumio[27011]: info: sendMpdCommand pause took 4 milliseconds Mar 04 20:14:00 volumio volumio[27011]: info: ControllerMpd::getState Mar 04 20:14:00 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand status Mar 04 20:14:00 volumio volumio[27011]: info: sendMpdCommand status took 10 milliseconds Mar 04 20:14:00 volumio volumio[27011]: verbose: ControllerMpd::parseState Mar 04 20:14:00 volumio volumio[27011]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 04 20:14:00 volumio volumio[27011]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 04 20:14:00 volumio volumio[27011]: verbose: ControllerMpd::parseTrackInfo Mar 04 20:14:00 volumio volumio[27011]: info: ControllerMpd::pushState Mar 04 20:14:00 volumio volumio[27011]: info: CoreCommandRouter::servicePushState Mar 04 20:14:00 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Mar 04 20:14:00 volumio volumio[27011]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":11462,"duration":282,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"795 Kbps","isStreaming":false,"title":"0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ0NGI5NWQxNDUwNGU5ZjQzNjMyMTA4OGNkZDY0MTI0ZC5tcDQ/0.flac?token=1772655229~MDk0MGMyZTBkN2MxZjc5ZmU0ZDZkNDUwNzkyMDA5MTIxNjg4ZGU5MQ==","trackType":"tidal"} Mar 04 20:14:00 volumio volumio[27011]: verbose: CURRENT POSITION 0 Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::syncState stateService pause Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::syncState currentStatus pause Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::pushState Mar 04 20:14:00 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:14:00 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Mar 04 20:14:00 volumio volumio[27011]: info: MRS: Pushing multiroomSync output update for this device Mar 04 20:14:00 volumio volumio[27011]: info: MRS: Pushing multiroomSync output Mar 04 20:14:00 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Mar 04 20:14:00 volumio volumio[27011]: info: CoreStateMachine::stPlaybackTimer Mar 04 20:14:00 volumio volumio5-onboarding[2437]: time=2026-03-04T20:14:00.378+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" state=STATUS_PAUSED positionMs=10130 volume=5 Mar 04 20:14:00 volumio volumio5-onboarding[2437]: time=2026-03-04T20:14:00.379+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" id=tidal://song/2420807 title="Fields Of Gold (Songbird)" Mar 04 20:14:00 volumio volumio[27011]: info: ------------------------------ 106ms Mar 04 20:14:00 volumio volumio[27011]: info: BOOT COMPLETED Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=info msg="zeroconf server listening on port 35925" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="obtained new client token: AADQMsSaB1GYcWUCLjg6lYu4RXlvJs+s5r9wCfpXAIXYP9Rv5QugX+50FJu+wX2+5K+B2X4YauScUQaYpmgcR4Ux/oahAimsWQ39iOXlzgp2TKZka+Z1BFTZhBwo//g5hzTYaezY9wN+QgcckZhNE0yVC7fd1SC1VWS5wmZ2VnQEPi2HhqFQvMwZr+jH75dfFc7pk9ypkSqHJmmfko6hmMQpx/h3frXod2duurm15pXaUYOotIPLFEj+Wg==" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="completed keyexchange" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=debug msg="completed challenge" Mar 04 20:14:00 volumio go-librespot[27677]: time="2026-03-04T20:14:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:14:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:14:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:14:02 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:14:02 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:14:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 04 20:14:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:04 volumio go-librespot[27685]: go-librespot daemon starting... Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="app state loaded" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=info msg="zeroconf server listening on port 38065" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="obtained new client token: AABVcinnaMdDeTRpr3O0f9SHDlzewYTVQqKc9yHjKvrW7l2FYdyYFU8TIRSfdajRgnSJfJI6SB2LsIoqu+w5cabyxBRfQ/KFXnBaoYnkFZIiNQ5sHk/GAseGt+xID+im24aS8BCtxvyiMkVfg8BxW5MwHTnuDqdmQ0w7yTC16b0c09KSvjmHlW5QoQWOANWG7SGLbCrijDhRs3XFOFzTIKEmyUfdBaavCWLGO2zfeE7GhvUQAxWe6U5aCQ==" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="completed keyexchange" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=debug msg="completed challenge" Mar 04 20:14:04 volumio go-librespot[27686]: time="2026-03-04T20:14:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:14:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:14:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:14:05 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:14:05 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:14:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 04 20:14:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:08 volumio go-librespot[27707]: go-librespot daemon starting... Mar 04 20:14:08 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="app state loaded" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="new websocket client" Mar 04 20:14:08 volumio volumio[27011]: info: Connection to go-librespot Websocket established Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=info msg="zeroconf server listening on port 37443" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="obtained new client token: AAA8QIxYcXkPcOtiFOPqjr8rv6P/FiaJM3RVt6Wi5zqqIGzNhbgscCuHU8+Ow83M5ZgqzszHZDT+v4y7LL6UIfLsxM9UTmfhc8BVmyA6Gwp/VZSx5cq8E6lC5PHRulq/wiWnGleMixg3FaD1K4jg+cGPXPx82cr9UCVt6Vtw6ClfAGORUR9P7yB7rWDFGF4p8INBIUAerDKF28WJC0miE+zad/z5KzvYpl2XvbH/bvcOENXzwa+0ftym5g==" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="completed keyexchange" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=debug msg="completed challenge" Mar 04 20:14:08 volumio go-librespot[27708]: time="2026-03-04T20:14:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:14:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:14:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:14:08 volumio volumio[27011]: info: Connection to go-librespot Websocket closed Mar 04 20:14:11 volumio volumio[27011]: info: Getting Spotify volume Mar 04 20:14:11 volumio volumio[27011]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:14:11 volumio volumio[27011]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:14:11 volumio volumio[27011]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 20:14:11 volumio volumio[27011]: errno: -111, Mar 04 20:14:11 volumio volumio[27011]: code: 'ECONNREFUSED', Mar 04 20:14:11 volumio volumio[27011]: syscall: 'connect', Mar 04 20:14:11 volumio volumio[27011]: address: '127.0.0.1', Mar 04 20:14:11 volumio volumio[27011]: port: 9879, Mar 04 20:14:11 volumio volumio[27011]: response: undefined Mar 04 20:14:11 volumio volumio[27011]: } Mar 04 20:14:11 volumio volumio[27011]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:14:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 04 20:14:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:14:12 volumio go-librespot[27728]: go-librespot daemon starting... Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="app state loaded" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=info msg="zeroconf server listening on port 46881" Mar 04 20:14:12 volumio sudo[27738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:13' Mar 04 20:14:12 volumio sudo[27738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="obtained new client token: AACAurW3AmGx8HMR5MFPzzLzJL5z73reAINpu4NeYmzTVpweP6sIZAfTL69pTeY9Z90VG0YEdNrB+CCNOMlZIwwrMvyJjymUYn523PN3t6OY3vyVs7qFryp3TPYlUrVFUpmEmQr7wd9zHCBQ9noxEnIeyG4DGlvfiIZ2ZKCdhzuo+fxr0azTwgyBus+niu4NO4WD6lk//DFzC+tOLLB4O9Pgtn3zqIy4yq5PyXF57dwra4BCwWnpqUyeGA==" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="completed keyexchange" Mar 04 20:14:12 volumio go-librespot[27729]: time="2026-03-04T20:14:12+01:00" level=debug msg="completed challenge" Mar 04 20:14:13 volumio go-librespot[27729]: time="2026-03-04T20:14:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:14:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:14:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"