Dec 09 14:53:00 volumio volumio[14693]: info: Getting Spotify volume Dec 09 14:53:00 volumio volumio[14693]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 14:53:00 volumio volumio[14693]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:53:00 volumio volumio[14693]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 09 14:53:00 volumio volumio[14693]: errno: -111, Dec 09 14:53:00 volumio volumio[14693]: code: 'ECONNREFUSED', Dec 09 14:53:00 volumio volumio[14693]: syscall: 'connect', Dec 09 14:53:00 volumio volumio[14693]: address: '127.0.0.1', Dec 09 14:53:00 volumio volumio[14693]: port: 9879, Dec 09 14:53:00 volumio volumio[14693]: response: undefined Dec 09 14:53:00 volumio volumio[14693]: } Dec 09 14:53:00 volumio volumio[14693]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 14:53:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Dec 09 14:53:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:00 volumio go-librespot[15290]: go-librespot daemon starting... Dec 09 14:53:00 volumio go-librespot[15291]: time="2025-12-09T14:53:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:00 volumio go-librespot[15291]: time="2025-12-09T14:53:00-06:00" level=debug msg="app state loaded" Dec 09 14:53:00 volumio go-librespot[15291]: time="2025-12-09T14:53:00-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:00 volumio go-librespot[15291]: time="2025-12-09T14:53:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:00 volumio sudo[15299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 14:52' Dec 09 14:53:01 volumio sudo[15299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=info msg="zeroconf server listening on port 36989" Dec 09 14:53:01 volumio sudo[15299]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:01 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 09 14:53:01 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 09 14:53:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 09 14:53:01 volumio systemd[1]: volumio.service: Consumed 47.230s CPU time. Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="obtained new client token: AADLLCBD6lJ46/12xKiwax2XBeXphZooKKDQYscSBney4JEjG+XwlZ68Ja9K+G/1qCuNJ44Dtf7bk8THfhhh6Z5oHAqLu21Eg8KbgSWXeGl9RzKRE2srkS2P72LknCLzXj4e1MhQij81Bwp1LG4IT/pg6xIqZfJA9N1Q50su/6p+EmxOUECrYVR+mItTvkE9B3nQlrrWt/IloRIE+xLtWvcXMVdJk0TrXiS8jAdIHrxUD4dkjy1pSc1+vQ==" Dec 09 14:53:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 14:53:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 14:53:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24571. Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 14:53:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 09 14:53:01 volumio systemd[1]: volumio.service: Consumed 47.230s CPU time. Dec 09 14:53:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 09 14:53:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=debug msg="completed challenge" Dec 09 14:53:01 volumio go-librespot[15291]: time="2025-12-09T14:53:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:03 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:03 volumio volumio[15315]: info: ----- Volumio3 ---- Dec 09 14:53:03 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:03 volumio volumio[15315]: info: ----- System startup ---- Dec 09 14:53:03 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:04 volumio volumio[15315]: info: MYVOLUMIO Environment detected Dec 09 14:53:04 volumio volumio[15315]: info: Plugin folders cleanup Dec 09 14:53:04 volumio volumio[15315]: info: Scanning into folder /volumio/app/plugins/ Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category audio_interface Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category miscellanea Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category music_service Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category plugins.json Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category system_controller Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category user_interface Dec 09 14:53:04 volumio volumio[15315]: info: Scanning into folder /data/plugins/ Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category audio_interface Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category music_service Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category system_controller Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category system_hardware Dec 09 14:53:04 volumio volumio[15315]: info: Scanning category user_interface Dec 09 14:53:04 volumio volumio[15315]: info: Plugin folders cleanup completed Dec 09 14:53:04 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:04 volumio volumio[15315]: info: ----- Core plugins startup ---- Dec 09 14:53:04 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:04 volumio volumio[15315]: info: Loading plugins from folder /volumio/app/plugins/ Dec 09 14:53:04 volumio volumio[15315]: info: Adding plugin upnp to MyMusic Plugins Dec 09 14:53:04 volumio volumio[15315]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 09 14:53:04 volumio volumio[15315]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 09 14:53:04 volumio volumio[15315]: info: Loading plugins from folder /data/plugins/ Dec 09 14:53:04 volumio volumio[15315]: info: Loading plugin "system"... Dec 09 14:53:04 volumio volumio[15315]: info: Loading plugin "appearance"... Dec 09 14:53:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Dec 09 14:53:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:04 volumio go-librespot[15342]: go-librespot daemon starting... Dec 09 14:53:04 volumio go-librespot[15343]: time="2025-12-09T14:53:04-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:04 volumio go-librespot[15343]: time="2025-12-09T14:53:04-06:00" level=debug msg="app state loaded" Dec 09 14:53:04 volumio go-librespot[15343]: time="2025-12-09T14:53:04-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:04 volumio go-librespot[15343]: time="2025-12-09T14:53:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:05 volumio go-librespot[15343]: time="2025-12-09T14:53:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:05 volumio go-librespot[15343]: time="2025-12-09T14:53:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:05 volumio go-librespot[15343]: time="2025-12-09T14:53:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:05 volumio go-librespot[15343]: time="2025-12-09T14:53:05-06:00" level=info msg="zeroconf server listening on port 33445" Dec 09 14:53:05 volumio go-librespot[15343]: time="2025-12-09T14:53:05-06:00" level=debug msg="obtained new client token: AAC+bexg7f+fVqkc7ESJwS/G+MZC4r4bgRjX2vY7DaNiG901/b/f3gmsSLrCbFdgBKG5vSBjN6v2mTCqR+bkeO4PoEekK30R8kS/FdrJ8WYtKF0QluXMvlxYeWx/dURCC6jQuP2tOnPb/Eu/mgL4SNc6Vai87BGYmJNbrScXZPLOncg5+gXdcF9OBB7EoiTOItHcvqCrx2v/fsHWr9X8eQe6Noont6bvf8SZS9QLWELQg20/vEdmM5dVuA==" Dec 09 14:53:05 volumio go-librespot[15343]: time="2025-12-09T14:53:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "network"... Dec 09 14:53:05 volumio volumio[15315]: info: Refreshing Cached IP Addresses Dec 09 14:53:05 volumio sudo[15351]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 14:53:05 volumio sudo[15353]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 14:53:05 volumio sudo[15351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:05 volumio sudo[15353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:05 volumio sudo[15353]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:05 volumio sudo[15351]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "services"... Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "alsa_controller"... Dec 09 14:53:05 volumio sudo[15362]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 09 14:53:05 volumio sudo[15362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:05 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "wizard"... Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "networkfs"... Dec 09 14:53:05 volumio volumio[15315]: info: Starting Udev Watcher for removable devices Dec 09 14:53:05 volumio volumio[15315]: info: Ignoring mount for partition: boot Dec 09 14:53:05 volumio volumio[15315]: info: Ignoring mount for partition: volumio Dec 09 14:53:05 volumio volumio[15315]: info: Ignoring mount for partition: volumio_data Dec 09 14:53:05 volumio volumio[15315]: info: Mounting Device Wikipedia Dec 09 14:53:05 volumio sudo[15390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 09 14:53:05 volumio sudo[15390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:05 volumio sudo[15390]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:05 volumio volumio[15315]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 14:53:05 volumio volumio[15315]: dmesg(1) may have more information after failed mount system call. Dec 09 14:53:05 volumio volumio[15315]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 09 14:53:05 volumio volumio[15315]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 14:53:05 volumio volumio[15315]: dmesg(1) may have more information after failed mount system call. Dec 09 14:53:05 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "volumio_command_line_client"... Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "upnp"... Dec 09 14:53:05 volumio volumio[15315]: info: [1765313585776] Starting Upmpd Daemon Dec 09 14:53:05 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "my_music"... Dec 09 14:53:05 volumio volumio[15315]: info: Loading plugin "mpd"... Dec 09 14:53:06 volumio volumio[15315]: info: Loading plugin "upnp_browser"... Dec 09 14:53:06 volumio sudo[15362]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:06 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:06] [connect] Successful connection Dec 09 14:53:06 volumio go-librespot[15343]: time="2025-12-09T14:53:06-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:06 volumio go-librespot[15343]: time="2025-12-09T14:53:06-06:00" level=debug msg="completed challenge" Dec 09 14:53:06 volumio go-librespot[15343]: time="2025-12-09T14:53:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:07 volumio volumio[15315]: info: Loading plugin "alarm-clock"... Dec 09 14:53:07 volumio volumio[15315]: info: Loading plugin "airplay_emulation"... Dec 09 14:53:07 volumio volumio[15315]: info: Starting Shairport Sync Dec 09 14:53:07 volumio volumio[15315]: info: Loading plugin "last_100"... Dec 09 14:53:07 volumio volumio[15315]: info: Loading plugin "webradio"... Dec 09 14:53:07 volumio volumio[15315]: info: Loading plugin "i2s_dacs"... Dec 09 14:53:07 volumio volumio[15315]: info: I2S DAC not set, start Auto-detection Dec 09 14:53:07 volumio volumio[15315]: info: Loading plugin "volumiodiscovery"... Dec 09 14:53:07 volumio volumio[15315]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:07 volumio volumio[15315]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:07 volumio volumio[15315]: *** WARNING *** For more information see Dec 09 14:53:07 volumio volumio[15315]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:07 volumio volumio[15315]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:07 volumio volumio[15315]: *** WARNING *** For more information see Dec 09 14:53:07 volumio node[15315]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:07 volumio node[15315]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:07 volumio node[15315]: *** WARNING *** For more information see Dec 09 14:53:07 volumio node[15315]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:07 volumio node[15315]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:07 volumio node[15315]: *** WARNING *** For more information see Dec 09 14:53:07 volumio volumio[15315]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 09 14:53:07 volumio volumio[15315]: info: Discovery: Started advertising with name: Volumio Dec 09 14:53:08 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 14:53:08 volumio volumio[15315]: info: Loading plugin "bandcamp"... Dec 09 14:53:09 volumio volumio[15315]: info: Plugin calmradio is not enabled Dec 09 14:53:09 volumio volumio[15315]: info: Loading plugin "soundcloud"... Dec 09 14:53:09 volumio volumio[15315]: info: Loading plugin "spop"... Dec 09 14:53:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Dec 09 14:53:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:09 volumio go-librespot[15394]: go-librespot daemon starting... Dec 09 14:53:09 volumio go-librespot[15395]: time="2025-12-09T14:53:09-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:09 volumio go-librespot[15395]: time="2025-12-09T14:53:09-06:00" level=debug msg="app state loaded" Dec 09 14:53:09 volumio go-librespot[15395]: time="2025-12-09T14:53:09-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:09 volumio go-librespot[15395]: time="2025-12-09T14:53:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=info msg="zeroconf server listening on port 38579" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="obtained new client token: AAAJW+9jdp4zDcefK9EHJ2h4AJvaFhDMks4lTF5UKetmQv2u3ZkWQhfbOaLfZPVF5bYKuqg479eRgoMralJsd+C2Yi+hE8VZNLr0Hg7RPVoPCPe4xr3X3WKo2mpA9occ3+sFUvQKVyCFlmdwh39fI1vxVNjV08jEcb5vgImd9SujrKz6GdgrJVQXkINylbgNnnpECJcIE60vVDrZra6VZnDbQgRitgPMcQMG2KWJd12wiqDuZPBSX3c=" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=debug msg="completed challenge" Dec 09 14:53:10 volumio go-librespot[15395]: time="2025-12-09T14:53:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:10 volumio volumio[15315]: info: Loading plugin "squeezelite_mc"... Dec 09 14:53:11 volumio volumio[15315]: info: Loading plugin "youtube2"... Dec 09 14:53:12 volumio volumio[15315]: info: Loading plugin "ytcr"... Dec 09 14:53:13 volumio volumio[15315]: info: Loading plugin "ytmusic"... Dec 09 14:53:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Dec 09 14:53:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:13 volumio go-librespot[15402]: go-librespot daemon starting... Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="app state loaded" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=info msg="zeroconf server listening on port 39391" Dec 09 14:53:13 volumio volumio[15315]: info: Plugin now_playing is not enabled Dec 09 14:53:13 volumio volumio[15315]: info: Loading plugin "outputs"... Dec 09 14:53:13 volumio volumio[15315]: info: Loading plugin "albumart"... Dec 09 14:53:13 volumio volumio[15315]: info: Plugin example_plugin is not enabled Dec 09 14:53:13 volumio volumio[15315]: info: Loading plugin "inputs"... Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="obtained new client token: AABk6ZvUJDreBSBpo5NJ3uJGw0rdFufoUQ2ybX56UuwsrQCwfruePuedaawuAnLIu1x2twjiKDw5D0tneXbLp0DjKgMYsovDKtLOwiQNnS18TVPRoXqJn7ADdn7St2z3nCegIs51TRQIUEcbmQl4GibueEvb6R8AMZ/rM7Zr7bnyE2pymfDd3579WoJe1QviImo9H885yCts/ULMF+sNAXpl38xvmKNjNNkL9rDIcsvk8eHJ3ksWZjbpLA==" Dec 09 14:53:13 volumio volumio[15315]: info: Loading plugin "updater_comm"... Dec 09 14:53:13 volumio go-librespot[15403]: time="2025-12-09T14:53:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:13 volumio volumio[15315]: info: Plugin mpdemulation is not enabled Dec 09 14:53:13 volumio volumio[15315]: info: Loading plugin "rest_api"... Dec 09 14:53:14 volumio go-librespot[15403]: time="2025-12-09T14:53:14-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:14 volumio go-librespot[15403]: time="2025-12-09T14:53:14-06:00" level=debug msg="completed challenge" Dec 09 14:53:14 volumio volumio[15315]: info: Loading plugin "websocket"... Dec 09 14:53:14 volumio volumio[15315]: info: Starting Socket.io Server version 1.7.4 Dec 09 14:53:14 volumio volumio[15315]: info: Plugin fusiondsp is not enabled Dec 09 14:53:14 volumio volumio[15315]: info: Plugin mpdoutput is not enabled Dec 09 14:53:14 volumio volumio[15315]: info: Plugin RoonBridge is not enabled Dec 09 14:53:14 volumio volumio[15315]: info: Loading plugin "podcast"... Dec 09 14:53:14 volumio go-librespot[15403]: time="2025-12-09T14:53:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:14 volumio volumio[15315]: info: ControllerPodcast::constructor Dec 09 14:53:14 volumio volumio[15315]: info: Loading plugin "volusonic"... Dec 09 14:53:14 volumio volumio[15410]: Forking 3 albumart workers Dec 09 14:53:15 volumio volumio[15315]: info: Applying required configuration parameters for plugin volusonic Dec 09 14:53:15 volumio volumio[15315]: info: Loading plugin "backup_restore"... Dec 09 14:53:15 volumio volumio[15420]: Starting albumart workers Dec 09 14:53:16 volumio volumio[15421]: Starting albumart workers Dec 09 14:53:16 volumio volumio[15315]: info: Applying required configuration parameters for plugin backup_restore Dec 09 14:53:16 volumio volumio[15315]: info: Plugin rpi_eeprom_config is not enabled Dec 09 14:53:16 volumio volumio[15315]: info: Plugin rpi_eeprom_updater is not enabled Dec 09 14:53:16 volumio volumio[15315]: info: Loading plugin "scheduledrestart"... Dec 09 14:53:16 volumio volumio[15422]: Starting albumart workers Dec 09 14:53:16 volumio volumio[15315]: info: Applying required configuration parameters for plugin scheduledrestart Dec 09 14:53:16 volumio volumio[15315]: info: Plugin Bluetoothremote is not enabled Dec 09 14:53:16 volumio volumio[15315]: info: Plugin music_services_shield is not enabled Dec 09 14:53:16 volumio volumio[15315]: info: Loading plugin "Systeminfo"... Dec 09 14:53:16 volumio volumio[15315]: info: Plugin peppymeterbasic is not enabled Dec 09 14:53:16 volumio volumio[15315]: info: Loading plugin "peppyspectrum"... Dec 09 14:53:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Dec 09 14:53:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:17 volumio volumio[15315]: info: Loading i18n strings for locale en Dec 09 14:53:17 volumio volumio[15315]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 14:53:17 volumio volumio[15315]: Updating browse sources language Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:17 volumio go-librespot[15483]: go-librespot daemon starting... Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="app state loaded" Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::initPlayerControls Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: Express server listening on port 3000 Dec 09 14:53:17 volumio volumio[15315]: [Metrics] WebUI: 14s 546.13ms Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::resetVolumioState Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::getcurrentVolume Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:17 volumio sudo[15496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 14:53:17 volumio sudo[15496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:17 volumio sudo[15496]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:17 volumio sudo[15498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 14:53:17 volumio sudo[15498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:17 volumio sudo[15498]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=info msg="zeroconf server listening on port 36101" Dec 09 14:53:17 volumio volumio[15315]: info: Volumio Network Manager: Network status updated: 1 Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="obtained new client token: AACKWzwRU4N8zW0LWNgcScW5hISuw2Rd/JBp5fHo4DjoIsvDtjaVMM5YstS3Bosettw4CVruAmyilHY3ASD77FDHDSOc/g9eKnh0htxBjG83jj6sSfVcDZAuxnnEa/EY0S/6Yypoxrv6R57JEKEo7UXh40/aL+oxQyrBdb8mw3sVZl6jCphjt0LAnKsHgcTr+5uZotSUKMMt5O/8JKr2nqs7Bh6jnYbkhFKnAVMIfumvDG3V///Z9BZYjg==" Dec 09 14:53:17 volumio volumio[15315]: info: VolumeController:: Volume=86 Mute =false Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::pushState Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioPushState Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::updateTrackBlock Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrackBlock Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:17 volumio volumio[15315]: info: Reloading queue from file Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::setRepeat null single undefined Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::pushState Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioPushState Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::setRandom null Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::pushState Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioPushState Dec 09 14:53:17 volumio volumio[15315]: info: Setting Device type: Raspberry PI Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=debug msg="completed challenge" Dec 09 14:53:17 volumio volumio[15315]: info: VolumeController:: Volume=86 Mute =false Dec 09 14:53:17 volumio volumio[15315]: info: CoreStateMachine::pushState Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioPushState Dec 09 14:53:17 volumio go-librespot[15484]: time="2025-12-09T14:53:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:17 volumio volumio[15315]: info: Completed loading Core Plugins Dec 09 14:53:17 volumio volumio[15315]: info: Preparing to generate the ALSA configuration file Dec 09 14:53:17 volumio sudo[15511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 09 14:53:17 volumio sudo[15511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:17 volumio volumio[15315]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 14:53:17 volumio volumio[15315]: info: Discovery: Found device Volumio Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:17 volumio volumio[15315]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 14:53:17 volumio volumio[15315]: info: Discovery: Found device Volumio Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:17 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:17 volumio volumio[15315]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 14:53:17 volumio volumio[15315]: info: Reading ALSA contributions from plugins. Dec 09 14:53:17 volumio volumio[15315]: info: Asound.conf file unchanged, so no further update is needed Dec 09 14:53:17 volumio volumio[15315]: info: Output device has changed, restarting MPD Dec 09 14:53:17 volumio sudo[15511]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:17 volumio volumio[15315]: info: Output device has changed, restarting Shairport Sync Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:17 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:17 volumio sudo[15514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 14:53:17 volumio sudo[15514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:17 volumio sudo[15514]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:17 volumio sudo[15516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 14:53:17 volumio sudo[15516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:17 volumio volumio[15315]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:53:17 volumio volumio[15315]: info: ___________ START PLUGINS ___________ Dec 09 14:53:17 volumio volumio[15315]: info: ControllerMpd::onStart: Initializing MPD Dec 09 14:53:18 volumio volumio[15315]: info: Creating MPD Configuration file Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598024] CoreMusicLibrary::Adding element Media Servers Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 09 14:53:18 volumio sudo[15524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 14:53:18 volumio sudo[15524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:18 volumio sudo[15524]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:18 volumio sudo[15526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 14:53:18 volumio sudo[15526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:18 volumio volumio[15315]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:18 volumio volumio[15315]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598148] CoreMusicLibrary::Adding element Last_100 Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598152] CoreMusicLibrary::Adding element Webradio Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:53:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 14:53:18 volumio systemd[1]: mpd.service: Consumed 4.587s CPU time. Dec 09 14:53:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 14:53:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 14:53:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 14:53:18 volumio volumio[15315]: info: Initializing BBC Radios Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598226] CoreMusicLibrary::Adding element Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 14:53:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598243] CoreMusicLibrary::Adding element SoundCloud Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: info: Creating Spotify config file Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:18 volumio sudo[15551]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 14:53:18 volumio sudo[15551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 14:53:18 volumio sudo[15551]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:18 volumio volumio[15315]: info: [squeezelite_mc] Starting proxy server... Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598601] CoreMusicLibrary::Adding element YouTube2 Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598620] CoreMusicLibrary::Adding element YouTube Music Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube Music Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598631] CoreMusicLibrary::Adding element Podcast Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube Music Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Podcast Dec 09 14:53:18 volumio volumio[15315]: info: Loading i18n strings for locale en Dec 09 14:53:18 volumio volumio[15315]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 14:53:18 volumio volumio[15315]: Updating browse sources language Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube Music Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Podcast Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube Music Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Podcast Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:18 volumio volumio[15315]: info: [1765313598685] CoreMusicLibrary::Adding element Volusonic Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source YouTube Music Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Podcast Dec 09 14:53:18 volumio volumio[15315]: Cannot find translation for source Volusonic Dec 09 14:53:18 volumio volumio[15315]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 09 14:53:18 volumio volumio[15315]: info: Volumio Calling Home Dec 09 14:53:18 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:18] [connect] Successful connection Dec 09 14:53:18 volumio volumio[15315]: info: [squeezelite_mc] Proxy server started on port 36529 Dec 09 14:53:18 volumio volumio[15315]: info: Preparing to generate the ALSA configuration file Dec 09 14:53:18 volumio volumio[15315]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 14:53:18 volumio volumio[15315]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 14:53:18 volumio volumio[15315]: info: Reading ALSA contributions from plugins. Dec 09 14:53:18 volumio volumio[15315]: info: MPD Permissions set Dec 09 14:53:18 volumio volumio[15315]: info: MPD Permissions set Dec 09 14:53:18 volumio volumio[15315]: info: Upmpdcli Daemon Started Dec 09 14:53:18 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765313598 101 Dec 09 14:53:19 volumio volumio[15315]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 09 14:53:19 volumio volumio[15315]: info: Spotify config file written Dec 09 14:53:19 volumio sudo[15563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 09 14:53:19 volumio sudo[15563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:19 volumio volumio[15315]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 09 14:53:19 volumio volumio[15315]: info: VolumeController:: Volume=86 Mute =false Dec 09 14:53:19 volumio volumio[15315]: info: CoreStateMachine::pushState Dec 09 14:53:19 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::volumioPushState Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Server discovery started Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Player finder started Dec 09 14:53:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:19 volumio go-librespot[15565]: go-librespot daemon starting... Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 09 14:53:19 volumio sudo[15563]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="app state loaded" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio volumio[15315]: info: No need to fix Spotify hosts Dec 09 14:53:19 volumio volumio[15315]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 09 14:53:19 volumio volumio[15315]: info: Volumio called home Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=info msg="zeroconf server listening on port 44505" Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 09 14:53:19 volumio volumio[15315]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 14:53:19 volumio volumio[15315]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 14:53:19 volumio volumio[15315]: SPOTIFY: BQALc6485eukPi2t12KdFGxtpwHt4IByhTzlvDGP0aS_9CKrbSKDh6BlPzgKckjRDrWSLkaItrRuffL1apQUZpJOfQJEMBH-Xal0wp0yBZNUCQ7ix3m2mqEkpu10dGZWsdUeKAZAH24ziW_pmcdyNYKqcEEpASgjqfNU8hK7PqD4zOpqv3WAQy3xHe3kNrcinZhoV5xJatO4hrQ2ncJan4DWHzX8WfrJUwvqaB0 Dec 09 14:53:19 volumio volumio[15315]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 14:53:19 volumio volumio[15315]: info: New Spotify access token = BQALc6485eukPi2t12KdFGxtpwHt4IByhTzlvDGP0aS_9CKrbSKDh6BlPzgKckjRDrWSLkaItrRuffL1apQUZpJOfQJEMBH-Xal0wp0yBZNUCQ7ix3m2mqEkpu10dGZWsdUeKAZAH24ziW_pmcdyNYKqcEEpASgjqfNU8hK7PqD4zOpqv3WAQy3xHe3kNrcinZhoV5xJatO4hrQ2ncJan4DWHzX8WfrJUwvqaB0 Dec 09 14:53:19 volumio volumio[15315]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 09 14:53:19 volumio volumio[15315]: info: Starting Shairport Sync Dec 09 14:53:19 volumio volumio[15315]: info: Starting Shairport Sync Dec 09 14:53:19 volumio volumio[15315]: info: Starting Shairport Sync Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="obtained new client token: AAAE4r7psVXJ854Rl0xuAOe551VB/Ew8y+8w71M2pclxHwWL6Nz6cmJd51oSXkNqYixkCZ84R+e/r85H2x4Qs1E60lwdsUqjgz//vjcNfCV88Ah1tjp6sRZEsKSxVL0eIwowxF/7Y0tgqdTjDTrw4nS8oJ6eZmkeyYOJ0qsQaheTO7ks8qS3WpXwqkcjHF6XRT4ONuq3dejBoXdYWbkh9HnJv0gT71iNZ69NVGTUR95lBX9HhKnAY96ztA==" Dec 09 14:53:19 volumio sudo[15589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:53:19 volumio sudo[15591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:53:19 volumio sudo[15591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio sudo[15589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio sudo[15587]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 14:53:19 volumio sudo[15587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio sudo[15593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:53:19 volumio sudo[15593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio sudo[15587]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:19 volumio volumio[15315]: info: Asound.conf file unchanged, so no further update is needed Dec 09 14:53:19 volumio volumio[15315]: info: Output device has changed, restarting MPD Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=debug msg="completed challenge" Dec 09 14:53:19 volumio sudo[15599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 14:53:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 14:53:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 14:53:19 volumio volumio[15315]: info: Output device has changed, restarting Shairport Sync Dec 09 14:53:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:19 volumio systemd[1]: shairport-sync.service: Consumed 1.997s CPU time. Dec 09 14:53:19 volumio sudo[15599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:19 volumio sudo[15599]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:19 volumio go-librespot[15566]: time="2025-12-09T14:53:19-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:19 volumio volumio[15315]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:53:19 volumio sudo[15601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 14:53:19 volumio sudo[15601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:53:19 volumio sudo[15589]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:19 volumio sudo[15593]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:19 volumio sudo[15591]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:20 volumio volumio[15315]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 09 14:53:20 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 14:53:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 14:53:20 volumio systemd[1]: mpd.service: Consumed 1.648s CPU time. Dec 09 14:53:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 14:53:20 volumio sudo[15614]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 09 14:53:20 volumio mpd_monitor.sh[15553]: MPD error: Connection reset by peer Dec 09 14:53:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 14:53:20 volumio sudo[15614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:20 volumio mpd_monitor.sh[15145]: MPD Monitor Service: MPD Appears to be inactive, restarting Dec 09 14:53:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 14:53:20 volumio mpd_monitor.sh[15629]: mpd: no process found Dec 09 14:53:20 volumio sudo[15614]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:20 volumio volumio[15315]: info: MPD Permissions set Dec 09 14:53:20 volumio volumio[15315]: info: Shairport-Sync Started Dec 09 14:53:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 14:53:20 volumio volumio[15315]: Error adding Membership: Error: addMembership EINVAL Dec 09 14:53:20 volumio volumio[15315]: info: Shairport-Sync Started Dec 09 14:53:20 volumio volumio[15315]: info: Shairport-Sync Started Dec 09 14:53:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 14:53:20 volumio volumio[15315]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 14:53:20 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 14:53:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 14:53:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 14:53:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 14:53:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:20 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:20 volumio volumio[15315]: info: Starting Shairport Sync Dec 09 14:53:20 volumio volumio[15315]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 09 14:53:20 volumio volumio[15315]: info: Spotify Successfully logged in Dec 09 14:53:20 volumio sudo[15637]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:53:20 volumio volumio[15315]: info: [1765313600449] CoreMusicLibrary::Adding element Spotify Dec 09 14:53:20 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source Bandcamp Discover Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source SoundCloud Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source YouTube2 Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source YouTube Music Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source Podcast Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source Volusonic Dec 09 14:53:20 volumio volumio[15315]: Cannot find translation for source Spotify Dec 09 14:53:20 volumio sudo[15637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:20 volumio sudo[15646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:53:20 volumio sudo[15646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:20 volumio sudo[15637]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:20 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 09 14:53:20 volumio sudo[15644]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 14:53:20 volumio sudo[15644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 14:53:20 volumio sudo[15644]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 14:53:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 14:53:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:53:20 volumio sudo[15651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 09 14:53:20 volumio sudo[15651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:53:20 volumio sudo[15646]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:20 volumio volumio[15315]: info: Shairport-Sync Started Dec 09 14:53:20 volumio systemd[1]: Reloading. Dec 09 14:53:20 volumio volumio[15315]: info: [squeezelite_mc] Notification listener started Dec 09 14:53:20 volumio volumio[15315]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 14:53:21 volumio volumio[15315]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 14:53:21 volumio volumio[15315]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 14:53:21 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:21 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:21 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:53:21 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:53:22 volumio volumio[15315]: info: go-librespot daemon successfully initialized Dec 09 14:53:22 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:22 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:22 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:22 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:22 volumio sudo[15651]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:22 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:22 volumio sudo[15687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:22 volumio sudo[15687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Dec 09 14:53:23 volumio sudo[15687]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:23 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 09 14:53:23 volumio sudo[15691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 09 14:53:23 volumio sudo[15691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:23 volumio go-librespot[15689]: go-librespot daemon starting... Dec 09 14:53:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="app state loaded" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:23 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 14:53:23 volumio volumio[15315]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 09 14:53:23 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:23 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:23 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 09 14:53:23 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 14:53:23 volumio sudo[15691]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=info msg="zeroconf server listening on port 36669" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="obtained new client token: AADYPQf8lxf4cvhWtG5MKJqlleEeSN338m7sBijqTrkefY0q0njLcpSTes4y7L6LXuir3BLda1JZGfYQB7X8N28ZzU+Og21HxHoDbxF+zr7WWfXEkZx9YwrEzfTJvwnO06LsD/SPZX1ZWtw0XCqYCuPiI3WAZeA+stCUoIqaW1rhoTjwYsAa/07xUuiGtNyemKTc5MRWwwDwjrQ0gNOpE7UQNL6MB5A9FAXj2gicEzZQIUYYDraTszg0Bg==" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=debug msg="completed challenge" Dec 09 14:53:23 volumio go-librespot[15693]: time="2025-12-09T14:53:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:23 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:23 volumio sudo[15701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:23 volumio sudo[15701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:24 volumio sudo[15701]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 09 14:53:24 volumio sudo[15705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 09 14:53:24 volumio sudo[15705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:24 volumio sudo[15705]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 09 14:53:24 volumio sudo[15708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 09 14:53:24 volumio sudo[15708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:24 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 14:53:24 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 14:53:24 volumio sudo[15708]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 14:53:24 volumio mpd[15652]: 2025-12-09T14:53:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 09 14:53:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 09 14:53:24 volumio mpd_monitor.sh[15145]: MPD Monitor Service: MPD restarted due to no mpc output. Dec 09 14:53:24 volumio sudo[15516]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:24 volumio sudo[15601]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:24 volumio sudo[15526]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:24 volumio volumio[15315]: error: MPD error: The expression evaluated to a falsy value: Dec 09 14:53:24 volumio volumio[15315]: assert.ok(self.idling) Dec 09 14:53:24 volumio volumio[15315]: error: The expression evaluated to a falsy value: Dec 09 14:53:24 volumio volumio[15315]: assert.ok(self.idling) Dec 09 14:53:24 volumio volumio[15315]: error: MPD error: The expression evaluated to a falsy value: Dec 09 14:53:24 volumio volumio[15315]: assert.ok(self.idling) Dec 09 14:53:24 volumio volumio[15315]: error: The expression evaluated to a falsy value: Dec 09 14:53:24 volumio volumio[15315]: assert.ok(self.idling) Dec 09 14:53:24 volumio volumio[15315]: info: MPD running with PID15652 Dec 09 14:53:24 volumio volumio[15315]: ,establishing connection Dec 09 14:53:24 volumio volumio[15315]: error: updateQueue error: null Dec 09 14:53:24 volumio volumio[15315]: error: updateQueue error: null Dec 09 14:53:24 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:24 volumio sudo[15720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:24 volumio sudo[15720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:24 volumio sudo[15720]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:25 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:25 volumio sudo[15723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:25 volumio sudo[15723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:25 volumio sudo[15723]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:25 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:25 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:25 volumio volumio[15315]: info: Initializing connection to go-librespot Websocket Dec 09 14:53:25 volumio volumio[15315]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:53:25 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:26 volumio sudo[15740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:26 volumio sudo[15740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:26 volumio sudo[15740]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:26 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:26 volumio sudo[15743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:26 volumio sudo[15743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:26 volumio sudo[15743]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Dec 09 14:53:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:26 volumio go-librespot[15745]: go-librespot daemon starting... Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="app state loaded" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:27 volumio volumio[15315]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:53:27 volumio sudo[15754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:53:27 volumio sudo[15754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:27 volumio sudo[15754]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:27 volumio volumio[15315]: info: Completed starting Core Plugins Dec 09 14:53:27 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:27 volumio volumio[15315]: info: ----- MyVolumio plugins startup ---- Dec 09 14:53:27 volumio volumio[15315]: info: ------------------------------------------- Dec 09 14:53:27 volumio volumio[15315]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=info msg="zeroconf server listening on port 45719" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="obtained new client token: AAAfhEQz6ybXP5xVfNVJYMi/+xjus8ehomf6UfQ396EgD5S6aserx7um1XJHkVfebpLX7yfpntzmCivT2cfs2KXIy8joptTvNREi792+IGLg0qmWgVOCPFI/BljaY7F0L7DfZvL4SflvEOmEAxAbRo9bv0P+D61ojifcbtSersPf4DImc5bybLjK9a6URheXSL0tr0nBVIxMNasbIEB62DcuQ9CYxVW/rij0HyAfbKF/+noKDNXSXSwA+g==" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Dec 09 14:53:27 volumio sudo[15757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 14:53:27 volumio sudo[15757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:27 volumio sudo[15759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 14:53:27 volumio sudo[15759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=debug msg="completed challenge" Dec 09 14:53:27 volumio sudo[15762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 14:53:27 volumio sudo[15762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:27 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 14:53:27 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 14:53:27 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 14:53:27 volumio go-librespot[15746]: time="2025-12-09T14:53:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:27 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 14:53:27 volumio sudo[15759]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:27 volumio mpd_monitor.sh[15765]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 14:53:27 volumio sudo[15762]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:27 volumio sudo[15757]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:27 volumio volumio[15315]: info: Successfully started MPD Monitor Dec 09 14:53:27 volumio volumio[15315]: info: Successfully started MPD Monitor Dec 09 14:53:27 volumio volumio[15315]: info: Successfully started MPD Monitor Dec 09 14:53:28 volumio volumio[15315]: info: Initializing connection to go-librespot Websocket Dec 09 14:53:28 volumio volumio[15315]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:53:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Dec 09 14:53:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:30 volumio go-librespot[15769]: go-librespot daemon starting... Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="app state loaded" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=info msg="zeroconf server listening on port 42751" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="obtained new client token: AACaR/HF31wbd71685/Lv+Zy0zAFnAIamFzW46JSTq50p3wRw51wgabHpcSohme3RVJhputLzNbg++XglDi7YSljP9hHC6ohkUikFlCSB3feQ/6VtEh2wgPGOnqBnwe5XZZfdJGowN7+a58GQwtZsVZZ4QXpoaBOa1Dv7KgUCIcWLJxRg4XDtBDvm3uu2wyxEClYSOcmd1R2tlHwvDb/lwv1SkkArpAu97x33MaKtVSaHgKfkQ7VQLu3pA==" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=debug msg="completed challenge" Dec 09 14:53:31 volumio go-librespot[15770]: time="2025-12-09T14:53:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:32 volumio volumio[15315]: info: Initializing connection to go-librespot Websocket Dec 09 14:53:32 volumio volumio[15315]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:53:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Dec 09 14:53:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:34 volumio go-librespot[15778]: go-librespot daemon starting... Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=debug msg="app state loaded" Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 14:53:34 volumio go-librespot[15779]: time="2025-12-09T14:53:34-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 14:53:35 volumio go-librespot[15779]: time="2025-12-09T14:53:35-06:00" level=info msg="zeroconf server listening on port 42067" Dec 09 14:53:35 volumio go-librespot[15779]: time="2025-12-09T14:53:35-06:00" level=debug msg="obtained new client token: AAAtC0RwkiAT2dx7+pqkvJNod2a2TJYGdjXGNzpijnF9w1O644MTdwIi5SARm9m52VG/zTifRsB5bERpx/7ijWZgfvwvoB9Yua1H4e2LsyW+0Cc542eH+IadB20qOX4Jj7q3UPjfC/hfBwQYHVWT63FO7QpsbWvw3W8u4c60Q9F+S5I5P8PtjwZF8B6UznTHtcl6NVsFCNIiM9QqBejPZA9AsYzUY8mtvP5cN8iNK7hZFRr1miu5Bgs=" Dec 09 14:53:35 volumio go-librespot[15779]: time="2025-12-09T14:53:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:35 volumio go-librespot[15779]: time="2025-12-09T14:53:35-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:35 volumio go-librespot[15779]: time="2025-12-09T14:53:35-06:00" level=debug msg="completed challenge" Dec 09 14:53:35 volumio go-librespot[15779]: time="2025-12-09T14:53:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:35 volumio volumio[15315]: info: Initializing connection to go-librespot Websocket Dec 09 14:53:35 volumio volumio[15315]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin bluetooth to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin multiroom to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin metavolumio to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin cd_controller to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 09 14:53:35 volumio volumio[15315]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 09 14:53:36 volumio volumio[15315]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 09 14:53:36 volumio volumio[15315]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 09 14:53:36 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:36 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:36 volumio volumio[15315]: info: Starting MyVolumio Remote Streaming Endpoints Dec 09 14:53:36 volumio volumio[15315]: info: MyVolumio login type: Token Dec 09 14:53:36 volumio volumio[15315]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 09 14:53:36 volumio volumio[15315]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 09 14:53:37 volumio volumio[15315]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 09 14:53:37 volumio volumio[15315]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 09 14:53:37 volumio volumio[15315]: info: Streaming services startup Dec 09 14:53:37 volumio volumio[15315]: info: Starting Streaming Daemon Dec 09 14:53:37 volumio sudo[15802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 09 14:53:37 volumio sudo[15802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:37 volumio volumio[15315]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 09 14:53:37 volumio sudo[15802]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:37 volumio volumio[15315]: error: Cannot start Volumio Streaming Daemon Dec 09 14:53:37 volumio volumio[15315]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 09 14:53:37 volumio volumio[15315]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 09 14:53:37 volumio volumio[15315]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 09 14:53:38 volumio volumio[15315]: info: MyVolumio token set successfully Dec 09 14:53:38 volumio volumio[15315]: info: MYVOLUMIO: Adding device Dec 09 14:53:38 volumio volumio[15315]: info: MYVOLUMIO: Evaluating Server Dec 09 14:53:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Dec 09 14:53:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:38 volumio volumio[15315]: info: Initializing connection to go-librespot Websocket Dec 09 14:53:38 volumio volumio[15315]: info: MyVolumio status changed Dec 09 14:53:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:38 volumio volumio[15315]: info: Streaming services startup Dec 09 14:53:38 volumio volumio[15315]: info: Starting Streaming Daemon Dec 09 14:53:38 volumio go-librespot[15824]: go-librespot daemon starting... Dec 09 14:53:38 volumio volumio[15315]: info: Removing browser output: myVolumio user plan is not superstar Dec 09 14:53:38 volumio volumio[15315]: info: Removing audio output: Dec 09 14:53:38 volumio volumio[15315]: info: Stoppping Tunnel 1 Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="app state loaded" Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:38 volumio sudo[15837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:38 volumio sudo[15837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="new websocket client" Dec 09 14:53:38 volumio sudo[15839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 09 14:53:38 volumio sudo[15839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:38 volumio volumio[15315]: info: Connection to go-librespot Websocket established Dec 09 14:53:38 volumio sudo[15837]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio volumio[15315]: error: Cannot start Volumio Streaming Daemon Dec 09 14:53:38 volumio volumio[15315]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 09 14:53:38 volumio volumio[15315]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:53:38 volumio sudo[15839]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:38 volumio volumio[15315]: info: Remote SSH Stopped Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=info msg="zeroconf server listening on port 46189" Dec 09 14:53:38 volumio volumio[15315]: info: Setting Geolocation for MyVolumio to us1 Dec 09 14:53:38 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:38 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:38 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:38 volumio go-librespot[15830]: time="2025-12-09T14:53:38-06:00" level=debug msg="obtained new client token: AACYgtRquh+JgoQi9LfTor2AlbUYZBFdwBDWJmKo4rwxiof/NEvc+h1dsxVb/SIknEOt7hdMg0aSRzcfqoSN7EmIwatwFndtnupIXELxdA8mupJs56Nq/wUlDlMqyCF2zC5eJ3RICA5MdfF9UA+4f/Lk25FUeb+vvFqZUVpKKTPjXD49QgNu0LmBXI8VjDnL7riWkpVfk9uTSptVLBFQzOsDQjmBsdGcqwxihgoM5132PEoJeFOr9b33KQ==" Dec 09 14:53:39 volumio go-librespot[15830]: time="2025-12-09T14:53:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:39 volumio volumio[15315]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 09 14:53:39 volumio volumio[15315]: info: Updating MyVolumio device info Dec 09 14:53:39 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:39 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:39 volumio volumio[15315]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:53:40 volumio volumio[15315]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 09 14:53:41 volumio volumio[15315]: info: Getting Spotify volume Dec 09 14:53:41 volumio volumio[15315]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 09 14:53:41 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:41 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:41 volumio volumio[15315]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 09 14:53:41 volumio volumio[15315]: SPOTIFY: SPOTIFY VOLUME undefined Dec 09 14:53:41 volumio volumio[15315]: SPOTIFY: VOLUMIO VOLUME 86 Dec 09 14:53:41 volumio volumio[15315]: info: Aligning Spotify Volume to Volumio Volume Dec 09 14:53:41 volumio volumio[15315]: info: CoreCommandRouter::volumioGetState Dec 09 14:53:41 volumio volumio[15315]: info: CorePlayQueue::getTrack 0 Dec 09 14:53:41 volumio volumio[15315]: info: Setting Spotify Volume from Volumio: 86 Dec 09 14:53:42 volumio go-librespot[15830]: time="2025-12-09T14:53:42-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:42 volumio go-librespot[15830]: time="2025-12-09T14:53:42-06:00" level=debug msg="completed challenge" Dec 09 14:53:42 volumio go-librespot[15830]: time="2025-12-09T14:53:42-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:42 volumio volumio[15315]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 14:53:42 volumio volumio[15315]: Error: socket hang up Dec 09 14:53:42 volumio volumio[15315]: at connResetException (node:internal/errors:720:14) Dec 09 14:53:42 volumio volumio[15315]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 09 14:53:42 volumio volumio[15315]: at Socket.emit (node:events:526:35) Dec 09 14:53:42 volumio volumio[15315]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 09 14:53:42 volumio volumio[15315]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 09 14:53:42 volumio volumio[15315]: code: 'ECONNRESET', Dec 09 14:53:42 volumio volumio[15315]: response: undefined Dec 09 14:53:42 volumio volumio[15315]: } Dec 09 14:53:42 volumio volumio[15315]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 14:53:43 volumio sudo[15858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 14:52' Dec 09 14:53:43 volumio sudo[15858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:43 volumio sudo[15858]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:44 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:44] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Dec 09 14:53:44 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:44] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Dec 09 14:53:44 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:44 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 09 14:53:44 volumio systemd[1]: volumio.service: Consumed 45.934s CPU time. Dec 09 14:53:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 14:53:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 14:53:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24572. Dec 09 14:53:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 09 14:53:44 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 09 14:53:44 volumio systemd[1]: volumio.service: Consumed 45.934s CPU time. Dec 09 14:53:44 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 09 14:53:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 09 14:53:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Dec 09 14:53:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:45 volumio go-librespot[15893]: go-librespot daemon starting... Dec 09 14:53:45 volumio go-librespot[15894]: time="2025-12-09T14:53:45-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:45 volumio go-librespot[15894]: time="2025-12-09T14:53:45-06:00" level=debug msg="app state loaded" Dec 09 14:53:45 volumio go-librespot[15894]: time="2025-12-09T14:53:45-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:45 volumio go-librespot[15894]: time="2025-12-09T14:53:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=info msg="zeroconf server listening on port 39127" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="obtained new client token: AAAhAuXG/TyBK+vX30Ph+Vg2H5/ddvJlnuN6aedG4O2jyhDPQuCQmV1KqJ4P05d+zYvi5E0FEJ1dDrk8G+smh3DG002b8ovpRhOj3Xnf5i9gAMALoEYWAD4lItBOjoSKsiU+cKbQWEaXRQj+RP95RnzME0qTHld4CrVSgOuSCVtoRvLlve5esquAJOQJWJeCYYiF9jH20EyrulYfNJIAPVbUNU3wKso6B/XRBwy3Jr3+i2SzJdQ9izM=" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=debug msg="completed challenge" Dec 09 14:53:46 volumio go-librespot[15894]: time="2025-12-09T14:53:46-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:46 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:53:46 volumio volumio[15878]: info: ----- Volumio3 ---- Dec 09 14:53:46 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:53:46 volumio volumio[15878]: info: ----- System startup ---- Dec 09 14:53:46 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:53:47 volumio volumio[15878]: info: MYVOLUMIO Environment detected Dec 09 14:53:47 volumio volumio[15878]: info: Plugin folders cleanup Dec 09 14:53:47 volumio volumio[15878]: info: Scanning into folder /volumio/app/plugins/ Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category audio_interface Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category miscellanea Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category music_service Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category plugins.json Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category system_controller Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category user_interface Dec 09 14:53:47 volumio volumio[15878]: info: Scanning into folder /data/plugins/ Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category audio_interface Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category music_service Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category system_controller Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category system_hardware Dec 09 14:53:47 volumio volumio[15878]: info: Scanning category user_interface Dec 09 14:53:47 volumio volumio[15878]: info: Plugin folders cleanup completed Dec 09 14:53:47 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:53:47 volumio volumio[15878]: info: ----- Core plugins startup ---- Dec 09 14:53:47 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:53:47 volumio volumio[15878]: info: Loading plugins from folder /volumio/app/plugins/ Dec 09 14:53:47 volumio volumio[15878]: info: Adding plugin upnp to MyMusic Plugins Dec 09 14:53:47 volumio volumio[15878]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 09 14:53:47 volumio volumio[15878]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 09 14:53:47 volumio volumio[15878]: info: Loading plugins from folder /data/plugins/ Dec 09 14:53:47 volumio volumio[15878]: info: Loading plugin "system"... Dec 09 14:53:47 volumio volumio[15878]: info: Loading plugin "appearance"... Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "network"... Dec 09 14:53:48 volumio volumio[15878]: info: Refreshing Cached IP Addresses Dec 09 14:53:48 volumio sudo[15917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 14:53:48 volumio sudo[15917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:48 volumio sudo[15919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 14:53:48 volumio sudo[15919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:48 volumio sudo[15917]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "services"... Dec 09 14:53:48 volumio sudo[15919]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "alsa_controller"... Dec 09 14:53:48 volumio sudo[15926]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 09 14:53:48 volumio sudo[15926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:48 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "wizard"... Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "networkfs"... Dec 09 14:53:48 volumio volumio[15878]: info: Starting Udev Watcher for removable devices Dec 09 14:53:48 volumio volumio[15878]: info: Ignoring mount for partition: boot Dec 09 14:53:48 volumio volumio[15878]: info: Ignoring mount for partition: volumio Dec 09 14:53:48 volumio volumio[15878]: info: Ignoring mount for partition: volumio_data Dec 09 14:53:48 volumio volumio[15878]: info: Mounting Device Wikipedia Dec 09 14:53:48 volumio sudo[15956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 09 14:53:48 volumio sudo[15956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:53:48 volumio sudo[15956]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:48 volumio volumio[15878]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 14:53:48 volumio volumio[15878]: dmesg(1) may have more information after failed mount system call. Dec 09 14:53:48 volumio volumio[15878]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 09 14:53:48 volumio volumio[15878]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 09 14:53:48 volumio volumio[15878]: dmesg(1) may have more information after failed mount system call. Dec 09 14:53:48 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "volumio_command_line_client"... Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "upnp"... Dec 09 14:53:48 volumio volumio[15878]: info: [1765313628952] Starting Upmpd Daemon Dec 09 14:53:48 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "my_music"... Dec 09 14:53:48 volumio volumio[15878]: info: Loading plugin "mpd"... Dec 09 14:53:49 volumio sudo[15926]: pam_unix(sudo:session): session closed for user root Dec 09 14:53:49 volumio volumio[15878]: info: Loading plugin "upnp_browser"... Dec 09 14:53:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Dec 09 14:53:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:49 volumio go-librespot[15958]: go-librespot daemon starting... Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=debug msg="app state loaded" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:49 volumio volumio-remote-updater[9752]: [2025-12-09 14:53:49] [connect] Successful connection Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=info msg="zeroconf server listening on port 35625" Dec 09 14:53:49 volumio go-librespot[15959]: time="2025-12-09T14:53:49-06:00" level=debug msg="obtained new client token: AABQOIqGxcH+3UGT35ZjUhBLj4K6PsIwzL53J1gFuKz38cHgN2D9ciTrJBV3A6IYpfFuhSm1Sfq6MWO8qLj7eDA8/+ntDIk+c8jGc8KlNo3qUwEphOCTN4WAO9SPBbeG7tTQ7K17YMPFtPpoS9cQ/lD2WYmKDZYG00BFuNbRjehdU92anSRQi1tmGGSZtMPV4kiPrTT86LiAbN1SUBUJ9raOA14mVuAXKEKxDBDfzEeZQ9kbmIXEJ7S36w==" Dec 09 14:53:50 volumio go-librespot[15959]: time="2025-12-09T14:53:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:50 volumio go-librespot[15959]: time="2025-12-09T14:53:50-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:50 volumio go-librespot[15959]: time="2025-12-09T14:53:50-06:00" level=debug msg="completed challenge" Dec 09 14:53:50 volumio go-librespot[15959]: time="2025-12-09T14:53:50-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:50 volumio volumio[15878]: info: Loading plugin "alarm-clock"... Dec 09 14:53:50 volumio volumio[15878]: info: Loading plugin "airplay_emulation"... Dec 09 14:53:50 volumio volumio[15878]: info: Starting Shairport Sync Dec 09 14:53:50 volumio volumio[15878]: info: Loading plugin "last_100"... Dec 09 14:53:50 volumio volumio[15878]: info: Loading plugin "webradio"... Dec 09 14:53:51 volumio volumio[15878]: info: Loading plugin "i2s_dacs"... Dec 09 14:53:51 volumio volumio[15878]: info: I2S DAC not set, start Auto-detection Dec 09 14:53:51 volumio volumio[15878]: info: Loading plugin "volumiodiscovery"... Dec 09 14:53:51 volumio volumio[15878]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:51 volumio volumio[15878]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:51 volumio volumio[15878]: *** WARNING *** For more information see Dec 09 14:53:51 volumio volumio[15878]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:51 volumio volumio[15878]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:51 volumio volumio[15878]: *** WARNING *** For more information see Dec 09 14:53:51 volumio node[15878]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:51 volumio node[15878]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:51 volumio node[15878]: *** WARNING *** For more information see Dec 09 14:53:51 volumio node[15878]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 09 14:53:51 volumio node[15878]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 09 14:53:51 volumio node[15878]: *** WARNING *** For more information see Dec 09 14:53:51 volumio volumio[15878]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 09 14:53:51 volumio volumio[15878]: info: Discovery: Started advertising with name: Volumio Dec 09 14:53:51 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 09 14:53:51 volumio volumio[15878]: info: Loading plugin "bandcamp"... Dec 09 14:53:52 volumio volumio[15878]: info: Plugin calmradio is not enabled Dec 09 14:53:52 volumio volumio[15878]: info: Loading plugin "soundcloud"... Dec 09 14:53:52 volumio volumio[15878]: info: Loading plugin "spop"... Dec 09 14:53:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Dec 09 14:53:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:53 volumio go-librespot[15968]: go-librespot daemon starting... Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="app state loaded" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=info msg="zeroconf server listening on port 42303" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="obtained new client token: AACPUwxJLWyXYmNNY/SiHvwbNp9UnNyGq0MuloTBlWxyfAEFzbqthJij4eHkpxxAtis2LpwDSJ9RqHl2t2E1s+f0MzZQAUElQKQF0YV5XrNo2rIiT2oU7ul+Gee88ZH+UF4LZLaJOmrH2LqwBlRJdEpo8uy7QkShLRNWW99deT7KHYevex1uwBxJ30EnMmidOcgT3+XfyDUdRhLQwcddlgYMpUYw3/Fvx8BTNKEV6BQGQj7XAxM2pHDCdw==" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:53 volumio volumio[15878]: info: Loading plugin "squeezelite_mc"... Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=debug msg="completed challenge" Dec 09 14:53:53 volumio go-librespot[15969]: time="2025-12-09T14:53:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:54 volumio volumio[15878]: info: Loading plugin "youtube2"... Dec 09 14:53:55 volumio volumio[15878]: info: Loading plugin "ytcr"... Dec 09 14:53:56 volumio volumio[15878]: info: Loading plugin "ytmusic"... Dec 09 14:53:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Dec 09 14:53:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:56 volumio volumio[15878]: info: Plugin now_playing is not enabled Dec 09 14:53:56 volumio volumio[15878]: info: Loading plugin "outputs"... Dec 09 14:53:56 volumio volumio[15878]: info: Loading plugin "albumart"... Dec 09 14:53:56 volumio volumio[15878]: info: Plugin example_plugin is not enabled Dec 09 14:53:56 volumio volumio[15878]: info: Loading plugin "inputs"... Dec 09 14:53:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:53:57 volumio go-librespot[15977]: go-librespot daemon starting... Dec 09 14:53:57 volumio volumio[15878]: info: Loading plugin "updater_comm"... Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="app state loaded" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="stored credentials not found" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:53:57 volumio volumio[15878]: info: Plugin mpdemulation is not enabled Dec 09 14:53:57 volumio volumio[15878]: info: Loading plugin "rest_api"... Dec 09 14:53:57 volumio volumio[15878]: info: Loading plugin "websocket"... Dec 09 14:53:57 volumio volumio[15878]: info: Starting Socket.io Server version 1.7.4 Dec 09 14:53:57 volumio volumio[15878]: info: Plugin fusiondsp is not enabled Dec 09 14:53:57 volumio volumio[15878]: info: Plugin mpdoutput is not enabled Dec 09 14:53:57 volumio volumio[15878]: info: Plugin RoonBridge is not enabled Dec 09 14:53:57 volumio volumio[15878]: info: Loading plugin "podcast"... Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=info msg="zeroconf server listening on port 46751" Dec 09 14:53:57 volumio volumio[15878]: info: ControllerPodcast::constructor Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="obtained new client token: AACxQX0sp2ed0ye2ishJsMufX0w/rp4X3JLN0K1NxgFEGhdhBI3fJeYTAqGuvm2FfEqlqGhBs/gy4+d8i5eCnYDR3l06TZeLWvT40ZWexCsymGondi0AUtSHB7nLdwrLt4wXfmQrtjrX2d1l84N/xXO09Ae431NYKzf7v2z9j1R4EPw9UO28tazhMubYi/wdsxzh+L7TLws6UfB/2lu0AW2YN5CW4V0PToDtKiSkqPjsUa2W0npAk3r7IQ==" Dec 09 14:53:57 volumio volumio[15878]: info: Loading plugin "volusonic"... Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="completed keyexchange" Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=debug msg="completed challenge" Dec 09 14:53:57 volumio volumio[15978]: Forking 3 albumart workers Dec 09 14:53:57 volumio go-librespot[15979]: time="2025-12-09T14:53:57-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:53:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:53:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:53:59 volumio volumio[15878]: info: Applying required configuration parameters for plugin volusonic Dec 09 14:53:59 volumio volumio[15878]: info: Loading plugin "backup_restore"... Dec 09 14:53:59 volumio volumio[15996]: Starting albumart workers Dec 09 14:53:59 volumio volumio[15995]: Starting albumart workers Dec 09 14:53:59 volumio volumio[15997]: Starting albumart workers Dec 09 14:53:59 volumio volumio[15878]: info: Applying required configuration parameters for plugin backup_restore Dec 09 14:53:59 volumio volumio[15878]: info: Plugin rpi_eeprom_config is not enabled Dec 09 14:53:59 volumio volumio[15878]: info: Plugin rpi_eeprom_updater is not enabled Dec 09 14:53:59 volumio volumio[15878]: info: Loading plugin "scheduledrestart"... Dec 09 14:53:59 volumio volumio[15878]: info: Applying required configuration parameters for plugin scheduledrestart Dec 09 14:53:59 volumio volumio[15878]: info: Plugin Bluetoothremote is not enabled Dec 09 14:53:59 volumio volumio[15878]: info: Plugin music_services_shield is not enabled Dec 09 14:53:59 volumio volumio[15878]: info: Loading plugin "Systeminfo"... Dec 09 14:54:00 volumio volumio[15878]: info: Plugin peppymeterbasic is not enabled Dec 09 14:54:00 volumio volumio[15878]: info: Loading plugin "peppyspectrum"... Dec 09 14:54:00 volumio volumio[15878]: info: Loading i18n strings for locale en Dec 09 14:54:00 volumio volumio[15878]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 14:54:00 volumio volumio[15878]: Updating browse sources language Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::initPlayerControls Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:54:00 volumio volumio[15878]: Express server listening on port 3000 Dec 09 14:54:00 volumio volumio[15878]: [Metrics] WebUI: 14s 411.99ms Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::resetVolumioState Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::getcurrentVolume Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:00 volumio sudo[16062]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 09 14:54:00 volumio sudo[16062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:00 volumio sudo[16062]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Dec 09 14:54:00 volumio sudo[16064]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 09 14:54:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:00 volumio sudo[16064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:00 volumio sudo[16064]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:00 volumio volumio[15878]: info: Volumio Network Manager: Network status updated: 1 Dec 09 14:54:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:00 volumio go-librespot[16068]: go-librespot daemon starting... Dec 09 14:54:00 volumio go-librespot[16070]: time="2025-12-09T14:54:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:00 volumio go-librespot[16070]: time="2025-12-09T14:54:00-06:00" level=debug msg="app state loaded" Dec 09 14:54:00 volumio go-librespot[16070]: time="2025-12-09T14:54:00-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:00 volumio go-librespot[16070]: time="2025-12-09T14:54:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:00 volumio volumio[15878]: info: VolumeController:: Volume=86 Mute =false Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::pushState Dec 09 14:54:00 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::volumioPushState Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::updateTrackBlock Dec 09 14:54:00 volumio volumio[15878]: info: CorePlayQueue::getTrackBlock Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 14:54:00 volumio volumio[15878]: info: Reloading queue from file Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::setRepeat null single undefined Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::pushState Dec 09 14:54:00 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::volumioPushState Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::setRandom null Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::pushState Dec 09 14:54:00 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::volumioPushState Dec 09 14:54:00 volumio volumio[15878]: info: Setting Device type: Raspberry PI Dec 09 14:54:00 volumio volumio[15878]: info: VolumeController:: Volume=86 Mute =false Dec 09 14:54:00 volumio volumio[15878]: info: CoreStateMachine::pushState Dec 09 14:54:00 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:00 volumio volumio[15878]: info: CoreCommandRouter::volumioPushState Dec 09 14:54:00 volumio volumio[15878]: info: Completed loading Core Plugins Dec 09 14:54:01 volumio volumio[15878]: info: Preparing to generate the ALSA configuration file Dec 09 14:54:01 volumio sudo[16085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 09 14:54:01 volumio sudo[16085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:01 volumio volumio[15878]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 14:54:01 volumio volumio[15878]: info: Reading ALSA contributions from plugins. Dec 09 14:54:01 volumio volumio[15878]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 14:54:01 volumio volumio[15878]: info: Discovery: Found device Volumio Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:01 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:01 volumio sudo[16085]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:01 volumio volumio[15878]: info: Asound.conf file unchanged, so no further update is needed Dec 09 14:54:01 volumio volumio[15878]: info: Output device has changed, restarting MPD Dec 09 14:54:01 volumio volumio[15878]: info: Output device has changed, restarting Shairport Sync Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:01 volumio sudo[16088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 14:54:01 volumio sudo[16088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:01 volumio sudo[16088]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:01 volumio sudo[16090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 14:54:01 volumio sudo[16090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:01 volumio volumio[15878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:54:01 volumio volumio[15878]: info: ___________ START PLUGINS ___________ Dec 09 14:54:01 volumio volumio[15878]: info: ControllerMpd::onStart: Initializing MPD Dec 09 14:54:01 volumio volumio[15878]: info: Creating MPD Configuration file Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641152] CoreMusicLibrary::Adding element Media Servers Dec 09 14:54:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio sudo[16098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 14:54:01 volumio sudo[16098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:01 volumio sudo[16098]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:01 volumio sudo[16100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 14:54:01 volumio sudo[16100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:01 volumio volumio[15878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:01 volumio volumio[15878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641283] CoreMusicLibrary::Adding element Last_100 Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 14:54:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 14:54:01 volumio systemd[1]: mpd.service: Consumed 4.603s CPU time. Dec 09 14:54:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 14:54:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 14:54:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641319] CoreMusicLibrary::Adding element Webradio Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:54:01 volumio volumio[15878]: info: Initializing BBC Radios Dec 09 14:54:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 14:54:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641410] CoreMusicLibrary::Adding element Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641422] CoreMusicLibrary::Adding element SoundCloud Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: info: Creating Spotify config file Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:01 volumio go-librespot[16070]: time="2025-12-09T14:54:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 14:54:01 volumio go-librespot[16070]: time="2025-12-09T14:54:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 14:54:01 volumio go-librespot[16070]: time="2025-12-09T14:54:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 14:54:01 volumio go-librespot[16070]: time="2025-12-09T14:54:01-06:00" level=info msg="zeroconf server listening on port 45079" Dec 09 14:54:01 volumio sudo[16122]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 14:54:01 volumio sudo[16122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 14:54:01 volumio sudo[16122]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:01 volumio go-librespot[16070]: time="2025-12-09T14:54:01-06:00" level=debug msg="obtained new client token: AABMqsWo6F6vd58t5bgD0HLduKP8t533z6Md/twXiDjAS0lAQKdjm2AhbCtIP9v4+HSDRXlk1lqR/Y1VZTghIeUnAGa6vQh+nGcBuOXFxrPESxAfnneGMe4UpPDtm78KH7MPPmQsg7yVPoPcBgTrxtPRBaamrT7JzeefPbJOwVqyyYAQABPjR5eLcOFEFxYnseVXJ61VwGht5d048ps+8Q7Jty2emqPr2oOgR2V+zTCFgiPKXi/j7A1XRQ==" Dec 09 14:54:01 volumio volumio[15878]: info: [squeezelite_mc] Starting proxy server... Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641795] CoreMusicLibrary::Adding element YouTube2 Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641829] CoreMusicLibrary::Adding element YouTube Music Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube Music Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641841] CoreMusicLibrary::Adding element Podcast Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube Music Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Podcast Dec 09 14:54:01 volumio volumio[15878]: info: Loading i18n strings for locale en Dec 09 14:54:01 volumio volumio[15878]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 09 14:54:01 volumio volumio[15878]: Updating browse sources language Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube Music Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Podcast Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube Music Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Podcast Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:01 volumio volumio[15878]: info: [1765313641889] CoreMusicLibrary::Adding element Volusonic Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source YouTube Music Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Podcast Dec 09 14:54:01 volumio volumio[15878]: Cannot find translation for source Volusonic Dec 09 14:54:01 volumio volumio[15878]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 09 14:54:01 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 09 14:54:01 volumio volumio[15878]: info: Volumio Calling Home Dec 09 14:54:02 volumio go-librespot[16070]: time="2025-12-09T14:54:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:02 volumio volumio-remote-updater[9752]: [2025-12-09 14:54:02] [connect] Successful connection Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Proxy server started on port 33163 Dec 09 14:54:02 volumio volumio[15878]: info: Preparing to generate the ALSA configuration file Dec 09 14:54:02 volumio go-librespot[16070]: time="2025-12-09T14:54:02-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:02 volumio go-librespot[16070]: time="2025-12-09T14:54:02-06:00" level=debug msg="completed challenge" Dec 09 14:54:02 volumio go-librespot[16070]: time="2025-12-09T14:54:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 14:54:02 volumio volumio[15878]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 09 14:54:02 volumio volumio[15878]: info: Discovery: Found device Volumio Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:02 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:02 volumio volumio[15878]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 09 14:54:02 volumio volumio[15878]: info: Reading ALSA contributions from plugins. Dec 09 14:54:02 volumio volumio[15878]: info: MPD Permissions set Dec 09 14:54:02 volumio volumio[15878]: info: MPD Permissions set Dec 09 14:54:02 volumio volumio[15878]: info: Upmpdcli Daemon Started Dec 09 14:54:02 volumio volumio-remote-updater[9752]: [2025-12-09 14:54:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765313642 101 Dec 09 14:54:02 volumio volumio[15878]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 09 14:54:02 volumio volumio[15878]: info: Spotify config file written Dec 09 14:54:02 volumio sudo[16135]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 09 14:54:02 volumio sudo[16135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:02 volumio volumio[15878]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 09 14:54:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:02 volumio volumio[15878]: info: VolumeController:: Volume=86 Mute =false Dec 09 14:54:02 volumio volumio[15878]: info: CoreStateMachine::pushState Dec 09 14:54:02 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::volumioPushState Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Server discovery started Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Player finder started Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:02 volumio go-librespot[16137]: go-librespot daemon starting... Dec 09 14:54:02 volumio sudo[16135]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=debug msg="app state loaded" Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:02 volumio volumio[15878]: info: No need to fix Spotify hosts Dec 09 14:54:02 volumio volumio[15878]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 09 14:54:02 volumio volumio[15878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 14:54:02 volumio volumio[15878]: SPOTIFY: BQCdHVDbO9vL4NCKDj9MNYBh3XslS-UqtWKr-yx0qO7X29xVThEfFHoZIPxh7dBBaoETQ1O2CvsjygwFcqamBAN65WSPO4O8ez1FPCHn9Erype5geU0TOJHxcB1crxwEnXnJv2FsbxsF4I3B7mq4qLlJxwl8A_OaVXtlytar7HU41O5u3NFOfLg6MTMKKneKXFQmAgzbTJsScA3VPEyGnGCwMmFeW_VrY1t1830 Dec 09 14:54:02 volumio volumio[15878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 09 14:54:02 volumio volumio[15878]: info: New Spotify access token = BQCdHVDbO9vL4NCKDj9MNYBh3XslS-UqtWKr-yx0qO7X29xVThEfFHoZIPxh7dBBaoETQ1O2CvsjygwFcqamBAN65WSPO4O8ez1FPCHn9Erype5geU0TOJHxcB1crxwEnXnJv2FsbxsF4I3B7mq4qLlJxwl8A_OaVXtlytar7HU41O5u3NFOfLg6MTMKKneKXFQmAgzbTJsScA3VPEyGnGCwMmFeW_VrY1t1830 Dec 09 14:54:02 volumio volumio[15878]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 09 14:54:02 volumio volumio[15878]: info: Volumio called home Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:02 volumio go-librespot[16143]: time="2025-12-09T14:54:02-06:00" level=info msg="zeroconf server listening on port 44635" Dec 09 14:54:02 volumio volumio[15878]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"} Dec 09 14:54:02 volumio volumio[15878]: info: Starting Shairport Sync Dec 09 14:54:02 volumio volumio[15878]: info: Starting Shairport Sync Dec 09 14:54:02 volumio volumio[15878]: info: Starting Shairport Sync Dec 09 14:54:02 volumio sudo[16161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:54:02 volumio sudo[16161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:02 volumio sudo[16164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:54:02 volumio sudo[16159]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Dec 09 14:54:02 volumio sudo[16164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:02 volumio sudo[16159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:02 volumio sudo[16159]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 14:54:03 volumio sudo[16166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:54:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 14:54:03 volumio sudo[16166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:54:03 volumio systemd[1]: shairport-sync.service: Consumed 1.896s CPU time. Dec 09 14:54:03 volumio go-librespot[16143]: time="2025-12-09T14:54:03-06:00" level=debug msg="obtained new client token: AAAW049XJFjDyX5ofQkHOA8fxeZ51ZOrN5+WNnOpGFL1fst7Jv2P7ijqYgSurLGMm1yFfLdl276oW15BPvc9qwdHFpiNlTxeZ1b2XisZ5RZjXKF/bAtq90KzKcHb4oDzxmewoe/VSUDVGnIA7BOyCZAYha9eLLAGmw93xC9tmbFEbq9E9xSfJDOtOvQ3YK8B5AxOqBpNxeBZAIGMVSJbwuRkxSwGetBpQcWtdNPOBUDlKSp3Xy0Lew8=" Dec 09 14:54:03 volumio volumio[15878]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 09 14:54:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:54:03 volumio volumio[15878]: info: Asound.conf file unchanged, so no further update is needed Dec 09 14:54:03 volumio volumio[15878]: info: Output device has changed, restarting MPD Dec 09 14:54:03 volumio sudo[16173]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 09 14:54:03 volumio sudo[16173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio sudo[16161]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio sudo[16173]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 14:54:03 volumio volumio[15878]: info: Output device has changed, restarting Shairport Sync Dec 09 14:54:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:03 volumio sudo[16176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 14:54:03 volumio sudo[16176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio sudo[16176]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:54:03 volumio sudo[16164]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio sudo[16186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 14:54:03 volumio sudo[16186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio sudo[16166]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio volumio[15878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 14:54:03 volumio go-librespot[16143]: time="2025-12-09T14:54:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:03 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 09 14:54:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 14:54:03 volumio systemd[1]: mpd.service: Consumed 1.813s CPU time. Dec 09 14:54:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 09 14:54:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 14:54:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 14:54:03 volumio go-librespot[16143]: time="2025-12-09T14:54:03-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:03 volumio go-librespot[16143]: time="2025-12-09T14:54:03-06:00" level=debug msg="completed challenge" Dec 09 14:54:03 volumio go-librespot[16143]: time="2025-12-09T14:54:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 14:54:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 14:54:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:03 volumio volumio[15878]: info: MPD Permissions set Dec 09 14:54:03 volumio volumio[15878]: info: Shairport-Sync Started Dec 09 14:54:03 volumio volumio[15878]: Error adding Membership: Error: addMembership EINVAL Dec 09 14:54:03 volumio volumio[15878]: info: Shairport-Sync Started Dec 09 14:54:03 volumio volumio[15878]: info: Shairport-Sync Started Dec 09 14:54:03 volumio volumio[15878]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:03 volumio sudo[16216]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 09 14:54:03 volumio sudo[16216]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio sudo[16216]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:03 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:03 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 09 14:54:03 volumio sudo[16213]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 14:54:03 volumio sudo[16213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 14:54:03 volumio volumio[15878]: info: Starting Shairport Sync Dec 09 14:54:03 volumio sudo[16213]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:03 volumio sudo[16224]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 09 14:54:03 volumio sudo[16224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio volumio[15878]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Dec 09 14:54:03 volumio sudo[16227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 14:54:03 volumio sudo[16227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:03 volumio volumio[15878]: info: Spotify Successfully logged in Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 09 14:54:03 volumio volumio[15878]: info: [1765313643802] CoreMusicLibrary::Adding element Spotify Dec 09 14:54:03 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source Bandcamp Discover Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source SoundCloud Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source YouTube2 Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source YouTube Music Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source Podcast Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source Volusonic Dec 09 14:54:03 volumio volumio[15878]: Cannot find translation for source Spotify Dec 09 14:54:03 volumio systemd[1]: Reloading. Dec 09 14:54:04 volumio volumio[15878]: info: [squeezelite_mc] Notification listener started Dec 09 14:54:04 volumio volumio[15878]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 14:54:04 volumio volumio[15878]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 14:54:04 volumio volumio[15878]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 14:54:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 14:54:04 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 14:54:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:54:05 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 09 14:54:05 volumio volumio[15878]: info: go-librespot daemon successfully initialized Dec 09 14:54:05 volumio sudo[16224]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:05 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 14:54:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 14:54:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:54:06 volumio systemd[1]: shairport-sync.service: Consumed 1.582s CPU time. Dec 09 14:54:06 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:06 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:06 volumio sudo[16249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:06 volumio sudo[16249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 14:54:06 volumio sudo[16227]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:06 volumio volumio[15878]: info: Shairport-Sync Started Dec 09 14:54:06 volumio sudo[16249]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:06 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 09 14:54:06 volumio sudo[16266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 09 14:54:06 volumio sudo[16266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:06 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 14:54:06 volumio volumio[15878]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'disconnect' Dec 09 14:54:06 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:06 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:06 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 09 14:54:06 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 14:54:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Dec 09 14:54:06 volumio sudo[16266]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:06 volumio go-librespot[16269]: go-librespot daemon starting... Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=debug msg="app state loaded" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:06 volumio go-librespot[16270]: time="2025-12-09T14:54:06-06:00" level=info msg="zeroconf server listening on port 46271" Dec 09 14:54:07 volumio go-librespot[16270]: time="2025-12-09T14:54:07-06:00" level=debug msg="obtained new client token: AAC7dC+pPSt5M6W8YjAN7l6yqDdpHPuGKDAWlPW1sDgEllZmwwteXWdnmLvO5a0TZh9KI77KDDvT/JfIL+OiTAtJbCa4oJOJquFHJcbYmqRL52OwaroP7ZrRVPA9TH380L7hNpvIredMBXN6uI8Qa9uoRfObIRgbMyb3dCc1sTLwgDgMpGpbNU/JDKy2PO/YfSxcnh8+3uTQWgTX04ST4KtcewZ1gVUKRGK+0FX+KmGKxJhdR4IV1MY=" Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:07 volumio sudo[16278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:07 volumio sudo[16278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:07 volumio go-librespot[16270]: time="2025-12-09T14:54:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:07 volumio go-librespot[16270]: time="2025-12-09T14:54:07-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:07 volumio go-librespot[16270]: time="2025-12-09T14:54:07-06:00" level=debug msg="completed challenge" Dec 09 14:54:07 volumio sudo[16278]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 09 14:54:07 volumio go-librespot[16270]: time="2025-12-09T14:54:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:07 volumio sudo[16282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 09 14:54:07 volumio sudo[16282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:07 volumio sudo[16282]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 09 14:54:07 volumio sudo[16285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 09 14:54:07 volumio sudo[16285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:07 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 09 14:54:07 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 09 14:54:07 volumio sudo[16285]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] 'client' notification received from BigBoss (192.168.1.180); type is 'connect' Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] Getting players connected to BigBoss (192.168.1.180) Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] Players connected to BigBoss (192.168.1.180): [{"id":"00:04:20:27:50:e8","uuid":"01ef6d9b3e5a11e37681969e3bc3ac56","ip":"192.168.1.148","name":"Squeezebox Radio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}},{"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}}] Dec 09 14:54:07 volumio volumio[15878]: info: [squeezelite_mc] Player found: {"id":"b8:27:eb:bb:d5:b0","uuid":null,"ip":"192.168.1.221","name":"volumio","server":{"ip":"192.168.1.180","name":"BigBoss","ver":"7.999.999","uuid":"d9ef138b-f3d6-4b57-9529-029da004b8f2","jsonPort":"9006","cliPort":"9090"}} Dec 09 14:54:07 volumio mpd[16228]: 2025-12-09T14:54:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 09 14:54:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 09 14:54:07 volumio sudo[16186]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:07 volumio sudo[16100]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:07 volumio sudo[16090]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:07 volumio volumio[15878]: error: MPD error: The expression evaluated to a falsy value: Dec 09 14:54:07 volumio volumio[15878]: assert.ok(self.idling) Dec 09 14:54:08 volumio volumio[15878]: error: The expression evaluated to a falsy value: Dec 09 14:54:08 volumio volumio[15878]: assert.ok(self.idling) Dec 09 14:54:08 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:08 volumio volumio[15878]: error: MPD error: The expression evaluated to a falsy value: Dec 09 14:54:08 volumio volumio[15878]: assert.ok(self.idling) Dec 09 14:54:08 volumio volumio[15878]: error: The expression evaluated to a falsy value: Dec 09 14:54:08 volumio volumio[15878]: assert.ok(self.idling) Dec 09 14:54:08 volumio volumio[15878]: error: updateQueue error: null Dec 09 14:54:08 volumio volumio[15878]: info: MPD running with PID16228 Dec 09 14:54:08 volumio volumio[15878]: ,establishing connection Dec 09 14:54:08 volumio volumio[15878]: error: updateQueue error: null Dec 09 14:54:08 volumio sudo[16299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:08 volumio sudo[16299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:08 volumio sudo[16299]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:08 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:08 volumio sudo[16302]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:08 volumio sudo[16302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:08 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:08 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:08 volumio sudo[16302]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:08 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:08 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:09 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:09 volumio sudo[16319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:09 volumio sudo[16319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:09 volumio sudo[16319]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:09 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:09 volumio sudo[16322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:09 volumio sudo[16322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:09 volumio sudo[16322]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:10 volumio volumio[15878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 09 14:54:10 volumio sudo[16325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 09 14:54:10 volumio sudo[16325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Dec 09 14:54:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:10 volumio go-librespot[16327]: go-librespot daemon starting... Dec 09 14:54:10 volumio sudo[16325]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=debug msg="app state loaded" Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:10 volumio volumio[15878]: info: Completed starting Core Plugins Dec 09 14:54:10 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:54:10 volumio volumio[15878]: info: ----- MyVolumio plugins startup ---- Dec 09 14:54:10 volumio volumio[15878]: info: ------------------------------------------- Dec 09 14:54:10 volumio volumio[15878]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=info msg="zeroconf server listening on port 34237" Dec 09 14:54:10 volumio sudo[16336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 14:54:10 volumio sudo[16336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=debug msg="obtained new client token: AADLmqmlAOjmx9U4uSij+FMp1bUjfzbf7XD70GpiW+FEAwewzLApbvGpdqWwwfWxqOc/OG1uUAzo7BgAmQi/K53Zmh++rGa+KHVd1pyKsczRbZIBge1tkAdrCTEDf5T4VRBOHgwUhu1YxKgN8wQv9C1n2ZPezuUPiB5ZP6Bb/V7cOtvH1imR5ZNqAjbldNa0RXVYFq9uJQInmmSSJfftDd4HyxoWU1+ZqQth2kKqFOOGJ6DltiztJ6FZiA==" Dec 09 14:54:10 volumio sudo[16338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 14:54:10 volumio sudo[16338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:10 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 14:54:10 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 14:54:10 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 14:54:10 volumio go-librespot[16328]: time="2025-12-09T14:54:10-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Dec 09 14:54:11 volumio go-librespot[16328]: time="2025-12-09T14:54:11-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp 104.154.127.247:443: connect: connection refused" Dec 09 14:54:11 volumio sudo[16343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 14:54:11 volumio sudo[16343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 14:54:11 volumio sudo[16338]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:11 volumio sudo[16336]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:11 volumio mpd_monitor.sh[16341]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 14:54:11 volumio volumio[15878]: info: Successfully started MPD Monitor Dec 09 14:54:11 volumio volumio[15878]: info: Successfully started MPD Monitor Dec 09 14:54:11 volumio go-librespot[16328]: time="2025-12-09T14:54:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:80" Dec 09 14:54:11 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 14:54:11 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 14:54:11 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 14:54:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 14:54:11 volumio sudo[16343]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:11 volumio mpd_monitor.sh[16349]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 14:54:11 volumio volumio[15878]: info: Successfully started MPD Monitor Dec 09 14:54:11 volumio go-librespot[16328]: time="2025-12-09T14:54:11-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:11 volumio go-librespot[16328]: time="2025-12-09T14:54:11-06:00" level=debug msg="completed challenge" Dec 09 14:54:11 volumio go-librespot[16328]: time="2025-12-09T14:54:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:11 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:11 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Dec 09 14:54:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:14 volumio go-librespot[16353]: go-librespot daemon starting... Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="app state loaded" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=info msg="zeroconf server listening on port 35283" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="obtained new client token: AACTHxKE5f7pzjW/Iyezc2hAQN61lNgfDNHIfgD9Vkrx6AkDhyKGmcemkcP2n3Cwmxc7nbZHFsMt8Y0wAiEsNDILOv4RIgO3w4dWgB4gWr3lY/DC8hsncj66JbrGuU3FkfHG4HZgvw3ym2ewasPHTuh1mC8Do5eRBoReiHoUe/OALLUXObSC47bo5qhcNsbhYt7mLQmoif5DqkSagJRYqT7/bHWl2PaHLOjKlTczmH3cD4ttxCww5r3OYA==" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=debug msg="completed challenge" Dec 09 14:54:14 volumio go-librespot[16354]: time="2025-12-09T14:54:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:15 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:15 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Dec 09 14:54:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:18 volumio go-librespot[16362]: go-librespot daemon starting... Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="app state loaded" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=info msg="zeroconf server listening on port 46783" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="obtained new client token: AAD97zAnQPoSNVWJA52g1xPVN3VdL1PxXnoAKap2QBku/d8xLAUPC8OOHZqGN4vAqCOBYREblTMT5nxJW8G2Nqkj3NWQrGAWqAMHPA4AuEYcss6/fTjafvTCOV2XgwYNDF89x0zgl6pS2bqE4NITkG7ftTzZ5TX2pJ9fYYiu4aBJ2f0Qz9J4I6kd/RVGerhr/vVmTge0liKaBsXVO6wB88XHRzZwtJxUzBX9px2k1sX9UYns49DlIScTRg==" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=debug msg="completed challenge" Dec 09 14:54:18 volumio go-librespot[16363]: time="2025-12-09T14:54:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:18 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:18 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin bluetooth to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin multiroom to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin metavolumio to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin cd_controller to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 09 14:54:18 volumio volumio[15878]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 09 14:54:19 volumio volumio[15878]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 09 14:54:19 volumio volumio[15878]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 09 14:54:19 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:19 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:19 volumio volumio[15878]: info: Starting MyVolumio Remote Streaming Endpoints Dec 09 14:54:19 volumio volumio[15878]: info: MyVolumio login type: Token Dec 09 14:54:19 volumio volumio[15878]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 09 14:54:19 volumio volumio[15878]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 09 14:54:20 volumio volumio[15878]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 09 14:54:20 volumio volumio[15878]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 09 14:54:20 volumio volumio[15878]: info: Streaming services startup Dec 09 14:54:20 volumio volumio[15878]: info: Starting Streaming Daemon Dec 09 14:54:20 volumio sudo[16385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 09 14:54:20 volumio sudo[16385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:20 volumio volumio[15878]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 09 14:54:20 volumio sudo[16385]: pam_unix(sudo:session): session closed for user root Dec 09 14:54:20 volumio volumio[15878]: error: Cannot start Volumio Streaming Daemon Dec 09 14:54:20 volumio volumio[15878]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 09 14:54:20 volumio volumio[15878]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 09 14:54:21 volumio volumio[15878]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 09 14:54:21 volumio volumio[15878]: info: MyVolumio token set successfully Dec 09 14:54:21 volumio volumio[15878]: info: MYVOLUMIO: Adding device Dec 09 14:54:21 volumio volumio[15878]: info: MYVOLUMIO: Evaluating Server Dec 09 14:54:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Dec 09 14:54:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:21 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:21 volumio go-librespot[16393]: go-librespot daemon starting... Dec 09 14:54:21 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:21 volumio go-librespot[16394]: time="2025-12-09T14:54:21-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:21 volumio go-librespot[16394]: time="2025-12-09T14:54:21-06:00" level=debug msg="app state loaded" Dec 09 14:54:21 volumio go-librespot[16394]: time="2025-12-09T14:54:21-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:21 volumio go-librespot[16394]: time="2025-12-09T14:54:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=info msg="zeroconf server listening on port 39531" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="obtained new client token: AAC1hc+SQr/g9yHcJr5IJ3d8JRcAVBLzSZGPASmDsg+PZsvE3W4N61xcm8/LakHgJGBFukFm2GEdcumz1YvehBGB6oazWnXQAv0SQ7JfODYGHRT9jCnxnssWk1w9jao/1zkzAG5I7cQwSJAYStU2mbSdelwOOATc7FewVvjcR+EQst0MbNj7yxI5jXwH/t21ymYC6G+DJhDHFzXkoahy+lpQ9ox26Ij4y6YzDJrxysweG1ZBxkKJkzs=" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=debug msg="completed challenge" Dec 09 14:54:22 volumio go-librespot[16394]: time="2025-12-09T14:54:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:24 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:24 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Dec 09 14:54:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:25 volumio go-librespot[16402]: go-librespot daemon starting... Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="app state loaded" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=info msg="zeroconf server listening on port 42933" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="obtained new client token: AAA3GZWFTDRgHt3hMV11keYJF4K+yK7aStdKlOfCtSSfUPIMbqZDOfKqJv/5Gwyx9W9Km8iczKwdZZf8j5TaEjFfhhQ4IYUvVYH7UHxDf3fHPkxyIKKd4qPGCcP91lnxrphF523U1x+ECgjhNLPC+sB4JyhAY4XRJzTJUISWVjxvm4o8RHNwJmvAiKoTm7A0hB1DIjCbpPi9XA60asvKsoczl1L2Qf3BPzXNo/PRU8wO6ePfCYJhGDtSZg==" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:25 volumio go-librespot[16403]: time="2025-12-09T14:54:25-06:00" level=debug msg="completed challenge" Dec 09 14:54:26 volumio go-librespot[16403]: time="2025-12-09T14:54:26-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:27 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:27 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Dec 09 14:54:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:29 volumio go-librespot[16424]: go-librespot daemon starting... Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="app state loaded" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=info msg="zeroconf server listening on port 35263" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="obtained new client token: AAB+RsQcMogOVhdGKEdpt3OHTeP7t4i9c5qJLDpHv9ao2qFTL5oGeAmvwOXBqY/CtnTP2T26Rdy7MaqUX3s/of/glTNwsd1iQ0nvkW3QpLR7gNbY3HZIFkVGjzUTwFcRtne1+vF9kysu4iMOlOoA13/ymf4BAYPrJOQUjxPb9bd2taKxryqwG/6wu7Z2+ar4izFmJugsHwXtf00bta5tDYneAt/6frG4xjZXIvxLFPoGHgtDTg9MjNoQAg==" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=debug msg="completed challenge" Dec 09 14:54:29 volumio go-librespot[16425]: time="2025-12-09T14:54:29-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:30 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:30 volumio volumio[15878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:31 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 09 14:54:31 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 14:54:31 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 09 14:54:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Dec 09 14:54:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:33 volumio go-librespot[16438]: go-librespot daemon starting... Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="app state loaded" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=info msg="zeroconf server listening on port 40169" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="obtained new client token: AADscS0KeZC3LfMHcran3usFWr/9/pm6nPYa04mhAFs75v+5gfN69Y7R4h/wgD1Q+piiiBQGlwC9AQdeHMg4GRIN4VjfGjQl+JsdwgESsOX032imf6i7SZ9leMy3DftNW4H9KvzXNKcZ33taiYqCSEWabDhrTujVAAheuN4Doxt1PFbcltaJ+POzPfHN02Eq96SKPgdPq3WPwzc0fEg0qRz31hkNjUXB+DGrVtzNGBUhM75FQqkS7A0x6A==" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="completed challenge" Dec 09 14:54:33 volumio volumio[15878]: info: Initializing connection to go-librespot Websocket Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=debug msg="new websocket client" Dec 09 14:54:33 volumio volumio[15878]: info: Connection to go-librespot Websocket established Dec 09 14:54:33 volumio go-librespot[16439]: time="2025-12-09T14:54:33-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 09 14:54:33 volumio volumio[15878]: info: Connection to go-librespot Websocket closed Dec 09 14:54:34 volumio volumio[15878]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 09 14:54:34 volumio volumio[15878]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 09 14:54:34 volumio volumio[15878]: info: CoreCommandRouter::volumioGetState Dec 09 14:54:34 volumio volumio[15878]: info: CorePlayQueue::getTrack 0 Dec 09 14:54:36 volumio volumio[15878]: info: Getting Spotify volume Dec 09 14:54:36 volumio volumio[15878]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 14:54:36 volumio volumio[15878]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 09 14:54:36 volumio volumio[15878]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 09 14:54:36 volumio volumio[15878]: errno: -111, Dec 09 14:54:36 volumio volumio[15878]: code: 'ECONNREFUSED', Dec 09 14:54:36 volumio volumio[15878]: syscall: 'connect', Dec 09 14:54:36 volumio volumio[15878]: address: '127.0.0.1', Dec 09 14:54:36 volumio volumio[15878]: port: 9879, Dec 09 14:54:36 volumio volumio[15878]: response: undefined Dec 09 14:54:36 volumio volumio[15878]: } Dec 09 14:54:36 volumio volumio[15878]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 14:54:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Dec 09 14:54:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 09 14:54:37 volumio go-librespot[16459]: go-librespot daemon starting... Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=info msg="running go-librespot 0.4.0" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="app state loaded" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="stored credentials not found" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=info msg="zeroconf server listening on port 37451" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="obtained new client token: AABMyK4g+Dty66TkaqCy8YVkFccGH8KWYaBpVIFyEkE4ssqeY6DG0DGV7urMIKus/BR0yZR4p7vFKWzBa3a5e8R8U027xmT2X7E/IKBWKJWc0ICT/RqFVGud9rqeZNSkFbwAni/9yYXNPz+3nHftCkJ2fdBTcq6rnEHWB0+PKKmjvFKk5UKoj0i/m6zpxUkmne+JVkoDufoe57aABKKlQ9fB1IeG7AMcJOyHho/e7iYzQwmLDWoYO2Oo0w==" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="completed keyexchange" Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=debug msg="completed challenge" Dec 09 14:54:37 volumio sudo[16469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 14:53' Dec 09 14:54:37 volumio sudo[16469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 14:54:37 volumio go-librespot[16460]: time="2025-12-09T14:54:37-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 09 14:54:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 09 14:54:37 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"