-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Sun 2025-06-15 00:48:17 EDT. -- Jun 15 00:47:00 perivolumio volumio[866]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 15 00:47:02 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:02 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jun 15 00:47:02 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:02 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:02 perivolumio go-librespot[1386]: go-librespot daemon starting... Jun 15 00:47:02 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:02 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="app state loaded" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=info msg="zeroconf server listening on port 34101" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="obtained new client token: AAC1Mt/9Tir11s/RknKEXUn+IuCWtnDfM1ZreejyCefQWtwnsM2aZV8K2O7T2XLzsN6kOxdf7Q9nwa+3EKb78LcAELpvU8mJGR1mesfm6BYyPOcfSMGWA0cCPT57DSz1vP3wjKn0fZtk/M+YDldxvhtlIjpRLVeSM0b6Iyh+P9Uw3LrkxJGMqD0hcR7bVvjZozVGNly0pviWajoIiyC30lfCSP3JILQTFmlI7C7GE6syJx31BiZPx5E=" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04:00" level=debug msg="completed challenge" Jun 15 00:47:02 perivolumio go-librespot[1386]: time="2025-06-15T00:47:02-04: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 " Jun 15 00:47:02 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:02 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:03 perivolumio volumio[866]: info: MYVOLUMIO: Adding device Jun 15 00:47:03 perivolumio volumio[866]: info: MYVOLUMIO: Evaluating Server Jun 15 00:47:03 perivolumio volumio[866]: info: Setting Geolocation for MyVolumio to us1 Jun 15 00:47:03 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:47:04 perivolumio volumio[866]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 15 00:47:04 perivolumio systemd[1]: systemd-timedated.service: Succeeded. Jun 15 00:47:04 perivolumio volumio[866]: info: Updating MyVolumio device info Jun 15 00:47:04 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:47:05 perivolumio volumio[866]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 15 00:47:05 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:05 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:05 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:05 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jun 15 00:47:05 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:05 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:05 perivolumio go-librespot[1411]: go-librespot daemon starting... Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=debug msg="app state loaded" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:05 perivolumio go-librespot[1411]: time="2025-06-15T00:47:05-04:00" level=info msg="zeroconf server listening on port 38733" Jun 15 00:47:06 perivolumio go-librespot[1411]: time="2025-06-15T00:47:06-04:00" level=debug msg="obtained new client token: AABKnRCORKB0Cn4OmZDrAbs2ip5CidipR9T1x8Z420NQY+CIZiELGf+eReBE2k277f3na7LLIeCAJKS5CcKLqSYUMsQUQTh+BR9a4/qtc9Cfl/NFNy+Vv/RYWcGwsBcfv1v962s9AJEsLVRKWGXGaQp1IELXl1+SMiUnJGeorhwCnHmExsZfHcOnA+2620xgiyivoPY2vJhi1+VcuLLA4Ftm/x5RUWQVrSfvsnpx8BOfecNgyx+9QulUhw==" Jun 15 00:47:06 perivolumio go-librespot[1411]: time="2025-06-15T00:47:06-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:06 perivolumio go-librespot[1411]: time="2025-06-15T00:47:06-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:06 perivolumio go-librespot[1411]: time="2025-06-15T00:47:06-04:00" level=debug msg="completed challenge" Jun 15 00:47:06 perivolumio go-librespot[1411]: time="2025-06-15T00:47:06-04: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 " Jun 15 00:47:06 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:06 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:08 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:08 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 15 00:47:08 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:47:08 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:47:08 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:08 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:47:08 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:47:08 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:08 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:47:08 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:47:09 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:09 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jun 15 00:47:09 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:09 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:09 perivolumio go-librespot[1422]: go-librespot daemon starting... Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="app state loaded" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=info msg="zeroconf server listening on port 43337" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="obtained new client token: AAC8OVOjGN4k+HezZUK2OH1Uz8NWto1oEpjK0w3xeInjIxKtPeV9QhdEr6DXp1V6HsiBLor+yp45wJyRzIOG57yhy/oX8j3RvYmGfGbs0flPQjL8RkonttNPfF4mxwI8cbIxriHVYCHw07dudA9wbzhAc/JPBXA/eylYhLOX6f2VtOiSApciZLq1aOr5Zhez5uOAQDnShkVeABy/WEdR2Z2A2KwmuzgoY0yf1RslHUlmK44FoQ2nzMA=" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04:00" level=debug msg="completed challenge" Jun 15 00:47:09 perivolumio go-librespot[1422]: time="2025-06-15T00:47:09-04: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 " Jun 15 00:47:09 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:09 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:09 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 15 00:47:10 perivolumio volumio[866]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 15 00:47:10 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:10 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:11 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:11 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:12 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:12 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jun 15 00:47:12 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:12 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:12 perivolumio go-librespot[1444]: go-librespot daemon starting... Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=debug msg="app state loaded" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:12 perivolumio go-librespot[1444]: time="2025-06-15T00:47:12-04:00" level=info msg="zeroconf server listening on port 45419" Jun 15 00:47:13 perivolumio volumio[866]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/fusiondsp/volumio/buster/armhf Jun 15 00:47:13 perivolumio go-librespot[1444]: time="2025-06-15T00:47:13-04:00" level=debug msg="obtained new client token: AAD+ODCNkln37ZmSnsSeRduiiEAYYNZri53OfEUpAUuQY9dn6NYy/0ZAjQrJ4ceS5R6SqzviSdsD+gem94aDB4BjHsVBhEtzJ4xvrZXqa309iKZi4o/BEkOky5p39Zp3ob2/P7RTLiRBeHr6SyEtY+i5PcMI4xqGzrIwRv/SZn2qLI6A0CL/e6vAz8Cteq40p5rCOYnMuJp9WH8PHKRu4CIMC96wjWtIWIB/GYaN5aZyW2bgF7YtPFn54A==" Jun 15 00:47:13 perivolumio go-librespot[1444]: time="2025-06-15T00:47:13-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:13 perivolumio go-librespot[1444]: time="2025-06-15T00:47:13-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:13 perivolumio go-librespot[1444]: time="2025-06-15T00:47:13-04:00" level=debug msg="completed challenge" Jun 15 00:47:13 perivolumio go-librespot[1444]: time="2025-06-15T00:47:13-04: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 " Jun 15 00:47:13 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:13 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:13 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 15 00:47:13 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:47:13 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 15 00:47:13 perivolumio volumio-remote-updater[631]: Test mode enabled Jun 15 00:47:13 perivolumio volumio-remote-updater[631]: No alpha test mode Jun 15 00:47:13 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 15 00:47:13 perivolumio volumio[866]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 15 00:47:13 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 15 00:47:14 perivolumio volumio[866]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/fusiondsp/volumio/buster/armhf Jun 15 00:47:14 perivolumio volumio[866]: info: FusionDsp - Stopping FusionDsp service Jun 15 00:47:14 perivolumio volumio[866]: info: camilladsp stopping service pid 1210... Jun 15 00:47:14 perivolumio volumio[866]: info: camilladsp service terminated, instance 1 Jun 15 00:47:14 perivolumio sudo[1460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Jun 15 00:47:14 perivolumio sudo[1460]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:14 perivolumio systemd[1]: Stopping FusionDsp Daemon... Jun 15 00:47:14 perivolumio volumio[1218]: Backend configuration: Jun 15 00:47:14 perivolumio volumio[1218]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Jun 15 00:47:14 perivolumio volumio[1218]: active_config_txt: null Jun 15 00:47:14 perivolumio volumio[1218]: camilla_host: 127.0.0.1 Jun 15 00:47:14 perivolumio volumio[1218]: camilla_port: 9876 Jun 15 00:47:14 perivolumio volumio[1218]: coeff_dir: /data/INTERNAL/FusionDsp/filters Jun 15 00:47:14 perivolumio volumio[1218]: config_dir: /data/configuration/audio_interface/fusiondsp Jun 15 00:47:14 perivolumio volumio[1218]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Jun 15 00:47:14 perivolumio volumio[1218]: log_file: /tmp/camilladsp.log Jun 15 00:47:14 perivolumio volumio[1218]: on_get_active_config: null Jun 15 00:47:14 perivolumio volumio[1218]: on_set_active_config: null Jun 15 00:47:14 perivolumio volumio[1218]: port: 5011 Jun 15 00:47:14 perivolumio volumio[1218]: supported_capture_types: null Jun 15 00:47:14 perivolumio volumio[1218]: supported_playback_types: null Jun 15 00:47:14 perivolumio volumio[1218]: update_config_symlink: false Jun 15 00:47:14 perivolumio volumio[1218]: update_config_txt: false Jun 15 00:47:14 perivolumio volumio[1218]: ======== Running on http://0.0.0.0:5011 ======== Jun 15 00:47:14 perivolumio volumio[1218]: (Press CTRL+C to quit) Jun 15 00:47:14 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:14 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:14 perivolumio systemd[1]: fusiondsp.service: Succeeded. Jun 15 00:47:14 perivolumio systemd[1]: Stopped FusionDsp Daemon. Jun 15 00:47:14 perivolumio sudo[1460]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:14 perivolumio volumio[866]: info: FusionDsp - Reporting Fusion DSP Disabled Jun 15 00:47:14 perivolumio volumio[866]: info: Removing fusiondspeq DSP Signal Path Element Jun 15 00:47:14 perivolumio volumio[866]: info: Check plugin dependencies Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 15 00:47:14 perivolumio volumio[866]: info: Rename folder Jun 15 00:47:14 perivolumio volumio[866]: info: Folder /tmp/downloaded_plugin.zip removed Jun 15 00:47:14 perivolumio volumio[866]: info: Move to category Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetBrowseSources Jun 15 00:47:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 15 00:47:16 perivolumio volumio[866]: info: Checking if install.sh is present Jun 15 00:47:16 perivolumio volumio[866]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 15 00:47:16 perivolumio volumio[866]: info: Completed starting MyVolumio Plugin Jun 15 00:47:16 perivolumio volumio[866]: [Metrics] CommandRouter: 48s 271.41ms Jun 15 00:47:16 perivolumio volumio[866]: info: CoreCommandRouter::volumiosetStartupVolume Jun 15 00:47:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:47:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:47:16 perivolumio volumio[866]: info: CoreCommandRouter::Close All Modals sent Jun 15 00:47:16 perivolumio volumio[866]: info: CoreCommandRouter::Close All Modals sent Jun 15 00:47:16 perivolumio volumio[866]: info: Executing install.sh Jun 15 00:47:16 perivolumio volumio[866]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 15 00:47:16 perivolumio volumio[866]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 15 00:47:16 perivolumio volumio[866]: error: FusionDsp - TypeError: Cannot read property 'stop' of null Jun 15 00:47:16 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:16 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jun 15 00:47:16 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:16 perivolumio sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/install.sh Jun 15 00:47:16 perivolumio sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:16 perivolumio volumio[866]: info: creating filters folder and copying demo filters Jun 15 00:47:16 perivolumio volumio[866]: info: copying demo flters Jun 15 00:47:16 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:16 perivolumio go-librespot[1478]: go-librespot daemon starting... Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="app state loaded" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=info msg="zeroconf server listening on port 35019" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="obtained new client token: AAD691jWHhz2VP+TZTS+sCwbfDjtJs6XkIX2oKXBgkcboAFpx/uYN4F56evtF4rocegnP0w8+0LwKpjop6GRqYNkJsE3EVKjCI9rsKHO70dTYUlXVX2phEOFL/dU4drxj4cZhvsgm3fdkH2ZQsnPOBeLLsLqNnt9MucbCJOKEDHvtz+8uJ3eWQVh1LffcvyQ2STq2aEdJhII2ZYxDP7ZZv+nslduoELSJEOPpT9h36YwNeEA1L00JZY=" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04:00" level=debug msg="completed challenge" Jun 15 00:47:16 perivolumio go-librespot[1478]: time="2025-06-15T00:47:16-04: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 " Jun 15 00:47:16 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:16 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/ Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/2XEQ15/ Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/2XEQ15/.Bass-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/2XEQ15/.Soundtrack-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/2XEQ15/.Classic-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/2XEQ15/.Voice-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/2XEQ15/.Rock-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/PEQ/ Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/convfir/ Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/convfir/kef.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/convfir/test.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/EQ15/ Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/EQ15/.Bass-FusionDsp.json Jun 15 00:47:16 perivolumio sudo[1510]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt update Jun 15 00:47:16 perivolumio sudo[1510]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/EQ15/.Soundtrack-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/EQ15/.Classic-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/EQ15/.Voice-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: ./presets/EQ15/.Rock-FusionDsp.json Jun 15 00:47:16 perivolumio volumio[866]: info: Installing/fusiondsp dependencies Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 15 00:47:17 perivolumio volumio[866]: info: Version has changed, forcing UI Reload Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::Reload Ui Jun 15 00:47:17 perivolumio volumio[866]: info: Hit:1 https://deb.nodesource.com/node_14.x buster InRelease Jun 15 00:47:17 perivolumio volumio[866]: info: Get:2 http://raspbian.raspberrypi.org/raspbian buster InRelease [15.0 kB] Jun 15 00:47:17 perivolumio volumio[866]: info: Get:3 http://archive.raspberrypi.org/debian buster InRelease [54.2 kB] Jun 15 00:47:17 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:17 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:17 perivolumio sudo[1595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 15 00:47:17 perivolumio sudo[1595]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:17 perivolumio sudo[1595]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:17 perivolumio sudo[1600]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 15 00:47:17 perivolumio sudo[1600]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:17 perivolumio sudo[1600]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:17 perivolumio volumio[866]: verbose: New Socket.io Connection to 192.168.21.51 from 192.168.21.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetVisibleSources Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:17 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 15 00:47:17 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:47:17 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:17 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:17 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:17 perivolumio volumio[866]: info: Listing playlists Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 15 00:47:17 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:47:17 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:47:18 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:47:18 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:47:18 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:47:18 perivolumio volumio[866]: info: Get:4 http://archive.raspberrypi.org/debian buster/main armhf Packages [400 kB] Jun 15 00:47:18 perivolumio volumio[866]: info: Fetched 470 kB in 2s (292 kB/s) Jun 15 00:47:19 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 15 00:47:19 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:19 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:47:19 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:47:19 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:47:19 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:47:19 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:19 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:19 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:47:19 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:19 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jun 15 00:47:19 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:19 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:19 perivolumio go-librespot[1720]: go-librespot daemon starting... Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=debug msg="app state loaded" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:19 perivolumio go-librespot[1720]: time="2025-06-15T00:47:19-04:00" level=info msg="zeroconf server listening on port 40043" Jun 15 00:47:20 perivolumio go-librespot[1720]: time="2025-06-15T00:47:20-04:00" level=debug msg="obtained new client token: AADJjL+hkblE9WN9seg6S1KnJLGUBMHf94smrXXLie2tbpFrwirDXHxHpQSHyVRi8eOSgAl5Jmk8Cxku6uXynPaeRu24GTwMX/3ei81pcVsQ9zhpFZnrZO4bDjAtkYsyfauNoBYItzkqL7cVe5zCcxeBkGSojYstGhf5jROtNw0DT8QSSedAR4gGAVa7O27ec6uiZR3r0qx5ZBSeg7xrZtFQwPvcWvWdPdnKDSIserjJ+ue33+hr7iuuLQ==" Jun 15 00:47:20 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:20 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:47:20 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:47:20 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:47:20 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:47:20 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:20 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:20 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:47:20 perivolumio go-librespot[1720]: time="2025-06-15T00:47:20-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:20 perivolumio go-librespot[1720]: time="2025-06-15T00:47:20-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:20 perivolumio go-librespot[1720]: time="2025-06-15T00:47:20-04:00" level=debug msg="completed challenge" Jun 15 00:47:20 perivolumio go-librespot[1720]: time="2025-06-15T00:47:20-04: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 " Jun 15 00:47:20 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:20 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:20 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:20 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:21 perivolumio volumio[866]: info: Reading package lists... Jun 15 00:47:22 perivolumio volumio[866]: info: Building dependency tree... Jun 15 00:47:22 perivolumio volumio[866]: info: Reading state information... Jun 15 00:47:22 perivolumio volumio[866]: info: 11 packages can be upgraded. Run 'apt list --upgradable' to see them. Jun 15 00:47:22 perivolumio sudo[1510]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:22 perivolumio sudo[1744]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt -y install python3-aiohttp python3-pip Jun 15 00:47:22 perivolumio sudo[1744]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:23 perivolumio volumio[866]: info: BOOT COMPLETED Jun 15 00:47:23 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:23 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jun 15 00:47:23 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:23 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:23 perivolumio go-librespot[1747]: go-librespot daemon starting... Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="app state loaded" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=info msg="zeroconf server listening on port 44935" Jun 15 00:47:23 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="new websocket client" Jun 15 00:47:23 perivolumio volumio[866]: info: Connection to go-librespot Websocket established Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="obtained new client token: AABUG3ZuWo4q8HKBbXvENjNOPuBSO8zpDGNyeX4UXhxBXg4exYChhAzE1O2Y4y2sYB+FRGN1fpN82vWuO8K+3tf2ZmMTsJHXU1Auu05JhyARYXBcR5W4BZZMpOEonSForcBcJRkP4vMybxu101KgbcjHqcLXvIJXg5DR9MoZxgND2W5elnXIJ0Dugvkdt+Q0zqv3UnUQmJGnnNx+x/NqzyC9+yJJ//DJSoL2d4q4Cw6+K8KQ8zVSdsI=" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04:00" level=debug msg="completed challenge" Jun 15 00:47:23 perivolumio go-librespot[1747]: time="2025-06-15T00:47:23-04: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 " Jun 15 00:47:23 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:23 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:23 perivolumio volumio[866]: info: Connection to go-librespot Websocket closed Jun 15 00:47:25 perivolumio volumio[866]: info: Reading package lists... Jun 15 00:47:25 perivolumio volumio[866]: info: Building dependency tree... Jun 15 00:47:25 perivolumio volumio[866]: info: Reading state information... Jun 15 00:47:26 perivolumio volumio[866]: info: Getting Spotify volume Jun 15 00:47:26 perivolumio volumio[866]: (node:866) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:26 perivolumio volumio[866]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 15 00:47:26 perivolumio volumio[866]: (Use `node --trace-warnings ...` to show where the warning was created) Jun 15 00:47:26 perivolumio volumio[866]: (node:866) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Jun 15 00:47:26 perivolumio volumio[866]: (node:866) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Jun 15 00:47:26 perivolumio volumio[866]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 15 00:47:26 perivolumio sudo[1744]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:26 perivolumio sudo[1797]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C / Jun 15 00:47:26 perivolumio sudo[1797]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:26 perivolumio volumio[866]: info: python3-aiohttp is already the newest version (3.5.1-1+deb10u1). Jun 15 00:47:26 perivolumio sudo[1797]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:26 perivolumio volumio[866]: info: python3-pip is already the newest version (18.1-5+rpt1). Jun 15 00:47:26 perivolumio volumio[866]: info: 0 upgraded, 0 newly installed, 0 to remove and 13 not upgraded. Jun 15 00:47:26 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:26 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:26 perivolumio volumio[866]: info: lib/systemd/system/fusiondsp.service Jun 15 00:47:26 perivolumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Jun 15 00:47:26 perivolumio volumio[866]: SPOTIFY: SPOTIFY VOLUME undefined Jun 15 00:47:26 perivolumio volumio[866]: SPOTIFY: VOLUMIO VOLUME 33 Jun 15 00:47:26 perivolumio volumio[866]: info: Aligning Spotify Volume to Volumio Volume Jun 15 00:47:26 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:26 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:26 perivolumio volumio[866]: info: Setting Spotify Volume from Volumio: 33 Jun 15 00:47:26 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:26 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:26 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:26 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jun 15 00:47:26 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:26 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:26 perivolumio go-librespot[1803]: go-librespot daemon starting... Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=debug msg="app state loaded" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 15 00:47:26 perivolumio go-librespot[1803]: time="2025-06-15T00:47:26-04:00" level=info msg="zeroconf server listening on port 37023" Jun 15 00:47:27 perivolumio go-librespot[1803]: time="2025-06-15T00:47:27-04:00" level=debug msg="obtained new client token: AAAnFSerM2uzNxnMQWrPr37a2eZ2ZRdw8XJId0+JlQnhqCrkj5cLeLIHY5NL/uNdcHmnVOUJs0vZTIJ3mkP+5ipzsn7PQZ390hda/l45ip+9iiLlfxeEVkv1J24lWkZ+iVNG/2ED0WHfui+vOckGXxR+eSj6SL7fzKNPiip4G2BcqC3mEJqDmI60YqB35Jxw4eFOsJorfgwOpyhit4r6Qn3fkJGLBw+TsiKqOD91nXNXUDX2aTCY3mW5AA==" Jun 15 00:47:27 perivolumio go-librespot[1803]: time="2025-06-15T00:47:27-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:27 perivolumio go-librespot[1803]: time="2025-06-15T00:47:27-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:27 perivolumio go-librespot[1803]: time="2025-06-15T00:47:27-04:00" level=debug msg="completed challenge" Jun 15 00:47:27 perivolumio go-librespot[1803]: time="2025-06-15T00:47:27-04: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 " Jun 15 00:47:27 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:27 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:27 perivolumio volumio[866]: info: MiniUnz 1.01b, demo of zLib + Unz package written by Gilles Vollant Jun 15 00:47:27 perivolumio volumio[866]: info: more info at http://www.winimage.com/zLibDll/unzip.html Jun 15 00:47:27 perivolumio volumio[866]: info: Jun 15 00:47:27 perivolumio volumio[866]: info: cgui-1.0.0.zip opened Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/LICENSE.txt Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/README.md Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/build/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/robots.txt Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/logo512.png Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/asset-manifest.json Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/index.html Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/.put_statics_here Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/favicon.ico Jun 15 00:47:27 perivolumio sudo[1812]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/logo192.png Jun 15 00:47:27 perivolumio sudo[1812]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/.xdp-css-variables-1.css-PvrWoX Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/manifest.json Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/css-variables.css Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/precache-manifest.76db5aad1647230454f47b1e22783b54.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/service-worker.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/precache-manifest.5e6c675b70ef6a3fe73d0209febfe347.js Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/build/static/ Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/build/static/css/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css.map Jun 15 00:47:27 perivolumio sudo[1812]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/main.1503f6cd.css.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/main.1503f6cd.css Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/build/static/media/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/media/camilladsp.95719842.svg Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/media/camilladsp.4767ea4ad3510467418b818dc677a87e.svg Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/build/static/js/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.71e11955.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.LICENSE.txt Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.71e11955.js.LICENSE.txt Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.71e11955.js.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.map Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.LICENSE.txt Jun 15 00:47:27 perivolumio sudo[1814]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/config/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/config/camillagui.yml Jun 15 00:47:27 perivolumio sudo[1814]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/config/.xdp-css-variables-1.css-ppBDuX Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/config/gui-config.yml Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/backend/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/filters_test.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/version.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/filters.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/settings.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/views.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/filterdefaults.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__init__.py Jun 15 00:47:27 perivolumio volumio[866]: info: creating directory: cgui/backend/__pycache__/ Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/filterdefaults.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/views.cpython-37.pyc Jun 15 00:47:27 perivolumio sudo[1814]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/settings.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/__init__.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/routes.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/filemanagement.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/filters.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/__pycache__/version.cpython-37.pyc Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/routes.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/backend/filemanagement.py Jun 15 00:47:27 perivolumio volumio[866]: info: extracting: cgui/main.py Jun 15 00:47:27 perivolumio sudo[1816]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip Jun 15 00:47:27 perivolumio sudo[1816]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:27 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 15 00:47:27 perivolumio sudo[1816]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:28 perivolumio volumio[866]: SPOTIFY: SETTING SPOTIFY VOLUME 33 Jun 15 00:47:28 perivolumio volumio[866]: info: Sending Spotify command with payload to local API: /player/volume Jun 15 00:47:28 perivolumio volumio[866]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:29 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:29 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:30 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:30 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jun 15 00:47:30 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:30 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:30 perivolumio go-librespot[1833]: go-librespot daemon starting... Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="app state loaded" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=info msg="zeroconf server listening on port 33353" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="obtained new client token: AACWq2z1dJIZvBmhZaOQTroWU9RBgENhBwpWR9QRT/ptrvCZho2s7e08/nUGasPkwTGpYLOjz4pukwW8PPhjWiEUjDm+5VhTLRPHZpcP7teQ1IdyW5//+U9wDUfKR1oB3mluAH1yrPoczAFOXHHJ2+2wyJelGVxFJwt3hd3Tjr09kquSMU0QQoDnx3w4pD3mF63378qYHfkteNBL7SXS2HOLVf+laIJj4KhIseY6nEA2XIXAx7fKqVo=" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04:00" level=debug msg="completed challenge" Jun 15 00:47:30 perivolumio go-librespot[1833]: time="2025-06-15T00:47:30-04: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 " Jun 15 00:47:30 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:30 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:31 perivolumio ntpd[815]: Soliciting pool server 198.46.254.130 Jun 15 00:47:31 perivolumio volumio[866]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/youtube2/volumio/buster/armhf Jun 15 00:47:31 perivolumio ntpd[815]: Soliciting pool server 198.137.202.56 Jun 15 00:47:32 perivolumio ntpd[815]: Soliciting pool server 216.229.4.69 Jun 15 00:47:32 perivolumio volumio[866]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Jun 15 00:47:32 perivolumio volumio[866]: info: Collecting git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 Jun 15 00:47:32 perivolumio volumio[866]: info: Cloning https://github.com/HEnquist/pycamilladsp.git (to revision v1.0.0) to /tmp/pip-req-build-18j3wre5 Jun 15 00:47:32 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:32 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:32 perivolumio volumio[866]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/youtube2/volumio/buster/armhf Jun 15 00:47:32 perivolumio volumio[866]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesYouTube2 Jun 15 00:47:32 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 15 00:47:32 perivolumio volumio[866]: Cannot find translation for source YouTube Music Jun 15 00:47:32 perivolumio volumio[866]: Cannot find translation for source Plex Jun 15 00:47:32 perivolumio volumio[866]: Cannot find translation for source Spotify Jun 15 00:47:32 perivolumio ntpd[815]: Soliciting pool server 198.71.50.75 Jun 15 00:47:32 perivolumio ntpd[815]: Soliciting pool server 66.85.78.80 Jun 15 00:47:33 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:33 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jun 15 00:47:33 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:33 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:33 perivolumio go-librespot[1863]: go-librespot daemon starting... Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=debug msg="app state loaded" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:33 perivolumio go-librespot[1863]: time="2025-06-15T00:47:33-04:00" level=info msg="zeroconf server listening on port 40787" Jun 15 00:47:33 perivolumio ntpd[815]: Soliciting pool server 46.37.96.107 Jun 15 00:47:33 perivolumio ntpd[815]: Soliciting pool server 23.141.40.123 Jun 15 00:47:34 perivolumio go-librespot[1863]: time="2025-06-15T00:47:34-04:00" level=debug msg="obtained new client token: AABlUmmbyNoiLIkM6IYs106eb9zHrGOwJXPNAYjxtBkslxHjgeEJ+7RmTsozG0iZ6BOJ4z6l++E6Gg9IQgadECJBIlM1pcECsOrs3JJmsAa8P1+CvXPgzMRWVjfpK1ZU8vYUe6zJrqfuoy+VfatinzEtn4laSBIN+qe9S+HSHewnwhm1gnz0A8TuEXCuGeHVTecI4NhrrKBMZkc0ZWCfmdijYWxc0mQnB+bThDL/CVLbwD7E9pPJED6qLQ==" Jun 15 00:47:34 perivolumio volumio[866]: info: Check plugin dependencies Jun 15 00:47:34 perivolumio go-librespot[1863]: time="2025-06-15T00:47:34-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:34 perivolumio ntpd[815]: Soliciting pool server 192.155.94.72 Jun 15 00:47:34 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 15 00:47:34 perivolumio volumio[866]: info: Rename folder Jun 15 00:47:34 perivolumio go-librespot[1863]: time="2025-06-15T00:47:34-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:34 perivolumio go-librespot[1863]: time="2025-06-15T00:47:34-04:00" level=debug msg="completed challenge" Jun 15 00:47:34 perivolumio volumio[866]: info: Folder /tmp/downloaded_plugin.zip removed Jun 15 00:47:34 perivolumio volumio[866]: info: Move to category Jun 15 00:47:34 perivolumio go-librespot[1863]: time="2025-06-15T00:47:34-04: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 " Jun 15 00:47:34 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:34 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:34 perivolumio ntpd[815]: Soliciting pool server 144.202.0.197 Jun 15 00:47:34 perivolumio ntpd[815]: Soliciting pool server 74.208.14.149 Jun 15 00:47:35 perivolumio ntpd[815]: Soliciting pool server 192.48.105.15 Jun 15 00:47:35 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:35 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:35 perivolumio ntpd[815]: Soliciting pool server 208.67.75.242 Jun 15 00:47:35 perivolumio ntpd[815]: Soliciting pool server 5.161.111.190 Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 15 00:47:36 perivolumio volumio[866]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 15 00:47:36 perivolumio volumio[866]: info: Received Get System Version Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 15 00:47:36 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:47:36 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:36 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:36 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:47:36 perivolumio ntpd[815]: Soliciting pool server 129.250.35.250 Jun 15 00:47:36 perivolumio ntpd[815]: Soliciting pool server 50.251.160.20 Jun 15 00:47:37 perivolumio volumio[866]: info: Checking if install.sh is present Jun 15 00:47:37 perivolumio volumio[866]: info: Executing install.sh Jun 15 00:47:37 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:37 perivolumio sudo[1885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/youtube2/install.sh Jun 15 00:47:37 perivolumio volumio[866]: info: YouTube2 plugin installed Jun 15 00:47:37 perivolumio volumio[866]: Plugin install end detected on script Jun 15 00:47:37 perivolumio volumio[866]: info: YouTube2 plugin installed Jun 15 00:47:37 perivolumio volumio[866]: Plugin install end detected on script Jun 15 00:47:37 perivolumio volumio[866]: info: Install script completed Jun 15 00:47:37 perivolumio volumio[866]: info: Done installing plugin. Jun 15 00:47:37 perivolumio volumio[866]: info: Enabling plugin youtube2 Jun 15 00:47:37 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jun 15 00:47:37 perivolumio sudo[1885]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:37 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:37 perivolumio sudo[1885]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:37 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:37 perivolumio go-librespot[1882]: go-librespot daemon starting... Jun 15 00:47:37 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:37 perivolumio volumio[866]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.61","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":true,"enabled":true,"active":false},{"prettyName":"miniDLNA","name":"minidlna","category":"music_service","version":"3.1.12","icon":"fa-share-alt","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Plex and PlexAmp","name":"plexamp","category":"music_service","version":"1.0.3","icon":"fa-server","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.5","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"1.4.2","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.2.3","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Music","name":"ytmusic","category":"music_service","version":"1.3.1","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"System information","name":"Systeminfo","category":"user_interface","version":"3.0.6","icon":"fa-info-circle","isManuallyInstalled":false,"enabled":true,"active":true}] Jun 15 00:47:37 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 15 00:47:37 perivolumio volumio[866]: info: Folder /tmp/plugins removed Jun 15 00:47:37 perivolumio volumio[866]: info: Folder /tmp/downloaded_plugin.zip removed Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="app state loaded" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:37 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:37 perivolumio volumio[866]: info: Folder /data/temp removed Jun 15 00:47:37 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:47:37 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=info msg="zeroconf server listening on port 45107" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="obtained new client token: AAC+cKDB5if6Oozhvg4MTFpHwqfEUNUhGf/a5CQYJhask08ogeraA4vh4JtuvEkK4dXWc7pKugsImND4PFBmA6W5pxvOHQbOBpM6Cymq2PqyXr72pBCa2grIno/BNGbCDoFYAKrKLR2Gh4TQLsTHjx87Bx+80Czj8ZATHmOmZ9uvhwkpW1vL7TuAd+ojjAE9WwNR7D+wJbYFIpDcm8/b9OA9cEd5SaGKvdkmPOqYE7/BOCnje0q2U1w=" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04:00" level=debug msg="completed challenge" Jun 15 00:47:37 perivolumio go-librespot[1882]: time="2025-06-15T00:47:37-04: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 " Jun 15 00:47:37 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:37 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:37 perivolumio ntpd[815]: Soliciting pool server 23.168.24.210 Jun 15 00:47:37 perivolumio ntpd[815]: Soliciting pool server 2001:19f0:ac02:88a:5400:4ff:fe87:24e1 Jun 15 00:47:38 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:38 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:40 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:40 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jun 15 00:47:40 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:40 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:40 perivolumio go-librespot[1911]: go-librespot daemon starting... Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=debug msg="app state loaded" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:40 perivolumio go-librespot[1911]: time="2025-06-15T00:47:40-04:00" level=info msg="zeroconf server listening on port 44863" Jun 15 00:47:41 perivolumio go-librespot[1911]: time="2025-06-15T00:47:41-04:00" level=debug msg="obtained new client token: AAA8BKPI3Sf7CVwNDXn8ZH4nHfWZUWJ8k9A9z482ojWMwtoc1sSQdJ85yzDFxx8zzuaaEhMfWj4DhGh6jmVU56eexrgKfx02koggMyqHvOESQdl77q8H9/xu9trntz+SgwrmIldV51uLmA29pxZc2X/7JbEufZv1DiFRUGhMWycSypPdkU0SGAijmsMElVPBNkU9VgdmawyBTQMNSZqMzhzL7RNM2r8IMillLaio7fbfvNRrC+rOTYyIyA==" Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fd99af15 does not match aorg 0000000000.00000000 from server@23.168.24.210 xmt 0xebf8ceed.b571befa Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fda2a7d2 does not match aorg 0000000000.00000000 from server@66.85.78.80 xmt 0xebf8ceed.b57a433a Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fd9db807 does not match aorg 0000000000.00000000 from server@50.251.160.20 xmt 0xebf8ceed.b50e7114 Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fd9fdf1b does not match aorg 0000000000.00000000 from server@74.208.14.149 xmt 0xebf8ceed.b705212c Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fda1b43d does not match aorg 0000000000.00000000 from server@23.141.40.123 xmt 0xebf8ceed.bb2e18ce Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fda3a603 does not match aorg 0000000000.00000000 from server@198.137.202.56 xmt 0xebf8ceed.b9772125 Jun 15 00:47:41 perivolumio ntpd[815]: receive: Unexpected origin timestamp 0xebf8ceec.fda0be2e does not match aorg 0000000000.00000000 from server@46.37.96.107 xmt 0xebf8ceed.ba854fc4 Jun 15 00:47:41 perivolumio go-librespot[1911]: time="2025-06-15T00:47:41-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Jun 15 00:47:41 perivolumio go-librespot[1911]: time="2025-06-15T00:47:41-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jun 15 00:47:41 perivolumio go-librespot[1911]: time="2025-06-15T00:47:41-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:41 perivolumio go-librespot[1911]: time="2025-06-15T00:47:41-04:00" level=debug msg="completed challenge" Jun 15 00:47:41 perivolumio go-librespot[1911]: time="2025-06-15T00:47:41-04: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 " Jun 15 00:47:41 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:41 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:42 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:42 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:44 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:44 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jun 15 00:47:44 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:44 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:44 perivolumio go-librespot[1942]: go-librespot daemon starting... Jun 15 00:47:44 perivolumio go-librespot[1942]: time="2025-06-15T00:47:44-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:44 perivolumio go-librespot[1942]: time="2025-06-15T00:47:44-04:00" level=debug msg="app state loaded" Jun 15 00:47:44 perivolumio go-librespot[1942]: time="2025-06-15T00:47:44-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:44 perivolumio go-librespot[1942]: time="2025-06-15T00:47:44-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=info msg="zeroconf server listening on port 45121" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="obtained new client token: AADBWBqkXTni97lKOaMx4e3/BeiFpGhPpdvSLhOVFqQSdvnyGdiJ9nJIScFMC5sgSFVSP4kAj49kAiHZr87Sieygt3PDGdIrJE9bKFSqoqMnxbXsRlk3S5uJorE142ZBA0ErxMraMcX7o2zwKdfJ2Gw3rn7VOGQUVO0zznEF84/JQHVY7Q0Xm6PiQlhp4N9oKIvHJ/UWOYeQZFG3VWOIDBTh1DWu1ld2p9z2CkGEafmw1krcH7JEDFs=" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04:00" level=debug msg="completed challenge" Jun 15 00:47:45 perivolumio go-librespot[1942]: time="2025-06-15T00:47:45-04: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 " Jun 15 00:47:45 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:45 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:45 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:45 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:45 perivolumio sudo[1961]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params Jun 15 00:47:45 perivolumio sudo[1961]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:45 perivolumio sudo[1961]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:45 perivolumio sudo[1963]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params Jun 15 00:47:45 perivolumio sudo[1963]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:45 perivolumio sudo[1963]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:46 perivolumio sudo[1965]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc Jun 15 00:47:46 perivolumio sudo[1965]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:47 perivolumio sudo[1965]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:47 perivolumio sudo[1477]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:47 perivolumio volumio[866]: info: Install script completed Jun 15 00:47:47 perivolumio volumio[866]: info: Done installing plugin. Jun 15 00:47:47 perivolumio volumio[866]: info: Enabling plugin fusiondsp Jun 15 00:47:47 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:47 perivolumio volumio[866]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.61","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":true,"enabled":true,"active":false},{"prettyName":"miniDLNA","name":"minidlna","category":"music_service","version":"3.1.12","icon":"fa-share-alt","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Plex and PlexAmp","name":"plexamp","category":"music_service","version":"1.0.3","icon":"fa-server","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.5","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"1.4.2","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.2.3","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Music","name":"ytmusic","category":"music_service","version":"1.3.1","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"System information","name":"Systeminfo","category":"user_interface","version":"3.0.6","icon":"fa-info-circle","isManuallyInstalled":false,"enabled":true,"active":true}] Jun 15 00:47:47 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 15 00:47:47 perivolumio volumio[866]: info: Folder /data/temp removed Jun 15 00:47:47 perivolumio volumio[866]: info: Folder /tmp/plugins removed Jun 15 00:47:47 perivolumio volumio[866]: info: Folder /tmp/downloaded_plugin.zip removed Jun 15 00:47:47 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 15 00:47:48 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:48 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jun 15 00:47:48 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:48 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:48 perivolumio go-librespot[1972]: go-librespot daemon starting... Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="app state loaded" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=info msg="zeroconf server listening on port 36405" Jun 15 00:47:48 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="new websocket client" Jun 15 00:47:48 perivolumio volumio[866]: info: Connection to go-librespot Websocket established Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="obtained new client token: AAD09D568S9qpXzVXZHxfQSEjMuw+vh3IS5rVZF8agLFXuGPaA01Sj0Jqk6iD+pJxXiYocy67eiOXlmoySAaaUqa5+dNcAXAQg3jHFP5BomHfUK11+WF5MVx36X6oOaNWv/3Df4ubGMur0AgJ6WYtEAz2oovlSD3GDj7smntQ0oZv5UNB2kWbNNnsTFfW6vCx4xPnHrt0gSwvPLOUfnDDz63sYvMetc0AdwwADkEmqUylO6Z2coh5KPWlA==" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04:00" level=debug msg="completed challenge" Jun 15 00:47:48 perivolumio go-librespot[1972]: time="2025-06-15T00:47:48-04: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 " Jun 15 00:47:48 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:48 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:48 perivolumio volumio[866]: info: Connection to go-librespot Websocket closed Jun 15 00:47:51 perivolumio volumio[866]: info: Getting Spotify volume Jun 15 00:47:51 perivolumio volumio[866]: (node:866) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:51 perivolumio volumio[866]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 15 00:47:51 perivolumio volumio[866]: (node:866) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Jun 15 00:47:51 perivolumio volumio[866]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 15 00:47:51 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:51 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:51 perivolumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Jun 15 00:47:51 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:51 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:51 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:51 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jun 15 00:47:51 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:51 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:51 perivolumio go-librespot[1994]: go-librespot daemon starting... Jun 15 00:47:51 perivolumio go-librespot[1994]: time="2025-06-15T00:47:51-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:51 perivolumio go-librespot[1994]: time="2025-06-15T00:47:51-04:00" level=debug msg="app state loaded" Jun 15 00:47:51 perivolumio go-librespot[1994]: time="2025-06-15T00:47:51-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:51 perivolumio go-librespot[1994]: time="2025-06-15T00:47:51-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=info msg="zeroconf server listening on port 34603" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="obtained new client token: AADQwxhYdaenu+C2iYnausjIiTsVyUjKA750AAyzyspWzTQKSS66CU4Dz5QC4aDt5CcVtFH1UqGrHKyzM3eBCnaR8ijYs07Eb7IIt9mizmFMboY29Tlr2Z64vJ4sL2VmHt9kUp7p3nZLitksLnBnq3PnheXZnZK/w2caJyGLjpgLC/Ne3QKuz8Kpxlx4kkxBfCWtI8P+ITSZIt25A1NmNfA3I2maXju0N8WipmZptxC1BHEVcEp4tCU=" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04:00" level=debug msg="completed challenge" Jun 15 00:47:52 perivolumio go-librespot[1994]: time="2025-06-15T00:47:52-04: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 " Jun 15 00:47:52 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:52 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:54 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:54 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:55 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:55 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jun 15 00:47:55 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:55 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:55 perivolumio go-librespot[2003]: go-librespot daemon starting... Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="app state loaded" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=info msg="zeroconf server listening on port 45649" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="obtained new client token: AAA+SeLyE670sxFErUiFcTwZ+q/wNsmm83YKGgsWfS80MQmdGkTj3jTTjm/sDZHLKcIvHi0AH3TfLyfDPqRmhTmr4/G68sqBCc7Y2FuLa+b3kxUWZB42MeS+kg0Pcg2qm60LYd1oQDEC7ijgzVaMT0g6htJsvrtSQ56VjvvwaFtXlqXkGCZ6kfGMpqT0B9HxNwQ9e4snl2+UXUjmynVlCoDKjIS5GAERncSy9TLPiZT2LBkkOmIXcBpctQ==" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04:00" level=debug msg="completed challenge" Jun 15 00:47:55 perivolumio go-librespot[2003]: time="2025-06-15T00:47:55-04: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 " Jun 15 00:47:55 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:55 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:57 perivolumio sudo[2012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 15 00:47:57 perivolumio sudo[2012]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:57 perivolumio sudo[2012]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:57 perivolumio sudo[2015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 15 00:47:57 perivolumio sudo[2015]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:57 perivolumio sudo[2015]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:57 perivolumio volumio[866]: verbose: New Socket.io Connection to 192.168.21.51 from 192.168.21.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 15 00:47:57 perivolumio sudo[2018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 15 00:47:57 perivolumio sudo[2018]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:57 perivolumio sudo[2018]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:57 perivolumio sudo[2020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 15 00:47:57 perivolumio sudo[2020]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:47:57 perivolumio sudo[2020]: pam_unix(sudo:session): session closed for user root Jun 15 00:47:57 perivolumio volumio[866]: verbose: New Socket.io Connection to 192.168.21.51 from 192.168.21.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jun 15 00:47:57 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:47:57 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetVisibleSources Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:57 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 15 00:47:57 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:47:57 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:57 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:57 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:57 perivolumio volumio[866]: info: Listing playlists Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 15 00:47:57 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:47:57 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:47:58 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:47:58 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:58 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:58 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:47:58 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jun 15 00:47:58 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:47:58 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:47:58 perivolumio go-librespot[2023]: go-librespot daemon starting... Jun 15 00:47:58 perivolumio go-librespot[2023]: time="2025-06-15T00:47:58-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:47:58 perivolumio go-librespot[2023]: time="2025-06-15T00:47:58-04:00" level=debug msg="app state loaded" Jun 15 00:47:58 perivolumio go-librespot[2023]: time="2025-06-15T00:47:58-04:00" level=debug msg="stored credentials not found" Jun 15 00:47:58 perivolumio go-librespot[2023]: time="2025-06-15T00:47:58-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=info msg="zeroconf server listening on port 35433" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="obtained new client token: AADb6KSqqG+uRi3m/o8do8gDFQyE8MfTXz66sqg++b5s4U3HIj7qBVrGDHV4/pAg5AegteQOVF07bRfW3GVERfp3mG1jDlXDiLwZrVlI3Xnp6YTieNDeQ+Jq84yOkF31cG9K+pIHqdSlpGYdXW2nw2Jl0oJjZwKgttE53dUI+NY7/hVFHmZAth9NnxFVqczwsMdL1pPTnY11yoxvo/kCf8eJG6nGlWw1O4jzuEqLAtcuperjcWpRZXA=" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="completed keyexchange" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04:00" level=debug msg="completed challenge" Jun 15 00:47:59 perivolumio go-librespot[2023]: time="2025-06-15T00:47:59-04: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 " Jun 15 00:47:59 perivolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 15 00:47:59 perivolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 15 00:47:59 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 15 00:47:59 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:47:59 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:47:59 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:47:59 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:47:59 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:47:59 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:47:59 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:47:59 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:48:00 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:48:00 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:48:00 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:48:00 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:48:00 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:48:00 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:48:00 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:48:00 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:48:00 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:48:00 perivolumio volumio[866]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 15 00:48:01 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 15 00:48:01 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 15 00:48:01 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:48:01 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:48:01 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:48:02 perivolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 15 00:48:02 perivolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jun 15 00:48:02 perivolumio systemd[1]: Stopped go-librespot Daemon. Jun 15 00:48:02 perivolumio systemd[1]: Started go-librespot Daemon. Jun 15 00:48:02 perivolumio go-librespot[2045]: go-librespot daemon starting... Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=info msg="running go-librespot 0.2.0" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="app state loaded" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="stored credentials not found" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=info msg="zeroconf server listening on port 33275" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="obtained new client token: AAD3ZBYfjOX82I/xm2cuMNVwmK3nVvNZlAM8lNTX+U06AhCBiGz7KnWjRBqRnp5pJkNgS7fOrT7lDNiNKDQ5uL03J2ZvPLOIkrLMCyDM2R1rWp/Od4AEO6btbGTeGYJecjSaUAiLFH0iz11fgMjUEIwuwgGDMS5k/NWPhp94yzhKnx0oYLmIA6bNmNnBDxc4BW0IZYy2NFqhHsAnev9N6TrEw59QQ171m8XOlumiyjDVmjKt5cjYI3yFjA==" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Jun 15 00:48:02 perivolumio go-librespot[2045]: time="2025-06-15T00:48:02-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jun 15 00:48:03 perivolumio volumio[866]: info: Initializing connection to go-librespot Websocket Jun 15 00:48:03 perivolumio go-librespot[2045]: time="2025-06-15T00:48:03-04:00" level=debug msg="new websocket client" Jun 15 00:48:03 perivolumio volumio[866]: info: Connection to go-librespot Websocket established Jun 15 00:48:06 perivolumio volumio[866]: info: Getting Spotify volume Jun 15 00:48:06 perivolumio volumio[866]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jun 15 00:48:06 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:48:06 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:48:06 perivolumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Jun 15 00:48:08 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 15 00:48:13 perivolumio volumio[866]: info: Enabling plugin youtube2 Jun 15 00:48:13 perivolumio volumio[866]: info: Loading plugin "youtube2"... Jun 15 00:48:13 perivolumio volumio[866]: info: PLUGIN START: youtube2 Jun 15 00:48:13 perivolumio volumio[866]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 15 00:48:13 perivolumio volumio[866]: info: [1749962893777] CoreMusicLibrary::Adding element YouTube2 Jun 15 00:48:13 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 15 00:48:13 perivolumio volumio[866]: Cannot find translation for source YouTube Music Jun 15 00:48:13 perivolumio volumio[866]: Cannot find translation for source Plex Jun 15 00:48:13 perivolumio volumio[866]: Cannot find translation for source Spotify Jun 15 00:48:13 perivolumio volumio[866]: Cannot find translation for source YouTube2 Jun 15 00:48:13 perivolumio volumio[866]: info: Done. Jun 15 00:48:13 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:48:13 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:48:13 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:48:14 perivolumio volumio[866]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesYouTube2 Jun 15 00:48:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source YouTube Music Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source Plex Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source Spotify Jun 15 00:48:14 perivolumio volumio[866]: info: Disabling plugin youtube2 Jun 15 00:48:14 perivolumio volumio[866]: info: Done. Jun 15 00:48:14 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:48:14 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:48:14 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:48:14 perivolumio volumio[866]: info: Enabling plugin youtube2 Jun 15 00:48:14 perivolumio volumio[866]: info: Loading plugin "youtube2"... Jun 15 00:48:14 perivolumio volumio[866]: info: PLUGIN START: youtube2 Jun 15 00:48:14 perivolumio volumio[866]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 15 00:48:14 perivolumio volumio[866]: info: [1749962894697] CoreMusicLibrary::Adding element YouTube2 Jun 15 00:48:14 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source YouTube Music Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source Plex Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source Spotify Jun 15 00:48:14 perivolumio volumio[866]: Cannot find translation for source YouTube2 Jun 15 00:48:14 perivolumio volumio[866]: info: Done. Jun 15 00:48:14 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:48:14 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:48:14 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:48:16 perivolumio volumio[866]: info: Enabling plugin fusiondsp Jun 15 00:48:16 perivolumio volumio[866]: info: Loading plugin "fusiondsp"... Jun 15 00:48:16 perivolumio volumio[866]: info: Applying required configuration parameters for plugin fusiondsp Jun 15 00:48:16 perivolumio volumio[866]: info: Preparing to generate the ALSA configuration file Jun 15 00:48:16 perivolumio volumio[866]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 15 00:48:16 perivolumio volumio[866]: info: Reading ALSA contributions from plugins. Jun 15 00:48:16 perivolumio volumio[866]: info: Asound.conf file unchanged, so no further update is needed Jun 15 00:48:16 perivolumio volumio[866]: info: Output device has changed, restarting MPD Jun 15 00:48:16 perivolumio sudo[2071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 15 00:48:16 perivolumio sudo[2071]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio sudo[2071]: pam_unix(sudo:session): session closed for user root Jun 15 00:48:16 perivolumio volumio[866]: info: Output device has changed, restarting Shairport Sync Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:48:16 perivolumio sudo[2074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 15 00:48:16 perivolumio sudo[2074]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio systemd[1]: Stopping Music Player Daemon... Jun 15 00:48:16 perivolumio systemd[1]: mpd.service: Succeeded. Jun 15 00:48:16 perivolumio systemd[1]: Stopped Music Player Daemon. Jun 15 00:48:16 perivolumio volumio[866]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 15 00:48:16 perivolumio volumio[866]: info: PLUGIN START: fusiondsp Jun 15 00:48:16 perivolumio volumio[866]: info: Loading i18n strings for locale en Jun 15 00:48:16 perivolumio volumio[866]: info: Plugin plexamp has duplicated i18n key SAVE. It is ignored. Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:48:16 perivolumio volumio[866]: info: FusionDsp - mixtype--------------------- Hardware Jun 15 00:48:16 perivolumio volumio[866]: info: Preparing to generate the ALSA configuration file Jun 15 00:48:16 perivolumio volumio[866]: info: Done. Jun 15 00:48:16 perivolumio volumio[866]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 15 00:48:16 perivolumio volumio[866]: info: Reading ALSA contributions from plugins. Jun 15 00:48:16 perivolumio volumio[866]: info: MPD Permissions set Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:48:16 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:48:16 perivolumio systemd[1]: Starting Music Player Daemon... Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:48:16 perivolumio volumio[866]: info: FusionDsp - Jun 15 00:48:16 perivolumio sudo[2079]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 15 00:48:16 perivolumio sudo[2079]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio sudo[2079]: pam_unix(sudo:session): session closed for user root Jun 15 00:48:16 perivolumio volumio[866]: info: Starting Shairport Sync Jun 15 00:48:16 perivolumio volumio[866]: info: FusionDsp - undefined Jun 15 00:48:16 perivolumio sudo[2087]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 15 00:48:16 perivolumio sudo[2087]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 15 00:48:16 perivolumio systemd[1]: shairport-sync.service: Succeeded. Jun 15 00:48:16 perivolumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 15 00:48:16 perivolumio volumio[866]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 15 00:48:16 perivolumio volumio[866]: info: Received Get System Version Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 15 00:48:16 perivolumio volumio[866]: info: Received Get System Info Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 15 00:48:16 perivolumio volumio[866]: info: Discovery: Getting this device information Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::volumioGetState Jun 15 00:48:16 perivolumio volumio[866]: info: CorePlayQueue::getTrack 0 Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 15 00:48:16 perivolumio volumio[866]: info: Asound.conf file unchanged, so no further update is needed Jun 15 00:48:16 perivolumio volumio[866]: info: Output device has changed, restarting MPD Jun 15 00:48:16 perivolumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 15 00:48:16 perivolumio sudo[2087]: pam_unix(sudo:session): session closed for user root Jun 15 00:48:16 perivolumio sudo[2091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 15 00:48:16 perivolumio sudo[2091]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio sudo[2091]: pam_unix(sudo:session): session closed for user root Jun 15 00:48:16 perivolumio volumio[866]: info: Output device has changed, restarting Shairport Sync Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 15 00:48:16 perivolumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 15 00:48:16 perivolumio sudo[2096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 15 00:48:16 perivolumio sudo[2096]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 15 00:48:16 perivolumio systemd[1]: mpd.service: Succeeded. Jun 15 00:48:16 perivolumio systemd[1]: Stopped Music Player Daemon. Jun 15 00:48:16 perivolumio systemd[1]: Starting Music Player Daemon... Jun 15 00:48:16 perivolumio volumio[866]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 15 00:48:16 perivolumio volumio[866]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 15 00:48:16 perivolumio volumio[866]: TypeError: Cannot read property 'off' of undefined Jun 15 00:48:16 perivolumio volumio[866]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15) Jun 15 00:48:16 perivolumio volumio[866]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Jun 15 00:48:16 perivolumio volumio[866]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Jun 15 00:48:16 perivolumio volumio[866]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29) Jun 15 00:48:16 perivolumio volumio[866]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1401:47) Jun 15 00:48:16 perivolumio volumio[866]: at Socket.emit (events.js:315:20) Jun 15 00:48:16 perivolumio volumio[866]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jun 15 00:48:16 perivolumio volumio[866]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jun 15 00:48:16 perivolumio volumio[866]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 15 00:48:16 perivolumio sudo[2101]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 15 00:48:16 perivolumio sudo[2101]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 15 00:48:16 perivolumio sudo[2101]: pam_unix(sudo:session): session closed for user root Jun 15 00:48:17 perivolumio sudo[2113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-15 00:47 Jun 15 00:48:17 perivolumio sudo[2113]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"