Feb 10 05:15:00 volumio volumio-remote-updater[751]: [2026-02-10 05:15:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 05:15:00 volumio volumio-remote-updater[751]: [2026-02-10 05:15:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 05:15:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 05:15:00 volumio systemd[1]: volumio.service: Consumed 48.685s CPU time. Feb 10 05:15:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 05:15:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 05:15:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3645. Feb 10 05:15:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 05:15:00 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 05:15:00 volumio systemd[1]: volumio.service: Consumed 48.685s CPU time. Feb 10 05:15:00 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 05:15:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 05:15:02 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:02 volumio volumio[24599]: info: ----- Volumio3 ---- Feb 10 05:15:02 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:02 volumio volumio[24599]: info: ----- System startup ---- Feb 10 05:15:02 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 05:15:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:02 volumio go-librespot[24620]: go-librespot daemon starting... Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-06:00" level=debug msg="app state loaded" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-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]" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-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]" Feb 10 05:15:02 volumio go-librespot[24621]: time="2026-02-10T05:15:02-06:00" level=info msg="zeroconf server listening on port 33923" Feb 10 05:15:03 volumio go-librespot[24621]: time="2026-02-10T05:15:03-06:00" level=debug msg="obtained new client token: AADjNSeZEROZOEj8mdXHXcL8G5JFknzk37A5Jsan/IEjivXE336D/cNv0rcEFUBORztfkWlOLBsItewIIuGtHir1xsc57I/0krw0atojkCCoaSXHnNhP7zJgiAdfyDfPDUZzpLftlvAIlnXoBmfPCO0U5r+hQ8NYbAsJgUOEwFejO2aCjxbumsblkX1YqbUPEXUHOIZstomEQFT2Ducl40JcfCOk/eX+uZ1HqG8CGgwkdhRu6T1q48M=" Feb 10 05:15:03 volumio volumio[24599]: info: MYVOLUMIO Environment detected Feb 10 05:15:03 volumio go-librespot[24621]: time="2026-02-10T05:15:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:03 volumio go-librespot[24621]: time="2026-02-10T05:15:03-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:03 volumio volumio[24599]: info: Plugin folders cleanup Feb 10 05:15:03 volumio go-librespot[24621]: time="2026-02-10T05:15:03-06:00" level=debug msg="completed challenge" Feb 10 05:15:03 volumio volumio[24599]: info: Scanning into folder /volumio/app/plugins/ Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category audio_interface Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category miscellanea Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category music_service Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category plugins.json Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category system_controller Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category user_interface Feb 10 05:15:03 volumio volumio[24599]: info: Scanning into folder /data/plugins/ Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category audio_interface Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category music_service Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category system_controller Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category system_hardware Feb 10 05:15:03 volumio volumio[24599]: info: Scanning category user_interface Feb 10 05:15:03 volumio volumio[24599]: info: Plugin folders cleanup completed Feb 10 05:15:03 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:03 volumio volumio[24599]: info: ----- Core plugins startup ---- Feb 10 05:15:03 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:03 volumio volumio[24599]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 05:15:03 volumio volumio[24599]: info: Adding plugin upnp to MyMusic Plugins Feb 10 05:15:03 volumio volumio[24599]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 05:15:03 volumio volumio[24599]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 05:15:03 volumio volumio[24599]: info: Loading plugins from folder /data/plugins/ Feb 10 05:15:03 volumio go-librespot[24621]: time="2026-02-10T05:15: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 " Feb 10 05:15:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:03 volumio volumio[24599]: info: Loading plugin "system"... Feb 10 05:15:03 volumio volumio[24599]: info: Loading plugin "appearance"... Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "network"... Feb 10 05:15:04 volumio volumio[24599]: info: Refreshing Cached IP Addresses Feb 10 05:15:04 volumio sudo[24635]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 05:15:04 volumio sudo[24635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:04 volumio sudo[24637]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 05:15:04 volumio sudo[24637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:04 volumio sudo[24635]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:04 volumio sudo[24637]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "services"... Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "alsa_controller"... Feb 10 05:15:04 volumio sudo[24645]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 05:15:04 volumio sudo[24645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:04 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "wizard"... Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "networkfs"... Feb 10 05:15:04 volumio volumio[24599]: info: Starting Udev Watcher for removable devices Feb 10 05:15:04 volumio volumio[24599]: info: Ignoring mount for partition: boot Feb 10 05:15:04 volumio volumio[24599]: info: Ignoring mount for partition: volumio Feb 10 05:15:04 volumio volumio[24599]: info: Ignoring mount for partition: volumio_data Feb 10 05:15:04 volumio volumio[24599]: info: Mounting Device Wikipedia Feb 10 05:15:04 volumio sudo[24674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 10 05:15:04 volumio sudo[24674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:04 volumio sudo[24674]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:04 volumio volumio[24599]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 05:15:04 volumio volumio[24599]: dmesg(1) may have more information after failed mount system call. Feb 10 05:15:04 volumio volumio[24599]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 10 05:15:04 volumio volumio[24599]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 05:15:04 volumio volumio[24599]: dmesg(1) may have more information after failed mount system call. Feb 10 05:15:04 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "volumio_command_line_client"... Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "upnp"... Feb 10 05:15:04 volumio volumio[24599]: info: [1770722104722] Starting Upmpd Daemon Feb 10 05:15:04 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "my_music"... Feb 10 05:15:04 volumio volumio[24599]: info: Loading plugin "mpd"... Feb 10 05:15:04 volumio sudo[24645]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:05 volumio volumio-remote-updater[751]: [2026-02-10 05:15:05] [connect] Successful connection Feb 10 05:15:05 volumio volumio[24599]: info: Loading plugin "upnp_browser"... Feb 10 05:15:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 05:15:06 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:15:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:06 volumio go-librespot[24676]: go-librespot daemon starting... Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-06:00" level=debug msg="app state loaded" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-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]" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-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]" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-06:00" level=info msg="zeroconf server listening on port 42889" Feb 10 05:15:06 volumio go-librespot[24678]: time="2026-02-10T05:15:06-06:00" level=debug msg="obtained new client token: AADx7e4rD4vNiV7HX1egJnhtwOL69oyzulRjWJdEOdlEGmauHljslQ7trs7CebE0jy3ftRleDYBggI4kOCoNSCH15PwM7NOqr937GfObANbqZ50WsIRJiAVALuLOetcBkG+aR4Lfea6W8FyT9iihFGObqOYwAWVqMB+K3+NpTNTKCzSK9ts0uzEKM5NPMwdO9hTvzTUX0POx0TNQyEnanI2nNJFZY9uAWuqjtn7F3FN4OEqM72dxeHIIZw==" Feb 10 05:15:07 volumio go-librespot[24678]: time="2026-02-10T05:15:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:07 volumio go-librespot[24678]: time="2026-02-10T05:15:07-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:07 volumio go-librespot[24678]: time="2026-02-10T05:15:07-06:00" level=debug msg="completed challenge" Feb 10 05:15:07 volumio go-librespot[24678]: time="2026-02-10T05:15: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 " Feb 10 05:15:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "alarm-clock"... Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "airplay_emulation"... Feb 10 05:15:08 volumio volumio[24599]: info: Starting Shairport Sync Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "last_100"... Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "webradio"... Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "i2s_dacs"... Feb 10 05:15:08 volumio volumio[24599]: info: I2S DAC not set, start Auto-detection Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "volumiodiscovery"... Feb 10 05:15:08 volumio volumio[24599]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:08 volumio volumio[24599]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:08 volumio volumio[24599]: *** WARNING *** For more information see Feb 10 05:15:08 volumio volumio[24599]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:08 volumio volumio[24599]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:08 volumio volumio[24599]: *** WARNING *** For more information see Feb 10 05:15:08 volumio node[24599]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:08 volumio node[24599]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:08 volumio node[24599]: *** WARNING *** For more information see Feb 10 05:15:08 volumio node[24599]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:08 volumio node[24599]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:08 volumio node[24599]: *** WARNING *** For more information see Feb 10 05:15:08 volumio volumio[24599]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 05:15:08 volumio volumio[24599]: info: Discovery: Started advertising with name: Volumio Feb 10 05:15:08 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:15:08 volumio volumio[24599]: info: Loading plugin "bandcamp"... Feb 10 05:15:09 volumio volumio[24599]: info: Plugin calmradio is not enabled Feb 10 05:15:09 volumio volumio[24599]: info: Loading plugin "soundcloud"... Feb 10 05:15:10 volumio volumio[24599]: info: Loading plugin "spop"... Feb 10 05:15:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 05:15:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:10 volumio go-librespot[24690]: go-librespot daemon starting... Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=debug msg="app state loaded" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:10 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15: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-gew4.spotify.com:80]" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-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]" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-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]" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=info msg="zeroconf server listening on port 41937" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=debug msg="obtained new client token: AADNwjshkWR4rCz0WspsScTw1zSBshzmToQF4kdOHA/45yvB8gCDleUc5tdQTA1kSSLFTlXhtpz1W1n4vdMo412FqAJkHdrlbk4jGznlZAScSKW4G+UPTukeCfCbuNFfMg5Gtaz7umT0OdVOiqGetHKC1aT1KJPodvreogmt4ZzzdtgIKmNCJ7pvPr06dbMu17i/ZfwOYmmKvMFCoGe3IlZvUUkVp4HJOHrHdaKsLFrZSgIDEhC8iR8Izg==" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15:10-06:00" level=debug msg="completed challenge" Feb 10 05:15:10 volumio go-librespot[24691]: time="2026-02-10T05:15: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 " Feb 10 05:15:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:11 volumio volumio[24599]: info: Loading plugin "squeezelite_mc"... Feb 10 05:15:11 volumio volumio[24599]: info: Loading plugin "youtube2"... Feb 10 05:15:12 volumio volumio[24599]: info: Loading plugin "ytcr"... Feb 10 05:15:13 volumio volumio[24599]: info: Loading plugin "ytmusic"... Feb 10 05:15:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 05:15:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:14 volumio go-librespot[24700]: go-librespot daemon starting... Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=debug msg="app state loaded" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:14 volumio volumio[24599]: info: Plugin now_playing is not enabled Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "outputs"... Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "albumart"... Feb 10 05:15:14 volumio volumio[24599]: info: Plugin example_plugin is not enabled Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "inputs"... Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "updater_comm"... Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15: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-gew1.spotify.com:80]" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-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]" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-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]" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=info msg="zeroconf server listening on port 46459" Feb 10 05:15:14 volumio volumio[24599]: info: Plugin mpdemulation is not enabled Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "rest_api"... Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "websocket"... Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=debug msg="obtained new client token: AABC3yoTkWDr5tSTQ9J3rTFzpd5EMPFSFgoGoagQSy119Hirz89SOf/vN0AGzUk1K0cljwzZ1ujueI0XPKXdw1TJB+OqHp1Yr+kiRmAJkM+YQG/ceyt2dL4Hh2U1FKd2bj4N0WibVhH7ATj3oHSoZ5XIcDoQAAtBgGgN4M8JCZQibh7TBI8txUMlT+Z995lBjRuHtfv9nhWjLrCUP46pHdzMWVA070RsWqAZ0Z8ufRKP4mDM8GUeVC37jQ==" Feb 10 05:15:14 volumio volumio[24599]: info: Starting Socket.io Server version 1.7.4 Feb 10 05:15:14 volumio volumio[24599]: info: Plugin fusiondsp is not enabled Feb 10 05:15:14 volumio volumio[24599]: info: Plugin mpdoutput is not enabled Feb 10 05:15:14 volumio volumio[24599]: info: Plugin RoonBridge is not enabled Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "podcast"... Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15:14-06:00" level=debug msg="completed challenge" Feb 10 05:15:14 volumio go-librespot[24701]: time="2026-02-10T05:15: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 " Feb 10 05:15:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:14 volumio volumio[24599]: info: ControllerPodcast::constructor Feb 10 05:15:14 volumio volumio[24599]: info: Loading plugin "volusonic"... Feb 10 05:15:14 volumio volumio[24708]: Forking 3 albumart workers Feb 10 05:15:16 volumio volumio[24599]: info: Applying required configuration parameters for plugin volusonic Feb 10 05:15:16 volumio volumio[24599]: info: Loading plugin "backup_restore"... Feb 10 05:15:16 volumio volumio[24734]: Starting albumart workers Feb 10 05:15:16 volumio volumio[24733]: Starting albumart workers Feb 10 05:15:16 volumio volumio[24732]: Starting albumart workers Feb 10 05:15:16 volumio volumio[24599]: info: Applying required configuration parameters for plugin backup_restore Feb 10 05:15:16 volumio volumio[24599]: info: Plugin rpi_eeprom_config is not enabled Feb 10 05:15:16 volumio volumio[24599]: info: Plugin rpi_eeprom_updater is not enabled Feb 10 05:15:16 volumio volumio[24599]: info: Loading plugin "scheduledrestart"... Feb 10 05:15:16 volumio volumio[24599]: info: Applying required configuration parameters for plugin scheduledrestart Feb 10 05:15:16 volumio volumio[24599]: info: Plugin Bluetoothremote is not enabled Feb 10 05:15:16 volumio volumio[24599]: info: Plugin music_services_shield is not enabled Feb 10 05:15:16 volumio volumio[24599]: info: Loading plugin "Systeminfo"... Feb 10 05:15:17 volumio volumio[24599]: info: Plugin peppymeterbasic is not enabled Feb 10 05:15:17 volumio volumio[24599]: info: Loading plugin "peppyspectrum"... Feb 10 05:15:17 volumio volumio-remote-updater[751]: [2026-02-10 05:15:17] [connect] Successful connection Feb 10 05:15:17 volumio volumio[24599]: info: Loading i18n strings for locale en Feb 10 05:15:17 volumio volumio[24599]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 05:15:17 volumio volumio[24599]: Updating browse sources language Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 05:15:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::initPlayerControls Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:17 volumio go-librespot[24780]: go-librespot daemon starting... Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:17 volumio volumio[24599]: Express server listening on port 3000 Feb 10 05:15:17 volumio volumio[24599]: [Metrics] WebUI: 16s 78.12ms Feb 10 05:15:17 volumio go-librespot[24781]: time="2026-02-10T05:15:17-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:17 volumio go-librespot[24781]: time="2026-02-10T05:15:17-06:00" level=debug msg="app state loaded" Feb 10 05:15:17 volumio go-librespot[24781]: time="2026-02-10T05:15:17-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:17 volumio go-librespot[24781]: time="2026-02-10T05:15:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:17 volumio volumio[24599]: info: CoreStateMachine::resetVolumioState Feb 10 05:15:17 volumio volumio[24599]: info: CoreStateMachine::getcurrentVolume Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:15:17 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:17 volumio sudo[24792]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 05:15:17 volumio sudo[24792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:17 volumio sudo[24792]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:17 volumio sudo[24794]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 05:15:17 volumio sudo[24794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:17 volumio sudo[24794]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:18 volumio volumio[24599]: info: Volumio Network Manager: Network status updated: 1 Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15: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-gew1.spotify.com:80]" Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-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]" Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-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]" Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-06:00" level=info msg="zeroconf server listening on port 43169" Feb 10 05:15:18 volumio volumio-remote-updater[751]: [2026-02-10 05:15:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770722117 101 Feb 10 05:15:18 volumio volumio[24599]: 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 Feb 10 05:15:18 volumio volumio[24599]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::pushState Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::updateTrackBlock Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrackBlock Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:15:18 volumio volumio[24599]: info: Reloading queue from file Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::setRepeat null single undefined Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::pushState Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::setRandom null Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::pushState Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:18 volumio volumio[24599]: info: Setting Device type: Raspberry PI Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-06:00" level=debug msg="obtained new client token: AABiD2eLH2ugapq+qC/dCj0ujaS+8XC1bzmTb3jCBIOGeg+ki4g1XzxUVloCe4V35A2ry5UPrpo8o8sR9AC+aS5Y2tgWh1e4rPwSuYT8n2A/fnOk5Bl6kVKZW/+Q6WTipaTEasIj6EWZDp1cC0OtMCovzloH1s3GdwDs1P0vVbfsRKrqErcpMKVI4HV+c80pxLsYTsGGKEbGv05ffPcTBS70Iqritz7RPHGz4/wy//vgEMXl8iKTaHc=" Feb 10 05:15:18 volumio volumio[24599]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:18 volumio volumio[24599]: info: CoreStateMachine::pushState Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:18 volumio sudo[24808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 05:15:18 volumio sudo[24808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:18 volumio volumio[24599]: info: Completed loading Core Plugins Feb 10 05:15:18 volumio volumio[24599]: info: Preparing to generate the ALSA configuration file Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15:18-06:00" level=debug msg="completed challenge" Feb 10 05:15:18 volumio volumio[24599]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 05:15:18 volumio volumio[24599]: info: Discovery: Found device Volumio Feb 10 05:15:18 volumio sudo[24808]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioGetState Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:18 volumio volumio[24599]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 05:15:18 volumio volumio[24599]: info: Discovery: Found device Volumio Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioGetState Feb 10 05:15:18 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:18 volumio volumio[24599]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 05:15:18 volumio volumio[24599]: info: Reading ALSA contributions from plugins. Feb 10 05:15:18 volumio volumio[24599]: info: Upmpdcli Daemon Started Feb 10 05:15:18 volumio volumio[24599]: info: Asound.conf file unchanged, so no further update is needed Feb 10 05:15:18 volumio volumio[24599]: info: Output device has changed, restarting MPD Feb 10 05:15:18 volumio go-librespot[24781]: time="2026-02-10T05:15: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 " Feb 10 05:15:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:18 volumio volumio[24599]: info: Output device has changed, restarting Shairport Sync Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:18 volumio sudo[24811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:15:18 volumio sudo[24813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:15:18 volumio sudo[24813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:18 volumio sudo[24811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:18 volumio sudo[24811]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:18 volumio volumio[24599]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:18 volumio volumio[24599]: info: ___________ START PLUGINS ___________ Feb 10 05:15:18 volumio volumio[24599]: info: ControllerMpd::onStart: Initializing MPD Feb 10 05:15:18 volumio volumio[24599]: info: Creating MPD Configuration file Feb 10 05:15:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:18 volumio volumio[24599]: info: [1770722118503] CoreMusicLibrary::Adding element Media Servers Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:18 volumio sudo[24823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:15:18 volumio sudo[24823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:18 volumio sudo[24821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:15:18 volumio sudo[24821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:18 volumio sudo[24821]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:18 volumio volumio[24599]: info: [1770722118613] CoreMusicLibrary::Adding element Last_100 Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:18 volumio volumio[24599]: info: [1770722118618] CoreMusicLibrary::Adding element Webradio Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:18 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 05:15:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 05:15:18 volumio systemd[1]: mpd.service: Consumed 4.116s CPU time. Feb 10 05:15:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 05:15:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 05:15:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:15:18 volumio volumio[24599]: info: Initializing BBC Radios Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:18 volumio volumio[24599]: info: [1770722118695] CoreMusicLibrary::Adding element Bandcamp Discover Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:18 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:18 volumio volumio[24599]: info: [1770722118705] CoreMusicLibrary::Adding element SoundCloud Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:18 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:18 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:18 volumio volumio[24599]: info: Creating Spotify config file Feb 10 05:15:18 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 05:15:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 05:15:18 volumio sudo[24848]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 05:15:18 volumio sudo[24848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 05:15:18 volumio sudo[24848]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Starting proxy server... Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:19 volumio volumio[24599]: info: [1770722119070] CoreMusicLibrary::Adding element YouTube2 Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:19 volumio volumio[24599]: info: [1770722119090] CoreMusicLibrary::Adding element YouTube Music Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube Music Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:19 volumio volumio[24599]: info: [1770722119102] CoreMusicLibrary::Adding element Podcast Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube Music Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Podcast Feb 10 05:15:19 volumio volumio[24599]: info: Loading i18n strings for locale en Feb 10 05:15:19 volumio volumio[24599]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 05:15:19 volumio volumio[24599]: Updating browse sources language Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube Music Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Podcast Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube Music Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Podcast Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:19 volumio volumio[24599]: info: [1770722119151] CoreMusicLibrary::Adding element Volusonic Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source YouTube Music Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Podcast Feb 10 05:15:19 volumio volumio[24599]: Cannot find translation for source Volusonic Feb 10 05:15:19 volumio volumio[24599]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 10 05:15:19 volumio volumio[24599]: info: Volumio Calling Home Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Proxy server started on port 39853 Feb 10 05:15:19 volumio volumio[24599]: info: Preparing to generate the ALSA configuration file Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:15:19 volumio volumio[24599]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 05:15:19 volumio volumio[24599]: info: Reading ALSA contributions from plugins. Feb 10 05:15:19 volumio volumio[24599]: info: MPD Permissions set Feb 10 05:15:19 volumio volumio[24599]: info: MPD Permissions set Feb 10 05:15:19 volumio volumio[24599]: info: Spotify config file written Feb 10 05:15:19 volumio sudo[24857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 05:15:19 volumio sudo[24857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:19 volumio volumio[24599]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 10 05:15:19 volumio volumio[24599]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:15:19 volumio volumio[24599]: info: CoreStateMachine::pushState Feb 10 05:15:19 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Server discovery started Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Player finder started Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 10 05:15:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:19 volumio go-librespot[24861]: go-librespot daemon starting... Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:19 volumio volumio[24599]: info: No need to fix Spotify hosts Feb 10 05:15:19 volumio sudo[24857]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15:19-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15:19-06:00" level=debug msg="app state loaded" Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15:19-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:19 volumio volumio[24599]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 10 05:15:19 volumio volumio[24599]: info: Volumio called home Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15: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]" Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15: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]" Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15: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]" Feb 10 05:15:19 volumio volumio[24599]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 10 05:15:19 volumio volumio[24599]: 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 Feb 10 05:15:19 volumio go-librespot[24872]: time="2026-02-10T05:15:19-06:00" level=info msg="zeroconf server listening on port 39133" Feb 10 05:15:19 volumio volumio[24599]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 05:15:19 volumio volumio[24599]: SPOTIFY: BQAGb0qZF79be90mFQCdtPDsiWCfUtUed9K5XPwSCY32rHzYawsqR9MqYAuBvRPcHxeX5bcmxRLdvFrjz9whJ2mXUqXBTPVozyelzwIXgqjFvzsDoYkWJNWi9_DBTxGY4XCt7BSd9Utjx10UwJAIMxfrmllowLVOa7kkiS7SOsM_0GV0hF0mVY534rM1l6d7sJgeznC2Sy_DX1Gx7YFiDlYmYnadX8CWbydSmSQ Feb 10 05:15:19 volumio volumio[24599]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 05:15:19 volumio volumio[24599]: info: New Spotify access token = BQAGb0qZF79be90mFQCdtPDsiWCfUtUed9K5XPwSCY32rHzYawsqR9MqYAuBvRPcHxeX5bcmxRLdvFrjz9whJ2mXUqXBTPVozyelzwIXgqjFvzsDoYkWJNWi9_DBTxGY4XCt7BSd9Utjx10UwJAIMxfrmllowLVOa7kkiS7SOsM_0GV0hF0mVY534rM1l6d7sJgeznC2Sy_DX1Gx7YFiDlYmYnadX8CWbydSmSQ Feb 10 05:15:19 volumio volumio[24599]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 05:15:20 volumio sudo[24881]: 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 Feb 10 05:15:20 volumio sudo[24881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio volumio[24599]: info: Starting Shairport Sync Feb 10 05:15:20 volumio volumio[24599]: info: Starting Shairport Sync Feb 10 05:15:20 volumio sudo[24881]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio volumio[24599]: info: Starting Shairport Sync Feb 10 05:15:20 volumio sudo[24885]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:20 volumio go-librespot[24872]: time="2026-02-10T05:15:20-06:00" level=debug msg="obtained new client token: AACeUJzCeVG/et6QajJVAIcThU3LsAqZosaGFfW184i5ApZmGDH2JiwTaOCRK30Zgy4+Xsw2BxAfqZMd4nh2UpUXv597tfoHZFbm9IaRXe7yyDwsfN9ICCsbOsDvpKn7ft3134M3vtRLwXY8N7PYWAa9+MrvuEx2gVh2EwvFG7IKtwrBqE6W3HIl1CEp6lFBsOh0yV/P40Su4iveE6TZkQlmjlJNUiHkgYWguzvmdjnYFw9dIrAzRNI=" Feb 10 05:15:20 volumio sudo[24885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio sudo[24887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:20 volumio sudo[24887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio sudo[24889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:20 volumio sudo[24889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio volumio[24599]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 10 05:15:20 volumio go-librespot[24872]: time="2026-02-10T05:15:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:15:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:15:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:20 volumio systemd[1]: shairport-sync.service: Consumed 2.043s CPU time. Feb 10 05:15:20 volumio volumio[24599]: info: Asound.conf file unchanged, so no further update is needed Feb 10 05:15:20 volumio volumio[24599]: info: Output device has changed, restarting MPD Feb 10 05:15:20 volumio volumio[24599]: info: Output device has changed, restarting Shairport Sync Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:20 volumio sudo[24895]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 10 05:15:20 volumio go-librespot[24872]: time="2026-02-10T05:15:20-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:20 volumio go-librespot[24872]: time="2026-02-10T05:15:20-06:00" level=debug msg="completed challenge" Feb 10 05:15:20 volumio sudo[24895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio sudo[24895]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio sudo[24897]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:15:20 volumio sudo[24897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio sudo[24900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:15:20 volumio volumio[24599]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:20 volumio sudo[24900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio go-librespot[24872]: time="2026-02-10T05:15:20-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 " Feb 10 05:15:20 volumio sudo[24897]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:20 volumio sudo[24885]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:20 volumio sudo[24887]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:15:20 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 05:15:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 05:15:20 volumio systemd[1]: mpd.service: Consumed 1.513s CPU time. Feb 10 05:15:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:15:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 05:15:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 05:15:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 05:15:20 volumio volumio[24599]: info: MPD Permissions set Feb 10 05:15:20 volumio volumio[24599]: info: Shairport-Sync Started Feb 10 05:15:20 volumio volumio[24599]: Error adding Membership: Error: addMembership EINVAL Feb 10 05:15:20 volumio volumio[24599]: info: Shairport-Sync Started Feb 10 05:15:20 volumio volumio[24599]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 05:15:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 05:15:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 05:15:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:20 volumio sudo[24929]: 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 Feb 10 05:15:20 volumio sudo[24929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio sudo[24889]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio sudo[24929]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:20 volumio volumio[24599]: info: CoreCommandRouter::volumioGetState Feb 10 05:15:20 volumio volumio[24599]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:20 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 10 05:15:20 volumio volumio[24599]: info: Shairport-Sync Started Feb 10 05:15:20 volumio volumio[24599]: info: Starting Shairport Sync Feb 10 05:15:20 volumio sudo[24952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 10 05:15:20 volumio sudo[24952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio sudo[24956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:20 volumio sudo[24956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:20 volumio systemd[1]: Reloading. Feb 10 05:15:20 volumio sudo[24930]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 05:15:20 volumio sudo[24930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 05:15:20 volumio sudo[24930]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:21 volumio volumio[24599]: 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"} Feb 10 05:15:21 volumio volumio[24599]: info: Spotify Successfully logged in Feb 10 05:15:21 volumio volumio[24599]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:21 volumio volumio[24599]: info: [1770722121056] CoreMusicLibrary::Adding element Spotify Feb 10 05:15:21 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source SoundCloud Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source YouTube2 Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source YouTube Music Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source Podcast Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source Volusonic Feb 10 05:15:21 volumio volumio[24599]: Cannot find translation for source Spotify Feb 10 05:15:21 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:21 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:21 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:21 volumio volumio[24599]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:22 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:15:22 volumio volumio[24599]: info: go-librespot daemon successfully initialized Feb 10 05:15:23 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. Feb 10 05:15:23 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. Feb 10 05:15:23 volumio sudo[24952]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:23 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:23 volumio sudo[24979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:23 volumio sudo[24979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 10 05:15:24 volumio sudo[24979]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:24 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 10 05:15:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:24 volumio sudo[24983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 10 05:15:24 volumio sudo[24983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:24 volumio go-librespot[24982]: go-librespot daemon starting... Feb 10 05:15:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:15:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:15:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:24 volumio systemd[1]: shairport-sync.service: Consumed 1.527s CPU time. Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=debug msg="app state loaded" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:24 volumio sudo[24956]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:24 volumio volumio[24599]: info: Shairport-Sync Started Feb 10 05:15:24 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 05:15:24 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 10 05:15:24 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 05:15:24 volumio sudo[24983]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-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]" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-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]" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-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]" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=info msg="zeroconf server listening on port 36203" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=debug msg="obtained new client token: AAAbTxwsST0VQovkBDwisHeJhjjGvXR1HAwNEciCWcbFjFZmZRhrtygfF2T0No9LjDHhH2W9VwFPOlohvuXUGitppkBkAjTrh6YOq/o3dMlceW6KHeWEOfP2YaprVmOQvAYt/ImPLPEzKhqIqm1dnQTjSO+j/0nOM74FbtsQQ0wOOkloeA7eTBHHpw3/w4WHAysSBaQge+TJATnrmfEA2Jn/OPT3n6uSHZ0NmQoyPoBNy5Pw3SSF8UXXHw==" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-06:00" level=debug msg="completed challenge" Feb 10 05:15:24 volumio go-librespot[24985]: time="2026-02-10T05:15:24-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 " Feb 10 05:15:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:25 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:25 volumio sudo[25022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:25 volumio sudo[25022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:25 volumio sudo[25022]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:25 volumio volumio[24599]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 10 05:15:25 volumio sudo[25026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 10 05:15:25 volumio sudo[25026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:25 volumio sudo[25026]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:25 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 10 05:15:25 volumio sudo[25029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 10 05:15:25 volumio sudo[25029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:25 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 05:15:25 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 05:15:25 volumio sudo[25029]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:25 volumio volumio[24599]: info: Initializing connection to go-librespot Websocket Feb 10 05:15:25 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:25 volumio volumio[24599]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:15:26 volumio sudo[25036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:26 volumio sudo[25036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:26 volumio sudo[25036]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:26 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:26 volumio sudo[25039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:26 volumio sudo[25039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:26 volumio sudo[25039]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:27 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:15:27 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:27 volumio sudo[25043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:27 volumio sudo[25043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:27 volumio mpd[24977]: 2026-02-10T05:15:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 05:15:27 volumio sudo[25043]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 05:15:27 volumio sudo[24823]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:27 volumio sudo[24900]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:27 volumio sudo[24813]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:27 volumio volumio[24599]: error: MPD error: The expression evaluated to a falsy value: Feb 10 05:15:27 volumio volumio[24599]: assert.ok(self.idling) Feb 10 05:15:27 volumio volumio[24599]: error: The expression evaluated to a falsy value: Feb 10 05:15:27 volumio volumio[24599]: assert.ok(self.idling) Feb 10 05:15:27 volumio volumio[24599]: error: MPD error: The expression evaluated to a falsy value: Feb 10 05:15:27 volumio volumio[24599]: assert.ok(self.idling) Feb 10 05:15:27 volumio volumio[24599]: error: The expression evaluated to a falsy value: Feb 10 05:15:27 volumio volumio[24599]: assert.ok(self.idling) Feb 10 05:15:27 volumio volumio[24599]: error: updateQueue error: null Feb 10 05:15:27 volumio volumio[24599]: info: MPD running with PID24977 Feb 10 05:15:27 volumio volumio[24599]: ,establishing connection Feb 10 05:15:27 volumio volumio[24599]: error: updateQueue error: null Feb 10 05:15:27 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:27 volumio sudo[25050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:27 volumio sudo[25050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:27 volumio sudo[25050]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 10 05:15:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:28 volumio go-librespot[25052]: go-librespot daemon starting... Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=debug msg="app state loaded" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-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]" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-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]" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-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]" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=info msg="zeroconf server listening on port 41525" Feb 10 05:15:28 volumio volumio[24599]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:15:28 volumio sudo[25061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:15:28 volumio sudo[25061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=debug msg="obtained new client token: AAB4sLfNDMLmkmCaSK2H9P3xoYJylWamN1N9wLx/W0UH0QhBAH74myxYS0gu2pPdUlPOj/kXPHYaWmIqxUkK7WC4sXXlN09A5X1Qd5TDZ6twsBGdpoE0XyJ4nzIBV/xRpHwe5AlwafyuJopSD4ISKOzXfLbTMMQmdWistHbLC4VQxYzkQEkCACPqJi/x/ocoWK9iNtktR5y5/sPe2qQBOkdqfq8E59MHmRq5kiBTGH3RLKJH/5E1se4aEQ==" Feb 10 05:15:28 volumio sudo[25061]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:28 volumio volumio[24599]: info: Completed starting Core Plugins Feb 10 05:15:28 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:28 volumio volumio[24599]: info: ----- MyVolumio plugins startup ---- Feb 10 05:15:28 volumio volumio[24599]: info: ------------------------------------------- Feb 10 05:15:28 volumio volumio[24599]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-06:00" level=debug msg="completed challenge" Feb 10 05:15:28 volumio go-librespot[25053]: time="2026-02-10T05:15:28-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 " Feb 10 05:15:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:28 volumio volumio[24599]: info: Initializing connection to go-librespot Websocket Feb 10 05:15:28 volumio volumio[24599]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:15:30 volumio sudo[25067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:15:30 volumio sudo[25067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:30 volumio sudo[25069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:15:30 volumio sudo[25069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:30 volumio sudo[25071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:15:30 volumio sudo[25071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:30 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 10 05:15:30 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 10 05:15:30 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 10 05:15:30 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 10 05:15:30 volumio sudo[25071]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:30 volumio sudo[25069]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:30 volumio sudo[25067]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:30 volumio mpd_monitor.sh[25075]: MPD Monitor Service: Starting MPD Monitor Service Feb 10 05:15:30 volumio volumio[24599]: info: Successfully started MPD Monitor Feb 10 05:15:30 volumio volumio[24599]: info: Successfully started MPD Monitor Feb 10 05:15:30 volumio volumio[24599]: info: Successfully started MPD Monitor Feb 10 05:15:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 10 05:15:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:31 volumio go-librespot[25081]: go-librespot daemon starting... Feb 10 05:15:31 volumio go-librespot[25082]: time="2026-02-10T05:15:31-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:31 volumio go-librespot[25082]: time="2026-02-10T05:15:31-06:00" level=debug msg="app state loaded" Feb 10 05:15:31 volumio go-librespot[25082]: time="2026-02-10T05:15:31-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:31 volumio go-librespot[25082]: time="2026-02-10T05:15:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:31 volumio volumio[24599]: info: Initializing connection to go-librespot Websocket Feb 10 05:15:31 volumio go-librespot[25082]: time="2026-02-10T05:15:31-06:00" level=debug msg="new websocket client" Feb 10 05:15:32 volumio volumio[24599]: info: Connection to go-librespot Websocket established Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-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]" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-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]" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-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]" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-06:00" level=info msg="zeroconf server listening on port 45703" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-06:00" level=debug msg="obtained new client token: AACL8qXV2ryxoQt76MQaoYCo6YtiLu95X0AKwQ2KjlvJ3dU5oRoKzB2BtCF3HT5kBzKBA2HUHma5KIz0g0b52q89tPxXhK+re6/z2dIwVEk6Cj4IJccAyZ0YNH7/slWf4FkcerGMuxZE/gvt3+P/0zpQGBLVe52gQ8NNgJWOZ1Z0TvIcTABYMI5P9RohJZHB6BIUtmaYQz6bNJ/gkFtaUmWBARmzd07wdvMIuSmGDYZbMkNEzdZAH44=" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-06:00" level=debug msg="completed challenge" Feb 10 05:15:32 volumio go-librespot[25082]: time="2026-02-10T05:15:32-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 " Feb 10 05:15:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:32 volumio volumio[24599]: info: Connection to go-librespot Websocket closed Feb 10 05:15:35 volumio volumio[24599]: info: Getting Spotify volume Feb 10 05:15:35 volumio volumio[24599]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 05:15:35 volumio volumio[24599]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:15:35 volumio volumio[24599]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 05:15:35 volumio volumio[24599]: errno: -111, Feb 10 05:15:35 volumio volumio[24599]: code: 'ECONNREFUSED', Feb 10 05:15:35 volumio volumio[24599]: syscall: 'connect', Feb 10 05:15:35 volumio volumio[24599]: address: '127.0.0.1', Feb 10 05:15:35 volumio volumio[24599]: port: 9879, Feb 10 05:15:35 volumio volumio[24599]: response: undefined Feb 10 05:15:35 volumio volumio[24599]: } Feb 10 05:15:35 volumio volumio[24599]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 05:15:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 10 05:15:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:35 volumio go-librespot[25115]: go-librespot daemon starting... Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=debug msg="app state loaded" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-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]" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-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]" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-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]" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=info msg="zeroconf server listening on port 45219" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=debug msg="obtained new client token: AAD0tr0/TccMQByJkLoKAsjeIiwJVDPpvjaSfIzI+gG6TGGTnurfW+I0o7NnjsOARQOSLXFYaSsN+FT/cSXc0JTzV6ruOcaW+pFTrNdOzBVjU2cWcFMUNA+7uUh4keTKOaiRQ+VpGtzVmp4FsrsMzWuqYKldoya9MVaq2zKjFsuYIScy5GniFzfpIh7DNgRChzRjFXQo1pQOZtJyp0IJuOCIHyl0fWg07Dn5EZxgDf5iyjzwQZj2wtzdUg==" Feb 10 05:15:35 volumio go-librespot[25116]: time="2026-02-10T05:15:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:36 volumio go-librespot[25116]: time="2026-02-10T05:15:36-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:36 volumio go-librespot[25116]: time="2026-02-10T05:15:36-06:00" level=debug msg="completed challenge" Feb 10 05:15:36 volumio go-librespot[25116]: time="2026-02-10T05:15:36-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 " Feb 10 05:15:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:36 volumio sudo[25125]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 05:14' Feb 10 05:15:36 volumio sudo[25125]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:36 volumio sudo[25125]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:36 volumio volumio-remote-updater[751]: [2026-02-10 05:15:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 05:15:36 volumio volumio-remote-updater[751]: [2026-02-10 05:15:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 05:15:36 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:36 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 05:15:36 volumio systemd[1]: volumio.service: Consumed 42.773s CPU time. Feb 10 05:15:36 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 05:15:36 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 05:15:36 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3646. Feb 10 05:15:36 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 05:15:36 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 05:15:36 volumio systemd[1]: volumio.service: Consumed 42.773s CPU time. Feb 10 05:15:36 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 05:15:36 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 05:15:38 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:15:38 volumio volumio[25137]: info: ----- Volumio3 ---- Feb 10 05:15:38 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:15:38 volumio volumio[25137]: info: ----- System startup ---- Feb 10 05:15:38 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:15:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 10 05:15:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:39 volumio go-librespot[25158]: go-librespot daemon starting... Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=debug msg="app state loaded" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:39 volumio volumio[25137]: info: MYVOLUMIO Environment detected Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-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]" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-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]" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-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]" Feb 10 05:15:39 volumio volumio[25137]: info: Plugin folders cleanup Feb 10 05:15:39 volumio volumio[25137]: info: Scanning into folder /volumio/app/plugins/ Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category audio_interface Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=info msg="zeroconf server listening on port 44415" Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category miscellanea Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category music_service Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category plugins.json Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category system_controller Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category user_interface Feb 10 05:15:39 volumio volumio[25137]: info: Scanning into folder /data/plugins/ Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category audio_interface Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category music_service Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category system_controller Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category system_hardware Feb 10 05:15:39 volumio volumio[25137]: info: Scanning category user_interface Feb 10 05:15:39 volumio volumio[25137]: info: Plugin folders cleanup completed Feb 10 05:15:39 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:15:39 volumio volumio[25137]: info: ----- Core plugins startup ---- Feb 10 05:15:39 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:15:39 volumio volumio[25137]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 05:15:39 volumio volumio[25137]: info: Adding plugin upnp to MyMusic Plugins Feb 10 05:15:39 volumio volumio[25137]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 05:15:39 volumio volumio[25137]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 05:15:39 volumio volumio[25137]: info: Loading plugins from folder /data/plugins/ Feb 10 05:15:39 volumio volumio[25137]: info: Loading plugin "system"... Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=debug msg="obtained new client token: AAAX3k4vYWJElIEzkl2fOE97oXHQsZSutf8eZfpKo4qRBByRWPFM0IDdiaP9ut+O0nQzbl684EW+3K2VB2XRe7bTIWunBU1MTlQ31dQnlGVnkddGFfeBAuKw0lQS+VFBAuw8fsPH5CkbmvCK5QclqUiGRQ4YD8m45msT+Ol7ucxInKa0hCik1LfhLN4rFO34G+8WXUmPwurhWVU0kFax7hjYSxX4RsUBjfaD5X9xXt9867EVzWruGAzs9Q==" Feb 10 05:15:39 volumio volumio[25137]: info: Loading plugin "appearance"... Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-06:00" level=debug msg="completed challenge" Feb 10 05:15:39 volumio go-librespot[25159]: time="2026-02-10T05:15:39-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 " Feb 10 05:15:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:40 volumio volumio[25137]: info: Loading plugin "network"... Feb 10 05:15:40 volumio volumio[25137]: info: Refreshing Cached IP Addresses Feb 10 05:15:40 volumio sudo[25174]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 05:15:40 volumio sudo[25174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:40 volumio sudo[25176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 05:15:40 volumio sudo[25176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:40 volumio sudo[25174]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:40 volumio sudo[25176]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:40 volumio volumio[25137]: info: Loading plugin "services"... Feb 10 05:15:40 volumio volumio[25137]: info: Loading plugin "alsa_controller"... Feb 10 05:15:40 volumio sudo[25187]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 05:15:40 volumio sudo[25187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:40 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:15:40 volumio volumio[25137]: info: Loading plugin "wizard"... Feb 10 05:15:40 volumio volumio[25137]: info: Loading plugin "networkfs"... Feb 10 05:15:40 volumio volumio[25137]: info: Starting Udev Watcher for removable devices Feb 10 05:15:41 volumio volumio[25137]: info: Ignoring mount for partition: boot Feb 10 05:15:41 volumio volumio[25137]: info: Ignoring mount for partition: volumio Feb 10 05:15:41 volumio volumio[25137]: info: Ignoring mount for partition: volumio_data Feb 10 05:15:41 volumio volumio[25137]: info: Mounting Device Wikipedia Feb 10 05:15:41 volumio sudo[25213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 10 05:15:41 volumio sudo[25213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:41 volumio sudo[25213]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:41 volumio volumio[25137]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 05:15:41 volumio volumio[25137]: dmesg(1) may have more information after failed mount system call. Feb 10 05:15:41 volumio volumio[25137]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 10 05:15:41 volumio volumio[25137]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 05:15:41 volumio volumio[25137]: dmesg(1) may have more information after failed mount system call. Feb 10 05:15:41 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:15:41 volumio volumio[25137]: info: Loading plugin "volumio_command_line_client"... Feb 10 05:15:41 volumio volumio[25137]: info: Loading plugin "upnp"... Feb 10 05:15:41 volumio volumio[25137]: info: [1770722141211] Starting Upmpd Daemon Feb 10 05:15:41 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:15:41 volumio volumio[25137]: info: Loading plugin "my_music"... Feb 10 05:15:41 volumio volumio[25137]: info: Loading plugin "mpd"... Feb 10 05:15:41 volumio sudo[25187]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:41 volumio volumio-remote-updater[751]: [2026-02-10 05:15:41] [connect] Successful connection Feb 10 05:15:41 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:15:41 volumio volumio[25137]: info: Loading plugin "upnp_browser"... Feb 10 05:15:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 10 05:15:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:43 volumio go-librespot[25216]: go-librespot daemon starting... Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=debug msg="app state loaded" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-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]" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-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]" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-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]" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=info msg="zeroconf server listening on port 34023" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=debug msg="obtained new client token: AADgtDnyXuVbujB4UvGU1LJR3xk2pCMwYv9OYiVjqXONMD0S8XVGwvGMaPlkwLq+xtTHaqqetk2g7Sk+IxysM+EIACT3xwxSIV9VrKKTRYKS9pYSrU0I6Ja0d5BFhDUu4T6Hl/iwnXgwiZVlnIEkOO4MnBkFRTvO08a3MQ78FHF+VQ4EUt+dyjPcHo7YSzfZnZNftSmejMBg38h/njS8j1J3iEJ+VDebTqJ8Vpix4tpHPklLMURmEeUH4A==" Feb 10 05:15:43 volumio go-librespot[25217]: time="2026-02-10T05:15:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "alarm-clock"... Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "airplay_emulation"... Feb 10 05:15:44 volumio volumio[25137]: info: Starting Shairport Sync Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "last_100"... Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "webradio"... Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "i2s_dacs"... Feb 10 05:15:44 volumio volumio[25137]: info: I2S DAC not set, start Auto-detection Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "volumiodiscovery"... Feb 10 05:15:44 volumio volumio[25137]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:44 volumio volumio[25137]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:44 volumio volumio[25137]: *** WARNING *** For more information see Feb 10 05:15:44 volumio volumio[25137]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:44 volumio volumio[25137]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:44 volumio volumio[25137]: *** WARNING *** For more information see Feb 10 05:15:44 volumio node[25137]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:44 volumio node[25137]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:44 volumio node[25137]: *** WARNING *** For more information see Feb 10 05:15:44 volumio node[25137]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 05:15:44 volumio node[25137]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:15:44 volumio node[25137]: *** WARNING *** For more information see Feb 10 05:15:44 volumio volumio[25137]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 05:15:44 volumio volumio[25137]: info: Discovery: Started advertising with name: Volumio Feb 10 05:15:44 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:15:44 volumio volumio[25137]: info: Loading plugin "bandcamp"... Feb 10 05:15:46 volumio volumio[25137]: info: Plugin calmradio is not enabled Feb 10 05:15:46 volumio volumio[25137]: info: Loading plugin "soundcloud"... Feb 10 05:15:46 volumio volumio[25137]: info: Loading plugin "spop"... Feb 10 05:15:47 volumio volumio[25137]: info: Loading plugin "squeezelite_mc"... Feb 10 05:15:47 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:15:48 volumio volumio[25137]: info: Loading plugin "youtube2"... Feb 10 05:15:48 volumio volumio[25137]: info: Loading plugin "ytcr"... Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "ytmusic"... Feb 10 05:15:50 volumio volumio[25137]: info: Plugin now_playing is not enabled Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "outputs"... Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "albumart"... Feb 10 05:15:50 volumio volumio[25137]: info: Plugin example_plugin is not enabled Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "inputs"... Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "updater_comm"... Feb 10 05:15:50 volumio volumio[25137]: info: Plugin mpdemulation is not enabled Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "rest_api"... Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "websocket"... Feb 10 05:15:50 volumio volumio[25137]: info: Starting Socket.io Server version 1.7.4 Feb 10 05:15:50 volumio volumio[25137]: info: Plugin fusiondsp is not enabled Feb 10 05:15:50 volumio volumio[25137]: info: Plugin mpdoutput is not enabled Feb 10 05:15:50 volumio volumio[25137]: info: Plugin RoonBridge is not enabled Feb 10 05:15:50 volumio volumio[25137]: info: Loading plugin "podcast"... Feb 10 05:15:51 volumio volumio[25137]: info: ControllerPodcast::constructor Feb 10 05:15:51 volumio volumio[25137]: info: Loading plugin "volusonic"... Feb 10 05:15:51 volumio volumio[25230]: Forking 3 albumart workers Feb 10 05:15:52 volumio volumio[25137]: info: Applying required configuration parameters for plugin volusonic Feb 10 05:15:52 volumio volumio[25254]: Starting albumart workers Feb 10 05:15:52 volumio volumio[25137]: info: Loading plugin "backup_restore"... Feb 10 05:15:52 volumio volumio[25256]: Starting albumart workers Feb 10 05:15:52 volumio volumio[25255]: Starting albumart workers Feb 10 05:15:53 volumio volumio[25137]: info: Applying required configuration parameters for plugin backup_restore Feb 10 05:15:53 volumio volumio[25137]: info: Plugin rpi_eeprom_config is not enabled Feb 10 05:15:53 volumio volumio[25137]: info: Plugin rpi_eeprom_updater is not enabled Feb 10 05:15:53 volumio volumio[25137]: info: Loading plugin "scheduledrestart"... Feb 10 05:15:53 volumio volumio[25137]: info: Applying required configuration parameters for plugin scheduledrestart Feb 10 05:15:53 volumio volumio[25137]: info: Plugin Bluetoothremote is not enabled Feb 10 05:15:53 volumio volumio[25137]: info: Plugin music_services_shield is not enabled Feb 10 05:15:53 volumio volumio[25137]: info: Loading plugin "Systeminfo"... Feb 10 05:15:53 volumio volumio[25137]: info: Plugin peppymeterbasic is not enabled Feb 10 05:15:53 volumio volumio[25137]: info: Loading plugin "peppyspectrum"... Feb 10 05:15:54 volumio volumio-remote-updater[751]: [2026-02-10 05:15:53] [connect] Successful connection Feb 10 05:15:54 volumio volumio[25137]: info: Loading i18n strings for locale en Feb 10 05:15:54 volumio volumio[25137]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 05:15:54 volumio volumio[25137]: Updating browse sources language Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::initPlayerControls Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: Express server listening on port 3000 Feb 10 05:15:54 volumio volumio[25137]: [Metrics] WebUI: 16s 27.02ms Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::resetVolumioState Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::getcurrentVolume Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:54 volumio sudo[25308]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 05:15:54 volumio sudo[25308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio sudo[25308]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:54 volumio sudo[25310]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 05:15:54 volumio sudo[25310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio sudo[25310]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:54 volumio volumio[25137]: info: Volumio Network Manager: Network status updated: 1 Feb 10 05:15:54 volumio volumio[25137]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::pushState Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::updateTrackBlock Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrackBlock Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:15:54 volumio volumio-remote-updater[751]: [2026-02-10 05:15:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770722153 101 Feb 10 05:15:54 volumio volumio[25137]: 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 Feb 10 05:15:54 volumio volumio[25137]: info: Reloading queue from file Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::setRepeat null single undefined Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::pushState Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::setRandom null Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::pushState Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:54 volumio volumio[25137]: info: Setting Device type: Raspberry PI Feb 10 05:15:54 volumio volumio[25137]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:15:54 volumio volumio[25137]: info: CoreStateMachine::pushState Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:54 volumio volumio[25137]: info: Completed loading Core Plugins Feb 10 05:15:54 volumio volumio[25137]: info: Preparing to generate the ALSA configuration file Feb 10 05:15:54 volumio sudo[25323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 05:15:54 volumio sudo[25323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio volumio[25137]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 05:15:54 volumio volumio[25137]: info: Discovery: Found device Volumio Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioGetState Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:54 volumio volumio[25137]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 05:15:54 volumio volumio[25137]: info: Reading ALSA contributions from plugins. Feb 10 05:15:54 volumio sudo[25323]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:54 volumio volumio[25137]: info: Upmpdcli Daemon Started Feb 10 05:15:54 volumio volumio[25137]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 05:15:54 volumio volumio[25137]: info: Discovery: Found device Volumio Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioGetState Feb 10 05:15:54 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:54 volumio volumio[25137]: info: Asound.conf file unchanged, so no further update is needed Feb 10 05:15:54 volumio volumio[25137]: info: Output device has changed, restarting MPD Feb 10 05:15:54 volumio volumio[25137]: info: Output device has changed, restarting Shairport Sync Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:54 volumio sudo[25326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:15:54 volumio sudo[25326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio sudo[25326]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:54 volumio sudo[25328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:15:54 volumio sudo[25328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio volumio[25137]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:54 volumio volumio[25137]: info: ___________ START PLUGINS ___________ Feb 10 05:15:54 volumio volumio[25137]: info: ControllerMpd::onStart: Initializing MPD Feb 10 05:15:54 volumio volumio[25137]: info: Creating MPD Configuration file Feb 10 05:15:54 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:54 volumio sudo[25336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:15:54 volumio sudo[25336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio volumio[25137]: info: [1770722154917] CoreMusicLibrary::Adding element Media Servers Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:54 volumio sudo[25338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:15:54 volumio sudo[25338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:54 volumio sudo[25336]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:54 volumio volumio[25137]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:55 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 05:15:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 05:15:55 volumio systemd[1]: mpd.service: Consumed 4.227s CPU time. Feb 10 05:15:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 05:15:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 05:15:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 05:15:55 volumio volumio[25137]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155033] CoreMusicLibrary::Adding element Last_100 Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155039] CoreMusicLibrary::Adding element Webradio Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:15:55 volumio volumio[25137]: info: Initializing BBC Radios Feb 10 05:15:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 05:15:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155125] CoreMusicLibrary::Adding element Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155137] CoreMusicLibrary::Adding element SoundCloud Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: info: Creating Spotify config file Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:55 volumio sudo[25359]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 05:15:55 volumio sudo[25359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 05:15:55 volumio sudo[25359]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:55 volumio volumio[25137]: info: [squeezelite_mc] Starting proxy server... Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155495] CoreMusicLibrary::Adding element YouTube2 Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155514] CoreMusicLibrary::Adding element YouTube Music Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube Music Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155526] CoreMusicLibrary::Adding element Podcast Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube Music Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Podcast Feb 10 05:15:55 volumio volumio[25137]: info: Loading i18n strings for locale en Feb 10 05:15:55 volumio volumio[25137]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 05:15:55 volumio volumio[25137]: Updating browse sources language Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube Music Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Podcast Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube Music Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Podcast Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:55 volumio volumio[25137]: info: [1770722155574] CoreMusicLibrary::Adding element Volusonic Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source YouTube Music Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Podcast Feb 10 05:15:55 volumio volumio[25137]: Cannot find translation for source Volusonic Feb 10 05:15:55 volumio volumio[25137]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 10 05:15:55 volumio volumio[25137]: info: Volumio Calling Home Feb 10 05:15:55 volumio volumio[25137]: info: [squeezelite_mc] Proxy server started on port 39399 Feb 10 05:15:55 volumio volumio[25137]: info: Preparing to generate the ALSA configuration file Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:15:55 volumio volumio[25137]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 05:15:55 volumio volumio[25137]: info: Reading ALSA contributions from plugins. Feb 10 05:15:55 volumio volumio[25137]: info: MPD Permissions set Feb 10 05:15:55 volumio volumio[25137]: info: MPD Permissions set Feb 10 05:15:55 volumio volumio[25137]: info: Spotify config file written Feb 10 05:15:55 volumio sudo[25373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 05:15:55 volumio sudo[25373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:55 volumio volumio[25137]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 10 05:15:55 volumio volumio[25137]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:15:55 volumio volumio[25137]: info: CoreStateMachine::pushState Feb 10 05:15:55 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::volumioPushState Feb 10 05:15:55 volumio volumio[25137]: info: [squeezelite_mc] Server discovery started Feb 10 05:15:55 volumio volumio[25137]: info: [squeezelite_mc] Player finder started Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:55 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 05:15:56 volumio systemd[1]: go-librespot-daemon.service: Killing process 25222 (go-librespot) with signal SIGKILL. Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: No need to fix Spotify hosts Feb 10 05:15:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:15:56 volumio go-librespot[25379]: go-librespot daemon starting... Feb 10 05:15:56 volumio sudo[25373]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=debug msg="app state loaded" Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=debug msg="stored credentials not found" Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:15:56 volumio volumio[25137]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 10 05:15:56 volumio volumio[25137]: info: Volumio called home Feb 10 05:15:56 volumio volumio[25137]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 10 05:15:56 volumio volumio[25137]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 10 05:15:56 volumio volumio[25137]: 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 Feb 10 05:15:56 volumio volumio[25137]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 05:15:56 volumio volumio[25137]: SPOTIFY: BQDQp3RLEjRNx4bkJrMr9SJ-MSJ6EQiFbyp5ratmQmrWgixhd2TdIwAO4yAk2mjymBjNQO_D0x5UX4RD7vEk_kYEuf6-RIQWxzomVa61QhNJ4qy1I2uhtwFALFP1xs6i2VcvdmBSLesBZ4IIypdZ8e-5Rpije_wL9Q2r-WFRD3_tGj8Tqi0pflaBWUpe1cG0c8nTSTbvAxx5E7s3EeUEE2uS0h-vsVxIumQJGsU Feb 10 05:15:56 volumio volumio[25137]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 05:15:56 volumio volumio[25137]: info: New Spotify access token = BQDQp3RLEjRNx4bkJrMr9SJ-MSJ6EQiFbyp5ratmQmrWgixhd2TdIwAO4yAk2mjymBjNQO_D0x5UX4RD7vEk_kYEuf6-RIQWxzomVa61QhNJ4qy1I2uhtwFALFP1xs6i2VcvdmBSLesBZ4IIypdZ8e-5Rpije_wL9Q2r-WFRD3_tGj8Tqi0pflaBWUpe1cG0c8nTSTbvAxx5E7s3EeUEE2uS0h-vsVxIumQJGsU Feb 10 05:15:56 volumio volumio[25137]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 05:15:56 volumio sudo[25398]: 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 Feb 10 05:15:56 volumio sudo[25398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-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]" Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-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]" Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-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]" Feb 10 05:15:56 volumio volumio[25137]: info: Starting Shairport Sync Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=info msg="zeroconf server listening on port 36291" Feb 10 05:15:56 volumio volumio[25137]: info: Starting Shairport Sync Feb 10 05:15:56 volumio sudo[25398]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio volumio[25137]: info: Starting Shairport Sync Feb 10 05:15:56 volumio sudo[25401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:56 volumio sudo[25401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio sudo[25403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:56 volumio sudo[25403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio sudo[25405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:56 volumio sudo[25405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio volumio[25137]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=debug msg="obtained new client token: AACfngcca32nxmo2M4lP1mSSpRHmm4bOtiZXMRChk7Hyt6ptSZFReUTjN48wGw6eEQqX4hMIe8NwCadPFgJJoDOVcAw8wOpN5qm6gTVL+1RQ49YwjSNER6m8fVfeqEqd3MIp+vPbOwz98wjjTSb+6Q9rQP2pg7SZ4uhDVLtOitVEmID0Vjl2QGz9o7HjQbNJwh4/VZIMwLKz7vq3xjWUeM+P6TkPSWoP/pXwBDKQ3bQjrTteRVOSBkasbg==" Feb 10 05:15:56 volumio volumio[25137]: info: Asound.conf file unchanged, so no further update is needed Feb 10 05:15:56 volumio volumio[25137]: info: Output device has changed, restarting MPD Feb 10 05:15:56 volumio volumio[25137]: info: Output device has changed, restarting Shairport Sync Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:56 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:15:56 volumio sudo[25415]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:15:56 volumio sudo[25415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:15:56 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:15:56 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:56 volumio systemd[1]: shairport-sync.service: Consumed 1.912s CPU time. Feb 10 05:15:56 volumio sudo[25412]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 10 05:15:56 volumio sudo[25412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio sudo[25413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:15:56 volumio sudo[25413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:56 volumio sudo[25412]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio volumio[25137]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:15:56 volumio sudo[25413]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=debug msg="completed keyexchange" Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-06:00" level=debug msg="completed challenge" Feb 10 05:15:56 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:15:56 volumio sudo[25403]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio sudo[25405]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio sudo[25401]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:56 volumio go-librespot[25388]: time="2026-02-10T05:15:56-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 " Feb 10 05:15:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:15:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:15:56 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 05:15:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 05:15:56 volumio systemd[1]: mpd.service: Consumed 1.607s CPU time. Feb 10 05:15:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 05:15:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 05:15:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 05:15:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 05:15:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 05:15:56 volumio volumio[25137]: info: MPD Permissions set Feb 10 05:15:56 volumio volumio[25137]: info: Shairport-Sync Started Feb 10 05:15:56 volumio volumio[25137]: Error adding Membership: Error: addMembership EINVAL Feb 10 05:15:56 volumio volumio[25137]: info: Shairport-Sync Started Feb 10 05:15:56 volumio volumio[25137]: info: Shairport-Sync Started Feb 10 05:15:56 volumio volumio[25137]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 05:15:57 volumio sudo[25446]: 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 Feb 10 05:15:57 volumio sudo[25446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:57 volumio sudo[25446]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:57 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::volumioGetState Feb 10 05:15:57 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:15:57 volumio volumio[25137]: info: Starting Shairport Sync Feb 10 05:15:57 volumio sudo[25454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 10 05:15:57 volumio sudo[25454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:57 volumio sudo[25443]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 05:15:57 volumio sudo[25443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 05:15:57 volumio sudo[25443]: pam_unix(sudo:session): session closed for user root Feb 10 05:15:57 volumio sudo[25457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:15:57 volumio sudo[25457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:15:57 volumio volumio[25137]: 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"} Feb 10 05:15:57 volumio volumio[25137]: info: Spotify Successfully logged in Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:15:57 volumio volumio[25137]: info: [1770722157283] CoreMusicLibrary::Adding element Spotify Feb 10 05:15:57 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source Bandcamp Discover Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source SoundCloud Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source YouTube2 Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source YouTube Music Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source Podcast Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source Volusonic Feb 10 05:15:57 volumio volumio[25137]: Cannot find translation for source Spotify Feb 10 05:15:57 volumio systemd[1]: Reloading. Feb 10 05:15:58 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:58 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:58 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:15:58 volumio volumio[25137]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:15:58 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:15:59 volumio volumio[25137]: info: go-librespot daemon successfully initialized Feb 10 05:16:00 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. Feb 10 05:16:00 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. Feb 10 05:16:00 volumio sudo[25454]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 05:16:00 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:00 volumio sudo[25480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:00 volumio sudo[25480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:00 volumio go-librespot[25481]: go-librespot daemon starting... Feb 10 05:16:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:16:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:16:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:16:00 volumio systemd[1]: shairport-sync.service: Consumed 1.546s CPU time. Feb 10 05:16:00 volumio go-librespot[25483]: time="2026-02-10T05:16:00-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:00 volumio go-librespot[25483]: time="2026-02-10T05:16:00-06:00" level=debug msg="app state loaded" Feb 10 05:16:00 volumio go-librespot[25483]: time="2026-02-10T05:16:00-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:00 volumio go-librespot[25483]: time="2026-02-10T05:16:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:16:00 volumio sudo[25457]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:00 volumio volumio[25137]: info: Shairport-Sync Started Feb 10 05:16:00 volumio sudo[25480]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:01 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 10 05:16:01 volumio sudo[25517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 10 05:16:01 volumio sudo[25517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:01 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16: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-gew4.spotify.com:80]" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-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]" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-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]" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-06:00" level=info msg="zeroconf server listening on port 34059" Feb 10 05:16:01 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 10 05:16:01 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 05:16:01 volumio sudo[25517]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-06:00" level=debug msg="obtained new client token: AAB5g1qQ2LCXIJPVWERjfv1REGjVqkp8AdptU/cCIS55uSAjYH98RKElNwYIZ2SQhig/i6Gi3WtmN5G+/VRMOXeVOUsfpa26Oe6qIMlz6SgCkWftOnqeOfQ9wBa67dAApo5Km2Yw/irdg8VoTmLwYpkFYHbjUjSmqp7L4fc2kVqBuASBxLYcIjwBTCu8ed2+MY9qgMOOhjcSgQJkPl1sH51Xo8kSgcfq2W03OKGlp/WA6h1keNA9xDC7Kg==" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16:01-06:00" level=debug msg="completed challenge" Feb 10 05:16:01 volumio go-librespot[25483]: time="2026-02-10T05:16: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 " Feb 10 05:16:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:01 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:01 volumio sudo[25525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:01 volumio sudo[25525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:01 volumio sudo[25525]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:01 volumio volumio[25137]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 10 05:16:02 volumio sudo[25529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 10 05:16:02 volumio sudo[25529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:02 volumio sudo[25529]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:02 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 10 05:16:02 volumio sudo[25532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 10 05:16:02 volumio sudo[25532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:02 volumio mpd[25459]: 2026-02-10T05:16:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 05:16:02 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 05:16:02 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 05:16:02 volumio sudo[25532]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 05:16:02 volumio sudo[25415]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:02 volumio sudo[25328]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:02 volumio volumio[25137]: info: Initializing connection to go-librespot Websocket Feb 10 05:16:02 volumio sudo[25338]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:02 volumio volumio[25137]: error: MPD error: The expression evaluated to a falsy value: Feb 10 05:16:02 volumio volumio[25137]: assert.ok(self.idling) Feb 10 05:16:02 volumio volumio[25137]: error: The expression evaluated to a falsy value: Feb 10 05:16:02 volumio volumio[25137]: assert.ok(self.idling) Feb 10 05:16:02 volumio volumio[25137]: error: MPD error: The expression evaluated to a falsy value: Feb 10 05:16:02 volumio volumio[25137]: assert.ok(self.idling) Feb 10 05:16:02 volumio volumio[25137]: error: The expression evaluated to a falsy value: Feb 10 05:16:02 volumio volumio[25137]: assert.ok(self.idling) Feb 10 05:16:02 volumio volumio[25137]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:16:02 volumio volumio[25137]: error: updateQueue error: null Feb 10 05:16:02 volumio volumio[25137]: info: MPD running with PID25459 Feb 10 05:16:02 volumio volumio[25137]: ,establishing connection Feb 10 05:16:02 volumio volumio[25137]: error: updateQueue error: null Feb 10 05:16:02 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:02 volumio sudo[25543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:02 volumio sudo[25543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:02 volumio sudo[25543]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:03 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:03 volumio sudo[25546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:03 volumio sudo[25546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:03 volumio sudo[25546]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:03 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:03 volumio sudo[25549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:03 volumio sudo[25549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:04 volumio sudo[25549]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:04 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:04 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:16:04 volumio sudo[25553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:04 volumio sudo[25553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 05:16:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:04 volumio go-librespot[25555]: go-librespot daemon starting... Feb 10 05:16:04 volumio sudo[25553]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-06:00" level=debug msg="app state loaded" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-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]" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-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]" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-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]" Feb 10 05:16:04 volumio go-librespot[25556]: time="2026-02-10T05:16:04-06:00" level=info msg="zeroconf server listening on port 43533" Feb 10 05:16:05 volumio go-librespot[25556]: time="2026-02-10T05:16:05-06:00" level=debug msg="obtained new client token: AAA6c1oDySauV3saNOaukPq3zAK4Xu5uMEiZD0dhSjV42GipTmEF+O8IKzhUnq0NouDmnUgEAly8cNdl91PgiA49p9mhyIjOlt8ZNWskJ9bUQ3XRhkmhHhhfV33bOhvjtDnWyyFO+Klog2b4N7/mpDX78l6eA2PuVfy4b2VgPqcJzaWJi67QpbnLTt8WMPDy2yB32z7AxaiAoJGCcXml2jStbKvgIA0mpjk+9ZmUM4EcIhhsN1yjrUk=" Feb 10 05:16:05 volumio go-librespot[25556]: time="2026-02-10T05:16:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:05 volumio go-librespot[25556]: time="2026-02-10T05:16:05-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:05 volumio go-librespot[25556]: time="2026-02-10T05:16:05-06:00" level=debug msg="completed challenge" Feb 10 05:16:05 volumio go-librespot[25556]: time="2026-02-10T05:16:05-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 " Feb 10 05:16:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:05 volumio volumio[25137]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:05 volumio sudo[25564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:05 volumio sudo[25564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:05 volumio sudo[25564]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:05 volumio volumio[25137]: info: Completed starting Core Plugins Feb 10 05:16:05 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:16:05 volumio volumio[25137]: info: ----- MyVolumio plugins startup ---- Feb 10 05:16:05 volumio volumio[25137]: info: ------------------------------------------- Feb 10 05:16:05 volumio volumio[25137]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 05:16:05 volumio sudo[25567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:16:05 volumio sudo[25567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:05 volumio sudo[25570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:16:05 volumio sudo[25570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:05 volumio sudo[25572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:16:05 volumio sudo[25572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:05 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 10 05:16:05 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 10 05:16:05 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 10 05:16:05 volumio volumio[25137]: info: Initializing connection to go-librespot Websocket Feb 10 05:16:05 volumio volumio[25137]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:16:05 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 10 05:16:05 volumio mpd_monitor.sh[25575]: MPD Monitor Service: Starting MPD Monitor Service Feb 10 05:16:05 volumio sudo[25572]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:05 volumio sudo[25570]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:05 volumio sudo[25567]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:05 volumio volumio[25137]: info: Successfully started MPD Monitor Feb 10 05:16:05 volumio volumio[25137]: info: Successfully started MPD Monitor Feb 10 05:16:05 volumio volumio[25137]: info: Successfully started MPD Monitor Feb 10 05:16:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 05:16:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:08 volumio go-librespot[25581]: go-librespot daemon starting... Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-06:00" level=debug msg="app state loaded" Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:08 volumio volumio[25137]: info: Initializing connection to go-librespot Websocket Feb 10 05:16:08 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-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]" Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-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]" Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-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]" Feb 10 05:16:08 volumio go-librespot[25582]: time="2026-02-10T05:16:08-06:00" level=info msg="zeroconf server listening on port 41755" Feb 10 05:16:09 volumio go-librespot[25582]: time="2026-02-10T05:16:09-06:00" level=debug msg="obtained new client token: AADn4/j54UTDAMk0L53KwiDq4os9Bnet1mYkRwDQbduhoaZ2fMSgerFPNUuwZ5rYX7IgEfXsZG94mYSTGQFUlytOBHugyUIJVp0uZqZfy25jyhxEcuAMmmD79h8jEHAF44vtuwzpPuqD1Z27E5Ve73+/5gXEC9v05aMfHRBISmYR9r+ygxDxidgqF/XkmQDSQK76FHijvfmawRnpxfgR2krCXW4kkB0/YhXmgctilDfRZCK+3Av/tVArbQ==" Feb 10 05:16:09 volumio go-librespot[25582]: time="2026-02-10T05:16:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:09 volumio go-librespot[25582]: time="2026-02-10T05:16:09-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:09 volumio go-librespot[25582]: time="2026-02-10T05:16:09-06:00" level=debug msg="completed challenge" Feb 10 05:16:09 volumio go-librespot[25582]: time="2026-02-10T05:16:09-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 " Feb 10 05:16:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:09 volumio volumio[25137]: info: Connection to go-librespot Websocket established Feb 10 05:16:09 volumio volumio[25137]: info: Connection to go-librespot Websocket closed Feb 10 05:16:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 05:16:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:12 volumio go-librespot[25605]: go-librespot daemon starting... Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="app state loaded" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-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]" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-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]" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-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]" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=info msg="zeroconf server listening on port 42223" Feb 10 05:16:12 volumio volumio[25137]: info: Getting Spotify volume Feb 10 05:16:12 volumio volumio[25137]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="obtained new client token: AAC/6rDZE0jLQsGbCKN0vltA5XqccRjvs9vAJgC59aPs9MPK99B3KCI8aR6GMycBttByqzz12VXhEUzoVP4Pi421cx8vTL6xg7nWoUTtsDAyWGQJCXeBf884Lw6dueqfFA+Ymv5P4c5y448LlyNGUmE+n3g2mBcfwJgZN3Mg99XdFFHdw4Mk+uxp3mwuhTutfpHXk0cAaZPgOEneKpuSZuy5FQf/IVg4qIBnua2ZtaZjvG0ARRLw1YDzPw==" Feb 10 05:16:12 volumio volumio[25137]: info: CoreCommandRouter::volumioGetState Feb 10 05:16:12 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:12 volumio volumio[25137]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 05:16:12 volumio volumio[25137]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 05:16:12 volumio volumio[25137]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 05:16:12 volumio volumio[25137]: info: Aligning Spotify Volume to Volumio Volume Feb 10 05:16:12 volumio volumio[25137]: info: CoreCommandRouter::volumioGetState Feb 10 05:16:12 volumio volumio[25137]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:12 volumio volumio[25137]: info: Setting Spotify Volume from Volumio: 100 Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="completed challenge" Feb 10 05:16:12 volumio volumio[25137]: info: Initializing connection to go-librespot Websocket Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-06:00" level=debug msg="new websocket client" Feb 10 05:16:12 volumio volumio[25137]: info: Connection to go-librespot Websocket established Feb 10 05:16:12 volumio go-librespot[25606]: time="2026-02-10T05:16:12-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 " Feb 10 05:16:12 volumio volumio[25137]: info: Connection to go-librespot Websocket closed Feb 10 05:16:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:12 volumio volumio[25137]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 05:16:12 volumio volumio[25137]: Error: socket hang up Feb 10 05:16:12 volumio volumio[25137]: at connResetException (node:internal/errors:720:14) Feb 10 05:16:12 volumio volumio[25137]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 05:16:12 volumio volumio[25137]: at Socket.emit (node:events:526:35) Feb 10 05:16:12 volumio volumio[25137]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 05:16:12 volumio volumio[25137]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 05:16:12 volumio volumio[25137]: code: 'ECONNRESET', Feb 10 05:16:12 volumio volumio[25137]: response: undefined Feb 10 05:16:12 volumio volumio[25137]: } Feb 10 05:16:12 volumio volumio[25137]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 05:16:13 volumio sudo[25627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 05:15' Feb 10 05:16:13 volumio sudo[25627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:13 volumio sudo[25627]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:14 volumio volumio-remote-updater[751]: [2026-02-10 05:16:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 05:16:14 volumio volumio-remote-updater[751]: [2026-02-10 05:16:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 05:16:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 05:16:14 volumio systemd[1]: volumio.service: Consumed 45.494s CPU time. Feb 10 05:16:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 05:16:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 05:16:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3647. Feb 10 05:16:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 05:16:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 05:16:14 volumio systemd[1]: volumio.service: Consumed 45.494s CPU time. Feb 10 05:16:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 05:16:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 05:16:14 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:16:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 05:16:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:16 volumio go-librespot[25658]: go-librespot daemon starting... Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=debug msg="app state loaded" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-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]" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-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]" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-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]" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=info msg="zeroconf server listening on port 46139" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=debug msg="obtained new client token: AAD3DEST/AZT7WOjpKemiP5+7/A2I0icybuqtcYcoTkH+jZUw7if2xb/FxLf//SgugHbC9lVs1AwAc+0fTzTsl/WARzKueoXTwXio9JbBbBBFKgQNWEO69yrJPi+7DwTBJ/uMt7Ha7ybuqGlEdfVuI51gRNuQ3sTBwsfqeI+S+GwDzgOJ0Rubaw37GmRoo/7uYGNf8ERrPFnUV9nUaWvVUKFxtrUbpvLz1hSy3x3k+tEcXnq5vNv7t0fwA==" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-06:00" level=debug msg="completed challenge" Feb 10 05:16:16 volumio go-librespot[25659]: time="2026-02-10T05:16:16-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 " Feb 10 05:16:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:16 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:16 volumio volumio[25642]: info: ----- Volumio3 ---- Feb 10 05:16:16 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:16 volumio volumio[25642]: info: ----- System startup ---- Feb 10 05:16:16 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:17 volumio volumio[25642]: info: MYVOLUMIO Environment detected Feb 10 05:16:17 volumio volumio[25642]: info: Plugin folders cleanup Feb 10 05:16:17 volumio volumio[25642]: info: Scanning into folder /volumio/app/plugins/ Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category audio_interface Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category miscellanea Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category music_service Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category plugins.json Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category system_controller Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category user_interface Feb 10 05:16:17 volumio volumio[25642]: info: Scanning into folder /data/plugins/ Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category audio_interface Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category music_service Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category system_controller Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category system_hardware Feb 10 05:16:17 volumio volumio[25642]: info: Scanning category user_interface Feb 10 05:16:17 volumio volumio[25642]: info: Plugin folders cleanup completed Feb 10 05:16:17 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:17 volumio volumio[25642]: info: ----- Core plugins startup ---- Feb 10 05:16:17 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:17 volumio volumio[25642]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 05:16:17 volumio volumio[25642]: info: Adding plugin upnp to MyMusic Plugins Feb 10 05:16:17 volumio volumio[25642]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 05:16:17 volumio volumio[25642]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 05:16:17 volumio volumio[25642]: info: Loading plugins from folder /data/plugins/ Feb 10 05:16:17 volumio volumio[25642]: info: Loading plugin "system"... Feb 10 05:16:17 volumio volumio[25642]: info: Loading plugin "appearance"... Feb 10 05:16:18 volumio volumio[25642]: info: Loading plugin "network"... Feb 10 05:16:18 volumio volumio[25642]: info: Refreshing Cached IP Addresses Feb 10 05:16:18 volumio sudo[25679]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 05:16:18 volumio sudo[25679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:18 volumio sudo[25681]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 05:16:18 volumio sudo[25681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:18 volumio sudo[25681]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:18 volumio sudo[25679]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:18 volumio volumio[25642]: info: Loading plugin "services"... Feb 10 05:16:18 volumio volumio[25642]: info: Loading plugin "alsa_controller"... Feb 10 05:16:18 volumio sudo[25688]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 05:16:18 volumio sudo[25688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:18 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:16:18 volumio volumio[25642]: info: Loading plugin "wizard"... Feb 10 05:16:18 volumio volumio[25642]: info: Loading plugin "networkfs"... Feb 10 05:16:18 volumio volumio[25642]: info: Starting Udev Watcher for removable devices Feb 10 05:16:19 volumio volumio[25642]: info: Ignoring mount for partition: boot Feb 10 05:16:19 volumio volumio[25642]: info: Ignoring mount for partition: volumio Feb 10 05:16:19 volumio volumio[25642]: info: Ignoring mount for partition: volumio_data Feb 10 05:16:19 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:16:19 volumio volumio[25642]: info: Mounting Device Wikipedia Feb 10 05:16:19 volumio sudo[25719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 10 05:16:19 volumio sudo[25719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:19 volumio sudo[25719]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:19 volumio volumio[25642]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 05:16:19 volumio volumio[25642]: dmesg(1) may have more information after failed mount system call. Feb 10 05:16:19 volumio volumio[25642]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 10 05:16:19 volumio volumio[25642]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 05:16:19 volumio volumio[25642]: dmesg(1) may have more information after failed mount system call. Feb 10 05:16:19 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:16:19 volumio volumio[25642]: info: Loading plugin "volumio_command_line_client"... Feb 10 05:16:19 volumio volumio[25642]: info: Loading plugin "upnp"... Feb 10 05:16:19 volumio volumio[25642]: info: [1770722179216] Starting Upmpd Daemon Feb 10 05:16:19 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:16:19 volumio volumio[25642]: info: Loading plugin "my_music"... Feb 10 05:16:19 volumio volumio[25642]: info: Loading plugin "mpd"... Feb 10 05:16:19 volumio sudo[25688]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:19 volumio volumio-remote-updater[751]: [2026-02-10 05:16:19] [connect] Successful connection Feb 10 05:16:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 05:16:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:19 volumio go-librespot[25721]: go-librespot daemon starting... Feb 10 05:16:19 volumio volumio[25642]: info: Loading plugin "upnp_browser"... Feb 10 05:16:19 volumio go-librespot[25722]: time="2026-02-10T05:16:19-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:19 volumio go-librespot[25722]: time="2026-02-10T05:16:19-06:00" level=debug msg="app state loaded" Feb 10 05:16:19 volumio go-librespot[25722]: time="2026-02-10T05:16:19-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:19 volumio go-librespot[25722]: time="2026-02-10T05:16:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-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]" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-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]" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-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]" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-06:00" level=info msg="zeroconf server listening on port 38715" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-06:00" level=debug msg="obtained new client token: AAD3J4iCD/fsy9KuZRUxEVF8gIt/Z0+eKIGxaR/+FVonj/9kq4T8X9RapcFmTq7CiT0YLjogEgq5zaSrQ1SCH4G4TdaydarZM532p2NTC+owiBFHN/HIE1ICTsKKsSCwOxC21PeVDeP+ZUVMzyF0h7qmoe0PGgt35cXZPCYyZiDp33tWd+JuBP2u+KsGw51E8nj3+ihDd8jkgDsVVC4RLSZ/tcc/V6+qZQ16uOi+Z9gqv2byyzpMjs5VhQ==" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-06:00" level=debug msg="completed challenge" Feb 10 05:16:20 volumio go-librespot[25722]: time="2026-02-10T05:16:20-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 " Feb 10 05:16:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "alarm-clock"... Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "airplay_emulation"... Feb 10 05:16:22 volumio volumio[25642]: info: Starting Shairport Sync Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "last_100"... Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "webradio"... Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "i2s_dacs"... Feb 10 05:16:22 volumio volumio[25642]: info: I2S DAC not set, start Auto-detection Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "volumiodiscovery"... Feb 10 05:16:22 volumio volumio[25642]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 05:16:22 volumio volumio[25642]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:16:22 volumio volumio[25642]: *** WARNING *** For more information see Feb 10 05:16:22 volumio volumio[25642]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 05:16:22 volumio volumio[25642]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:16:22 volumio volumio[25642]: *** WARNING *** For more information see Feb 10 05:16:22 volumio node[25642]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 05:16:22 volumio node[25642]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:16:22 volumio node[25642]: *** WARNING *** For more information see Feb 10 05:16:22 volumio node[25642]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 05:16:22 volumio node[25642]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 05:16:22 volumio node[25642]: *** WARNING *** For more information see Feb 10 05:16:22 volumio volumio[25642]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 05:16:22 volumio volumio[25642]: info: Discovery: Started advertising with name: Volumio Feb 10 05:16:22 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 05:16:22 volumio volumio[25642]: info: Loading plugin "bandcamp"... Feb 10 05:16:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 05:16:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:23 volumio go-librespot[25733]: go-librespot daemon starting... Feb 10 05:16:23 volumio go-librespot[25734]: time="2026-02-10T05:16:23-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:23 volumio go-librespot[25734]: time="2026-02-10T05:16:23-06:00" level=debug msg="app state loaded" Feb 10 05:16:23 volumio go-librespot[25734]: time="2026-02-10T05:16:23-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:23 volumio go-librespot[25734]: time="2026-02-10T05:16:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-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]" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-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]" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-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]" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-06:00" level=info msg="zeroconf server listening on port 44373" Feb 10 05:16:24 volumio volumio[25642]: info: Plugin calmradio is not enabled Feb 10 05:16:24 volumio volumio[25642]: info: Loading plugin "soundcloud"... Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-06:00" level=debug msg="obtained new client token: AABmN/E865s+6+0UPosi2C8ViZ7h+w7j1syCzS4ZUkAStsJVxM4k6ecyEbkS/UNDHym8Q9mNXdNC6N55xky+DeHjs4QGi8iEwbjxs/IlrQXhyEAL+1PZAq/1J5RZG44ZlBdSQ6G/pHm8l/JvAKj3MaeruKxfiCtXnvU+l0p5tHyPjssUnjSfD5SBowuI+9fmOMFVlWTwRvnclQXbJTHP/Ox011rX6RSVTBwpCAkuBHD+1ulkF+Ywtlc=" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-06:00" level=debug msg="completed challenge" Feb 10 05:16:24 volumio go-librespot[25734]: time="2026-02-10T05:16:24-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 " Feb 10 05:16:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:24 volumio volumio[25642]: info: Loading plugin "spop"... Feb 10 05:16:25 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:16:25 volumio volumio[25642]: info: Loading plugin "squeezelite_mc"... Feb 10 05:16:26 volumio volumio[25642]: info: Loading plugin "youtube2"... Feb 10 05:16:26 volumio volumio[25642]: info: Loading plugin "ytcr"... Feb 10 05:16:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 05:16:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:27 volumio go-librespot[25746]: go-librespot daemon starting... Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-06:00" level=debug msg="app state loaded" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-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]" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-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]" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-06:00" level=info msg="zeroconf server listening on port 39245" Feb 10 05:16:27 volumio go-librespot[25747]: time="2026-02-10T05:16:27-06:00" level=debug msg="obtained new client token: AADfdZ9k6ilM++XHwekhiaC6nN26YuNpQnSxUatRVR9bm9FFyXXXKPZ+JAhY1nZHb1puO0Eaj0KpaDFhJNCVSK5I/AxY951EBmXQQy+L6JdvmsxVLfeAQrx02V3MeGSkSe8sKKQQnvQgD4bWnqU6eqTYnkyYTTskaZZl80QfG8/klv8iVDY7mc8KEsECwQ3G8v8+3ldpxLz6jq/wtK82hdwVUCO7zB7aDhwOB6x6TGUp+dS0f1xiOBjM2w==" Feb 10 05:16:28 volumio go-librespot[25747]: time="2026-02-10T05:16:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:28 volumio go-librespot[25747]: time="2026-02-10T05:16:28-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:28 volumio go-librespot[25747]: time="2026-02-10T05:16:28-06:00" level=debug msg="completed challenge" Feb 10 05:16:28 volumio go-librespot[25747]: time="2026-02-10T05:16:28-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 " Feb 10 05:16:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "ytmusic"... Feb 10 05:16:28 volumio volumio[25642]: info: Plugin now_playing is not enabled Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "outputs"... Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "albumart"... Feb 10 05:16:28 volumio volumio[25642]: info: Plugin example_plugin is not enabled Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "inputs"... Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "updater_comm"... Feb 10 05:16:28 volumio volumio[25642]: info: Plugin mpdemulation is not enabled Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "rest_api"... Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "websocket"... Feb 10 05:16:28 volumio volumio[25642]: info: Starting Socket.io Server version 1.7.4 Feb 10 05:16:28 volumio volumio[25642]: info: Plugin fusiondsp is not enabled Feb 10 05:16:28 volumio volumio[25642]: info: Plugin mpdoutput is not enabled Feb 10 05:16:28 volumio volumio[25642]: info: Plugin RoonBridge is not enabled Feb 10 05:16:28 volumio volumio[25642]: info: Loading plugin "podcast"... Feb 10 05:16:29 volumio volumio[25642]: info: ControllerPodcast::constructor Feb 10 05:16:29 volumio volumio[25642]: info: Loading plugin "volusonic"... Feb 10 05:16:29 volumio volumio[25754]: Forking 3 albumart workers Feb 10 05:16:30 volumio volumio[25642]: info: Applying required configuration parameters for plugin volusonic Feb 10 05:16:30 volumio volumio[25642]: info: Loading plugin "backup_restore"... Feb 10 05:16:30 volumio volumio[25779]: Starting albumart workers Feb 10 05:16:30 volumio volumio[25778]: Starting albumart workers Feb 10 05:16:30 volumio volumio[25780]: Starting albumart workers Feb 10 05:16:31 volumio volumio[25642]: info: Applying required configuration parameters for plugin backup_restore Feb 10 05:16:31 volumio volumio[25642]: info: Plugin rpi_eeprom_config is not enabled Feb 10 05:16:31 volumio volumio[25642]: info: Plugin rpi_eeprom_updater is not enabled Feb 10 05:16:31 volumio volumio[25642]: info: Loading plugin "scheduledrestart"... Feb 10 05:16:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 05:16:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:31 volumio go-librespot[25808]: go-librespot daemon starting... Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=debug msg="app state loaded" Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:31 volumio volumio[25642]: info: Applying required configuration parameters for plugin scheduledrestart Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:31 volumio volumio[25642]: info: Plugin Bluetoothremote is not enabled Feb 10 05:16:31 volumio volumio[25642]: info: Plugin music_services_shield is not enabled Feb 10 05:16:31 volumio volumio[25642]: info: Loading plugin "Systeminfo"... Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-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]" Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-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]" Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=info msg="zeroconf server listening on port 34587" Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=debug msg="obtained new client token: AAC9VvAwtWd73Oppqld8wwEJ2pQJ2uBrwlZXvO3zwXN3QHXDhyr406gFv93HZbfyyIjEQRBj0eS2gPo7UZdd1Bs0IsRr2lPE6tGXMg+Hn5NioSwM4O4S0eTc9pAfv0saq7O5QjOLpV7Cav060KI5+TV/fAUxGpsfPFgyXpA7nE7aczrApyBcp5+hcTYvSBghOnV7/DIBy8CwcVAAJF0d5ZdPXwEce5wyeECokQvEqs0dGDGt/CpUdzMQOg==" Feb 10 05:16:31 volumio volumio[25642]: info: Plugin peppymeterbasic is not enabled Feb 10 05:16:31 volumio volumio[25642]: info: Loading plugin "peppyspectrum"... Feb 10 05:16:31 volumio go-librespot[25809]: time="2026-02-10T05:16:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:32 volumio go-librespot[25809]: time="2026-02-10T05:16:32-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:32 volumio go-librespot[25809]: time="2026-02-10T05:16:32-06:00" level=debug msg="completed challenge" Feb 10 05:16:32 volumio go-librespot[25809]: time="2026-02-10T05:16:32-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 " Feb 10 05:16:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:32 volumio volumio-remote-updater[751]: [2026-02-10 05:16:32] [connect] Successful connection Feb 10 05:16:32 volumio volumio[25642]: info: Loading i18n strings for locale en Feb 10 05:16:32 volumio volumio[25642]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 05:16:32 volumio volumio[25642]: Updating browse sources language Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::initPlayerControls Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: Express server listening on port 3000 Feb 10 05:16:32 volumio volumio[25642]: [Metrics] WebUI: 16s 213.31ms Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::resetVolumioState Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::getcurrentVolume Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:32 volumio sudo[25841]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 05:16:32 volumio sudo[25841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:32 volumio sudo[25841]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:32 volumio sudo[25843]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 05:16:32 volumio sudo[25843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:32 volumio sudo[25843]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:32 volumio volumio[25642]: info: Volumio Network Manager: Network status updated: 1 Feb 10 05:16:32 volumio volumio[25642]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::pushState Feb 10 05:16:32 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioPushState Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::updateTrackBlock Feb 10 05:16:32 volumio volumio[25642]: info: CorePlayQueue::getTrackBlock Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:16:32 volumio volumio-remote-updater[751]: [2026-02-10 05:16:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770722192 101 Feb 10 05:16:32 volumio volumio[25642]: 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 Feb 10 05:16:32 volumio volumio[25642]: info: Reloading queue from file Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::setRepeat null single undefined Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::pushState Feb 10 05:16:32 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioPushState Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::setRandom null Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::pushState Feb 10 05:16:32 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioPushState Feb 10 05:16:32 volumio volumio[25642]: info: Setting Device type: Raspberry PI Feb 10 05:16:32 volumio volumio[25642]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:16:32 volumio volumio[25642]: info: CoreStateMachine::pushState Feb 10 05:16:32 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioPushState Feb 10 05:16:32 volumio volumio[25642]: info: Completed loading Core Plugins Feb 10 05:16:32 volumio volumio[25642]: info: Preparing to generate the ALSA configuration file Feb 10 05:16:32 volumio sudo[25857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 05:16:32 volumio sudo[25857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:32 volumio volumio[25642]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 05:16:32 volumio volumio[25642]: info: Discovery: Found device Volumio Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::volumioGetState Feb 10 05:16:32 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:32 volumio volumio[25642]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 05:16:32 volumio volumio[25642]: info: Reading ALSA contributions from plugins. Feb 10 05:16:32 volumio volumio[25642]: info: Asound.conf file unchanged, so no further update is needed Feb 10 05:16:32 volumio volumio[25642]: info: Output device has changed, restarting MPD Feb 10 05:16:32 volumio sudo[25857]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:32 volumio volumio[25642]: info: Output device has changed, restarting Shairport Sync Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:32 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:32 volumio sudo[25860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:16:32 volumio sudo[25860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:32 volumio sudo[25860]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:32 volumio sudo[25862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:16:32 volumio sudo[25862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:33 volumio volumio[25642]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:16:33 volumio volumio[25642]: info: ___________ START PLUGINS ___________ Feb 10 05:16:33 volumio volumio[25642]: info: ControllerMpd::onStart: Initializing MPD Feb 10 05:16:33 volumio volumio[25642]: info: Creating MPD Configuration file Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:16:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193044] CoreMusicLibrary::Adding element Media Servers Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio sudo[25870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:16:33 volumio sudo[25870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:33 volumio sudo[25870]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:33 volumio sudo[25872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:16:33 volumio sudo[25872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:33 volumio volumio[25642]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:33 volumio volumio[25642]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193158] CoreMusicLibrary::Adding element Last_100 Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193163] CoreMusicLibrary::Adding element Webradio Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 05:16:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 05:16:33 volumio systemd[1]: mpd.service: Consumed 5.681s CPU time. Feb 10 05:16:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 05:16:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 05:16:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:16:33 volumio volumio[25642]: info: Initializing BBC Radios Feb 10 05:16:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193245] CoreMusicLibrary::Adding element Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193258] CoreMusicLibrary::Adding element SoundCloud Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: info: Creating Spotify config file Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:33 volumio sudo[25897]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 05:16:33 volumio sudo[25897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 05:16:33 volumio sudo[25897]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:33 volumio volumio[25642]: info: [squeezelite_mc] Starting proxy server... Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193620] CoreMusicLibrary::Adding element YouTube2 Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193639] CoreMusicLibrary::Adding element YouTube Music Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube Music Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193650] CoreMusicLibrary::Adding element Podcast Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube Music Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Podcast Feb 10 05:16:33 volumio volumio[25642]: info: Loading i18n strings for locale en Feb 10 05:16:33 volumio volumio[25642]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 05:16:33 volumio volumio[25642]: Updating browse sources language Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube Music Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Podcast Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube Music Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Podcast Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:33 volumio volumio[25642]: info: [1770722193699] CoreMusicLibrary::Adding element Volusonic Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source YouTube Music Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Podcast Feb 10 05:16:33 volumio volumio[25642]: Cannot find translation for source Volusonic Feb 10 05:16:33 volumio volumio[25642]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 10 05:16:33 volumio volumio[25642]: info: Volumio Calling Home Feb 10 05:16:33 volumio volumio[25642]: info: [squeezelite_mc] Proxy server started on port 34681 Feb 10 05:16:33 volumio volumio[25642]: info: Preparing to generate the ALSA configuration file Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 05:16:33 volumio volumio[25642]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 05:16:33 volumio volumio[25642]: info: Discovery: Found device Volumio Feb 10 05:16:33 volumio volumio[25642]: info: CoreCommandRouter::volumioGetState Feb 10 05:16:33 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:33 volumio volumio[25642]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 05:16:33 volumio volumio[25642]: info: Reading ALSA contributions from plugins. Feb 10 05:16:34 volumio volumio[25642]: info: MPD Permissions set Feb 10 05:16:34 volumio volumio[25642]: info: MPD Permissions set Feb 10 05:16:34 volumio volumio[25642]: info: Upmpdcli Daemon Started Feb 10 05:16:34 volumio volumio[25642]: info: Spotify config file written Feb 10 05:16:34 volumio volumio[25642]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 10 05:16:34 volumio sudo[25907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 05:16:34 volumio sudo[25907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio volumio[25642]: info: VolumeController:: Volume=100 Mute =false Feb 10 05:16:34 volumio volumio[25642]: info: CoreStateMachine::pushState Feb 10 05:16:34 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::volumioPushState Feb 10 05:16:34 volumio volumio[25642]: info: [squeezelite_mc] Server discovery started Feb 10 05:16:34 volumio volumio[25642]: info: [squeezelite_mc] Player finder started Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: No need to fix Spotify hosts Feb 10 05:16:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:34 volumio go-librespot[25912]: go-librespot daemon starting... Feb 10 05:16:34 volumio sudo[25907]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=debug msg="app state loaded" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:34 volumio volumio[25642]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 10 05:16:34 volumio volumio[25642]: info: Volumio called home Feb 10 05:16:34 volumio volumio[25642]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 10 05:16:34 volumio volumio[25642]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 10 05:16:34 volumio volumio[25642]: 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 Feb 10 05:16:34 volumio volumio[25642]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 05:16:34 volumio volumio[25642]: SPOTIFY: BQDB03WIFM_KYObQi_uyDTFxVvjyuOe005U-A5PiTwXsy5gCP8RxcnAhE4Ox3Wn-SXoiYL1g29NnHabj-_3CLBwl038t0lwTm4k-zo122WZzMfdJtpEysuYYC1zzOf6S01_I-5TO2GaacSMbms7Tlm5-Wz3CI-l4yYORkbt7VtOTGTQxA9s77g_nwkXfojL67KfPH2urWrw8xYYm86rMhJ5tZtZPyplplWrPE3U Feb 10 05:16:34 volumio volumio[25642]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 05:16:34 volumio volumio[25642]: info: New Spotify access token = BQDB03WIFM_KYObQi_uyDTFxVvjyuOe005U-A5PiTwXsy5gCP8RxcnAhE4Ox3Wn-SXoiYL1g29NnHabj-_3CLBwl038t0lwTm4k-zo122WZzMfdJtpEysuYYC1zzOf6S01_I-5TO2GaacSMbms7Tlm5-Wz3CI-l4yYORkbt7VtOTGTQxA9s77g_nwkXfojL67KfPH2urWrw8xYYm86rMhJ5tZtZPyplplWrPE3U Feb 10 05:16:34 volumio volumio[25642]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16: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]" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16: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]" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16: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]" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=info msg="zeroconf server listening on port 46283" Feb 10 05:16:34 volumio sudo[25932]: 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 Feb 10 05:16:34 volumio sudo[25932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio sudo[25932]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio volumio[25642]: info: Starting Shairport Sync Feb 10 05:16:34 volumio volumio[25642]: info: Starting Shairport Sync Feb 10 05:16:34 volumio volumio[25642]: info: Starting Shairport Sync Feb 10 05:16:34 volumio sudo[25940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:16:34 volumio sudo[25940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio sudo[25936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:16:34 volumio sudo[25936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio sudo[25938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:16:34 volumio sudo[25938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=debug msg="obtained new client token: AADTW4KGHOPnTd6Hm0DPuQAerilNP7zUrcNh+VZ4EI22LnFIKDq4EqbAXreTh3RH4UKSPep48jvA9mjV9m3FpFS2aZNyVKb/DQIf8r8jzpSe67nwkB3BOfA6qvCVKk790Y2H5kc/S57Oa1bj2BHn9tZve6T2fFIbZddyOnipoAoCiGpL7JmG7cYT6iJJYEWhsdzy2ZUM31x+ySd76UWZTXHjLV4ozMngOvuVMHk6Bt35lBlFR8wXYjOmHA==" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:16:34 volumio volumio[25642]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 10 05:16:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:16:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:16:34 volumio volumio[25642]: info: Asound.conf file unchanged, so no further update is needed Feb 10 05:16:34 volumio systemd[1]: shairport-sync.service: Consumed 1.987s CPU time. Feb 10 05:16:34 volumio volumio[25642]: info: Output device has changed, restarting MPD Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-06:00" level=debug msg="completed challenge" Feb 10 05:16:34 volumio sudo[25947]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 10 05:16:34 volumio sudo[25947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio volumio[25642]: info: Output device has changed, restarting Shairport Sync Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:34 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:34 volumio sudo[25949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 05:16:34 volumio sudo[25949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio sudo[25949]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:16:34 volumio go-librespot[25922]: time="2026-02-10T05:16:34-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 " Feb 10 05:16:34 volumio sudo[25940]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio sudo[25936]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio sudo[25951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 05:16:34 volumio sudo[25951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:34 volumio sudo[25938]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:34 volumio sudo[25947]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:34 volumio volumio[25642]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 05:16:34 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 05:16:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 05:16:35 volumio systemd[1]: mpd.service: Consumed 1.524s CPU time. Feb 10 05:16:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 05:16:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 05:16:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 05:16:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 05:16:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 05:16:35 volumio volumio[25642]: info: MPD Permissions set Feb 10 05:16:35 volumio volumio[25642]: info: Shairport-Sync Started Feb 10 05:16:35 volumio volumio[25642]: Error adding Membership: Error: addMembership EINVAL Feb 10 05:16:35 volumio volumio[25642]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 05:16:35 volumio volumio[25642]: info: Shairport-Sync Started Feb 10 05:16:35 volumio volumio[25642]: info: Shairport-Sync Started Feb 10 05:16:35 volumio sudo[25982]: 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 Feb 10 05:16:35 volumio sudo[25982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio sudo[25982]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::volumioGetState Feb 10 05:16:35 volumio volumio[25642]: info: CorePlayQueue::getTrack 0 Feb 10 05:16:35 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 10 05:16:35 volumio volumio[25642]: info: Starting Shairport Sync Feb 10 05:16:35 volumio sudo[25990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 10 05:16:35 volumio sudo[25990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:35 volumio sudo[25979]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 05:16:35 volumio sudo[25979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 05:16:35 volumio volumio[25642]: 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"} Feb 10 05:16:35 volumio volumio[25642]: info: Spotify Successfully logged in Feb 10 05:16:35 volumio sudo[25979]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:35 volumio sudo[25992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 05:16:35 volumio sudo[25992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:35 volumio systemd[1]: Reloading. Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 05:16:35 volumio volumio[25642]: info: [1770722195390] CoreMusicLibrary::Adding element Spotify Feb 10 05:16:35 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source Bandcamp Discover Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source SoundCloud Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source YouTube2 Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source YouTube Music Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source Podcast Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source Volusonic Feb 10 05:16:35 volumio volumio[25642]: Cannot find translation for source Spotify Feb 10 05:16:35 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 05:16:36 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:36 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:36 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 05:16:36 volumio volumio[25642]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 05:16:37 volumio volumio[25642]: info: go-librespot daemon successfully initialized Feb 10 05:16:37 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. Feb 10 05:16:37 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. Feb 10 05:16:38 volumio sudo[25990]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:38 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:38 volumio sudo[26016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:38 volumio sudo[26016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 05:16:38 volumio sudo[26016]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:38 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 10 05:16:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:38 volumio go-librespot[26018]: go-librespot daemon starting... Feb 10 05:16:38 volumio sudo[26020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 10 05:16:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 05:16:38 volumio sudo[26020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 05:16:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:16:38 volumio systemd[1]: shairport-sync.service: Consumed 1.563s CPU time. Feb 10 05:16:38 volumio go-librespot[26021]: time="2026-02-10T05:16:38-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:38 volumio go-librespot[26021]: time="2026-02-10T05:16:38-06:00" level=debug msg="app state loaded" Feb 10 05:16:38 volumio go-librespot[26021]: time="2026-02-10T05:16:38-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:38 volumio go-librespot[26021]: time="2026-02-10T05:16:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 05:16:38 volumio sudo[25992]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:38 volumio volumio[25642]: info: Shairport-Sync Started Feb 10 05:16:38 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 05:16:39 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 10 05:16:39 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 05:16:39 volumio sudo[26020]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-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]" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-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]" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-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]" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-06:00" level=info msg="zeroconf server listening on port 40593" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-06:00" level=debug msg="obtained new client token: AAA3YQELtguBQZD7r0ERpOIVc37vOVKMoB8w1IWgIUDjD2jgouz+Gh5Fakl95sq0r8uGsZ2b0nAp6Q5B1UZDR159sVnOxSPP6ZLyddGRDZvj3pN/b8UY6zw0d92ocmyx4/btysTrGTC7VBZDryP2UnyNyo0C4a3BL52XcEXYbBAVIorNGjJuMFy53Hyv21v/KIbBkBTu77UrRyr82b1PTgt/kKaIvu8JzQfXYWd5Jc+AfDrXUtf8xhwpzQ==" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-06:00" level=debug msg="completed challenge" Feb 10 05:16:39 volumio go-librespot[26021]: time="2026-02-10T05:16:39-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 " Feb 10 05:16:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:39 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:39 volumio sudo[26059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:39 volumio sudo[26059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:39 volumio sudo[26059]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:39 volumio volumio[25642]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 10 05:16:39 volumio sudo[26063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 10 05:16:39 volumio sudo[26063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:39 volumio sudo[26063]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:39 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 10 05:16:39 volumio sudo[26066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 10 05:16:39 volumio sudo[26066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:40 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 05:16:40 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 05:16:40 volumio sudo[26066]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:40 volumio volumio[25642]: info: Initializing connection to go-librespot Websocket Feb 10 05:16:40 volumio volumio[25642]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:16:40 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:40 volumio sudo[26073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:40 volumio sudo[26073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:40 volumio sudo[26073]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:41 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:41 volumio sudo[26076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:41 volumio sudo[26076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:41 volumio sudo[26076]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:41 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:41 volumio sudo[26079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:41 volumio sudo[26079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:41 volumio sudo[26079]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:41 volumio mpd[26014]: 2026-02-10T05:16:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 05:16:41 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 05:16:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 05:16:42 volumio sudo[25951]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:42 volumio sudo[25862]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:42 volumio sudo[25872]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:42 volumio volumio[25642]: error: MPD error: The expression evaluated to a falsy value: Feb 10 05:16:42 volumio volumio[25642]: assert.ok(self.idling) Feb 10 05:16:42 volumio volumio[25642]: error: The expression evaluated to a falsy value: Feb 10 05:16:42 volumio volumio[25642]: assert.ok(self.idling) Feb 10 05:16:42 volumio volumio[25642]: error: MPD error: The expression evaluated to a falsy value: Feb 10 05:16:42 volumio volumio[25642]: assert.ok(self.idling) Feb 10 05:16:42 volumio volumio[25642]: error: The expression evaluated to a falsy value: Feb 10 05:16:42 volumio volumio[25642]: assert.ok(self.idling) Feb 10 05:16:42 volumio volumio[25642]: error: updateQueue error: null Feb 10 05:16:42 volumio volumio[25642]: info: MPD running with PID26014 Feb 10 05:16:42 volumio volumio[25642]: ,establishing connection Feb 10 05:16:42 volumio volumio[25642]: error: updateQueue error: null Feb 10 05:16:42 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:42 volumio sudo[26087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:42 volumio sudo[26087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:42 volumio sudo[26087]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 10 05:16:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:42 volumio go-librespot[26089]: go-librespot daemon starting... Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=debug msg="app state loaded" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-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]" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-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]" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-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]" Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=info msg="zeroconf server listening on port 44675" Feb 10 05:16:42 volumio volumio[25642]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=debug msg="obtained new client token: AADfObsojCYc7RMsgneOOSTg47cxI+EU70FWxQATYM/Mwd6eAl1YyK1db7ZmZGz5D4gU0m6MEhsIyDucDwUdh+O/zav1/B4umGItJGOs9FF8Yh9PUf/NR9g65yg33z397o6VX1Oz8eb7j+hVDzolTpLVbRpbbFyjLDJi4ugfoHwrgI8LnRILzZY3sVMLX68CnphXjk+s6XibSYcwi9+kU1ijL1cgtd8vA/f+ZWdWMgjYAn8HU8YQbMatGw==" Feb 10 05:16:42 volumio sudo[26099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 05:16:42 volumio sudo[26099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:42 volumio go-librespot[26090]: time="2026-02-10T05:16:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 05:16:42 volumio sudo[26099]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:43 volumio volumio[25642]: info: Completed starting Core Plugins Feb 10 05:16:43 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:43 volumio volumio[25642]: info: ----- MyVolumio plugins startup ---- Feb 10 05:16:43 volumio volumio[25642]: info: ------------------------------------------- Feb 10 05:16:43 volumio volumio[25642]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 05:16:43 volumio volumio[25642]: info: Initializing connection to go-librespot Websocket Feb 10 05:16:43 volumio go-librespot[26090]: time="2026-02-10T05:16:43-06:00" level=debug msg="new websocket client" Feb 10 05:16:43 volumio volumio[25642]: info: Connection to go-librespot Websocket established Feb 10 05:16:44 volumio go-librespot[26090]: time="2026-02-10T05:16:44-06:00" level=debug msg="completed keyexchange" Feb 10 05:16:44 volumio go-librespot[26090]: time="2026-02-10T05:16:44-06:00" level=debug msg="completed challenge" Feb 10 05:16:44 volumio go-librespot[26090]: time="2026-02-10T05:16:44-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 " Feb 10 05:16:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 05:16:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 05:16:44 volumio volumio[25642]: info: Connection to go-librespot Websocket closed Feb 10 05:16:45 volumio sudo[26102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:16:45 volumio sudo[26102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:45 volumio sudo[26104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:16:45 volumio sudo[26104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:45 volumio sudo[26106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 05:16:45 volumio sudo[26106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:45 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 10 05:16:45 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 10 05:16:45 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 10 05:16:45 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 10 05:16:45 volumio sudo[26106]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:45 volumio mpd_monitor.sh[26110]: MPD Monitor Service: Starting MPD Monitor Service Feb 10 05:16:45 volumio sudo[26104]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:45 volumio volumio[25642]: info: Successfully started MPD Monitor Feb 10 05:16:45 volumio sudo[26102]: pam_unix(sudo:session): session closed for user root Feb 10 05:16:45 volumio volumio[25642]: info: Successfully started MPD Monitor Feb 10 05:16:45 volumio volumio[25642]: info: Successfully started MPD Monitor Feb 10 05:16:46 volumio volumio[25642]: info: Getting Spotify volume Feb 10 05:16:46 volumio volumio[25642]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 05:16:46 volumio volumio[25642]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 05:16:46 volumio volumio[25642]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 05:16:46 volumio volumio[25642]: errno: -111, Feb 10 05:16:46 volumio volumio[25642]: code: 'ECONNREFUSED', Feb 10 05:16:46 volumio volumio[25642]: syscall: 'connect', Feb 10 05:16:46 volumio volumio[25642]: address: '127.0.0.1', Feb 10 05:16:46 volumio volumio[25642]: port: 9879, Feb 10 05:16:46 volumio volumio[25642]: response: undefined Feb 10 05:16:46 volumio volumio[25642]: } Feb 10 05:16:46 volumio volumio[25642]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 05:16:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 10 05:16:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 05:16:47 volumio go-librespot[26126]: go-librespot daemon starting... Feb 10 05:16:47 volumio sudo[26129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 05:15' Feb 10 05:16:47 volumio sudo[26129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-06:00" level=debug msg="app state loaded" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-06:00" level=debug msg="stored credentials not found" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-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]" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-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]" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-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]" Feb 10 05:16:47 volumio go-librespot[26130]: time="2026-02-10T05:16:47-06:00" level=info msg="zeroconf server listening on port 36361" 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"