Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Asound.conf file written Dec 12 17:31:00 gbvpi-bedroom sudo[5476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 17:31:00 gbvpi-bedroom sudo[5476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:00 gbvpi-bedroom sudo[5476]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Output device has changed, restarting MPD Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Output device has changed, restarting Shairport Sync Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:00 gbvpi-bedroom sudo[5482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:31:00 gbvpi-bedroom sudo[5482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:00 gbvpi-bedroom sudo[5482]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:00 gbvpi-bedroom sudo[5484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:31:00 gbvpi-bedroom sudo[5484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: MRS: Pushing multiroomSync output for this device Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: MRS: Pushing multiroomSync output Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding audio output: Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding audio output: Dec 12 17:31:00 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.874s CPU time. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:00 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.49795 Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding METAVOLUMIO REST API Endpoints Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Preparing CD Folders Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding CD REST API Endpoints Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Starting UDEV Watcher for CD Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: Detecting CD presence with UDEV Dec 12 17:31:00 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 12 17:31:00 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.49795 disconnected from D-Bus Dec 12 17:31:00 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 17:31:00 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 17:31:00 gbvpi-bedroom sudo[5499]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 17:31:00 gbvpi-bedroom sudo[5499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 17:31:00 gbvpi-bedroom sudo[5499]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:01 gbvpi-bedroom mpd[5504]: 2025-12-12T17:31:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 17:31:01 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 17:31:01 gbvpi-bedroom sudo[5484]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Dec 12 17:31:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:02 gbvpi-bedroom go-librespot[5507]: go-librespot daemon starting... Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=debug msg="app state loaded" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05: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]" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05: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]" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05: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]" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=info msg="zeroconf server listening on port 41271" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=debug msg="obtained new client token: AAB68JRr/bXmykjwcVvJxgDUUrxF/i5inptYj6rrjC8x0NdHvDEFv7sWv1eBidllio07FVAnNWR+QS8zs7lE2KlmZbrcNUZdi8IMQubIV0tFsk0Uhyfdw0bHqA8JXWOeZWjar7mMWO862SUenUrwweeCg7EIFcrR+qKMWW2gVbRCY40g7OU0sXA1WW8ap+H5loXBYgMq9lRhKtVjG2mZZTVyKJ/hzLiUXnV7jfJJQLBL1P4u49Hrk0axmg==" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05: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" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=debug msg="completed challenge" Dec 12 17:31:02 gbvpi-bedroom go-librespot[5508]: time="2025-12-12T17:31:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding inputs REST Endpoints Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Scanning Audio Inputs Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Checking against Known Cards name Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding Server instance for streaming Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: error: Hi Res Audio Failed Login: Missing Login Data Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 12 17:31:05 gbvpi-bedroom sudo[5533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 12 17:31:05 gbvpi-bedroom sudo[5533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding TIDAL REST API Endpoints Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Stopping AccessToken refresher cron for QOBUZ Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 12 17:31:05 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 5001 (vtcs) with signal SIGKILL. Dec 12 17:31:05 gbvpi-bedroom sudo[5540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 12 17:31:05 gbvpi-bedroom sudo[5540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:05 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 12 17:31:05 gbvpi-bedroom sudo[5533]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:05 gbvpi-bedroom sudo[5540]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: AccessToken refresher cron started for QOBUZ Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding QOBUZ REST API Endpoints Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Updating MyVolumio device info Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Updating MyVolumio device info Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom sudo[5543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 12 17:31:05 gbvpi-bedroom sudo[5543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: MRS: Getting audio outputs on start Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: MRS: Requesting all other devices output Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Successfully Added MyVolumio device Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Successfully Added MyVolumio device Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 12 17:31:05 gbvpi-bedroom qobuz-connect[4961]: 20251212 17:31:05.387 [4961.4961] INFO SampleApp: Stopping Local configuration server Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: MPD Permissions set Dec 12 17:31:05 gbvpi-bedroom sudo[5547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 12 17:31:05 gbvpi-bedroom sudo[5547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom sudo[5547]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: error: updateQueue error: null Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioStop Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreStateMachine::stop Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Starting Shairport Sync Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 12 17:31:05 gbvpi-bedroom sudo[5562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding audio output: Dec 12 17:31:05 gbvpi-bedroom sudo[5562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Adding audio output: Dec 12 17:31:05 gbvpi-bedroom sudo[5564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:05 gbvpi-bedroom sudo[5564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:05 gbvpi-bedroom autossh[4945]: received signal to exit (15) Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Successfully Updated MyVolumio device Dec 12 17:31:05 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Successfully Updated MyVolumio device Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 17:31:05 gbvpi-bedroom sudo[5562]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:05 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:05 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.522s CPU time. Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Remote SSH Started Dec 12 17:31:05 gbvpi-bedroom autossh[5568]: port set to 0, monitoring disabled Dec 12 17:31:05 gbvpi-bedroom autossh[5568]: starting ssh (count 1) Dec 12 17:31:05 gbvpi-bedroom autossh[5568]: ssh child pid is 5571 Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:05 gbvpi-bedroom sudo[5564]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: Shairport-Sync Started Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:05 gbvpi-bedroom volumio[5086]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 17:31:05 gbvpi-bedroom volumiossh-tunnel[5571]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 12 17:31:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Dec 12 17:31:05 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:06 gbvpi-bedroom go-librespot[5587]: go-librespot daemon starting... Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=debug msg="app state loaded" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05: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]" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05: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]" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05: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]" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=info msg="zeroconf server listening on port 41333" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=debug msg="obtained new client token: AAAOJye/VjLcUjNsOVnMVpWqBGpYIuwtCLGCcg33tPwdRTlnOOGfsFy2R+4P7HjySJ5+h4Zt3hVBd/AhPAiyjlzu0/2d1dqU841i/2Nk6LxKE83gMzOArRaOHoRYZ/SQ3yHyIgE5qaX6L72vYIKv4T2OUYq0p64y/uBnodMojMXUrRzZkkbFxDJUR+Zsjtqe6Av8IjmxutnV+jWzg968yktnK4clo7fpVkkVK8sY1rbcl14rNIFNPGfZww==" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=debug msg="completed challenge" Dec 12 17:31:06 gbvpi-bedroom go-librespot[5588]: time="2025-12-12T17:31:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:06 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 12 17:31:06 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:06 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:06 gbvpi-bedroom sudo[5543]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:06 gbvpi-bedroom volumio[5086]: info: Executing endpoint qc_getconfig Dec 12 17:31:06 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.734 [5595.5595] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 12 17:31:06 gbvpi-bedroom volumio[5086]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 12 17:31:06 gbvpi-bedroom volumio[5086]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.738 [5595.5595] INFO VolumeManager: [0x303588]: Setting new playback volume: 75 Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.738 [5595.5595] INFO VolumeManager: [0x303588]: Setting new mute state: 0 Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.738 [5595.5595] INFO QobuzConnect: [0x303f58]: Client initialized! Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.738 [5595.5595] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.754 [5595.5595] INFO LocalConfigManager: [0x302e68]: Starting Local Configuration server Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.754 [5595.5595] INFO SampleApp: Starting Local configuration server Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.754 [5595.5595] INFO SampleApp: Connected to UNIX socket client 0x2ed818 Dec 12 17:31:06 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:06.885 [5595.5595] INFO SampleApp: Playback volume changed: 75 Dec 12 17:31:06 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: TidalConnect service stoped! Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 12 17:31:08 gbvpi-bedroom sudo[5610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 12 17:31:08 gbvpi-bedroom sudo[5610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:08 gbvpi-bedroom sudo[5614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 17:31:08 gbvpi-bedroom sudo[5614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:31:08 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 12 17:31:08 gbvpi-bedroom sudo[5610]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:08 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 17:31:08 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 17:31:08 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:08 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:08 gbvpi-bedroom sudo[5614]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Successfully started MPD Monitor Dec 12 17:31:08 gbvpi-bedroom mpd_monitor.sh[5618]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Executing endpoint tc_getconfig Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 12 17:31:08 gbvpi-bedroom vtcs[5616]: STARTING TidalConnect services, version: 1.5.2.56 Dec 12 17:31:08 gbvpi-bedroom vtcs[5616]: STARTED TidalConnect services. Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Executing endpoint tc_connect Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Connecting to TidalConnect Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::servicePushState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreStateMachine::pushState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: MRS: Pushing multiroomSync output update for this device Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: MRS: Pushing multiroomSync output Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::servicePushState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreStateMachine::pushState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: MRS: Pushing multiroomSync output update for this device Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: MRS: Pushing multiroomSync output Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 17:31:08 gbvpi-bedroom volumio[5086]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 17:31:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Dec 12 17:31:09 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:09 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:09 gbvpi-bedroom go-librespot[5636]: go-librespot daemon starting... Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05:00" level=debug msg="app state loaded" Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05: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]" Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05: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]" Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05: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]" Dec 12 17:31:09 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:09-05:00" level=info msg="zeroconf server listening on port 36229" Dec 12 17:31:10 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:10-05:00" level=debug msg="obtained new client token: AADrCu6J0Ny8+IQNpkBo1k2gABusyu1k98GHVRUs5WiHSgeu58jB7MbKXROXkuaV2XAVpkdc9LuYEN0HCPu6YfTYytOQ052BiyP7Kyo1KVhJeorvRCgnRQJnZB8kHjYBrGvqYE2lCSOF/wVD3cfJomHs4CewooiANq7M043d7+g1N4DyQsG85hkFSy4OT+dcDbsoZehOrJo94jv/PMucHHeDYn16DREXy9puI3PX+ZjjMUzHB79llpY=" Dec 12 17:31:10 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:10 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:10-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:10 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:10-05:00" level=debug msg="completed challenge" Dec 12 17:31:10 gbvpi-bedroom go-librespot[5637]: time="2025-12-12T17:31:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: TidalConnect service started! Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: [Metrics] CommandRouter: 29s 418.33ms Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumiosetStartupVolume Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::Close All Modals sent Dec 12 17:31:11 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::Close All Modals sent Dec 12 17:31:12 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 12 17:31:12 gbvpi-bedroom volumio[5086]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 12 17:31:12 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:12 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 12 17:31:12 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 12 17:31:12 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 12 17:31:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Dec 12 17:31:13 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:13 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:13 gbvpi-bedroom go-librespot[5662]: go-librespot daemon starting... Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=debug msg="app state loaded" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05: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]" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05: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]" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05: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]" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=info msg="zeroconf server listening on port 39567" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=debug msg="obtained new client token: AADlaLNJxURRpwcbdYW4ptHf45c0TUY9MxzMtrCuca06ppwmU+M8l9Pfxgxf8Y0mSRg27CwedAIJnm8wL4KEMkrVfPqZqHAglOupt3/jWL9p1EkCJ3knLuQFY6MxreH80R+XxrVabjgWkuMFRM+i6SH636bxR0HekaS8jcQO21UGsCUPF8JoefVLtH2emNi50ZoOf3QADNO+4ptP2T6WgFGDLKWMPjVcUsyvdtvB3ZsLzzfRqJkg1V0Lxw==" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=debug msg="completed challenge" Dec 12 17:31:13 gbvpi-bedroom go-librespot[5663]: time="2025-12-12T17:31:13-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: Listing playlists Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: Listing playlists Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: Listing playlists Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: Listing playlists Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:14 gbvpi-bedroom volumio[5086]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:31:16 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:16 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:16 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 12 17:31:16 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 12 17:31:16 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 12 17:31:16 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 12 17:31:16 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 12 17:31:16 gbvpi-bedroom volumio[5086]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

CAUTION

\n
    \n
  • This build may break your network
    • \n
\n

FIX

\n
    \n
  • Wireless and network handling
    • \n
\n","title":"Update v4.080","updateavailable":true} Dec 12 17:31:16 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Dec 12 17:31:17 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:17 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:17 gbvpi-bedroom go-librespot[5674]: go-librespot daemon starting... Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=debug msg="app state loaded" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=debug msg="new websocket client" Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: Connection to go-librespot Websocket established Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05: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]" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05: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]" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05: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]" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=info msg="zeroconf server listening on port 45605" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=debug msg="obtained new client token: AABCCbxSdp011cJdXTyW5YHeCEYoaZ9T6RwPp+OdHUOcFsUNG1uV+ygfFDm0GmYHLYEnOElkunXISVaGMupdnleBdU5WJWO0JsbuEuUDCAz4XTWtU9a29AkzuLKFQn7LZo7UUbGc39p0heqmh0Z24w3ntLejOU2AmXVSngRCPtvcJFsgKTX7iUfF9sHDunuhLKW/dHBftY3XwCbnmqvjpM3+uAluvKFRfbw6uI3zXdQHJfLXMWCuZxEwtw==" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=debug msg="completed challenge" Dec 12 17:31:17 gbvpi-bedroom go-librespot[5675]: time="2025-12-12T17:31:17-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:17 gbvpi-bedroom volumio[5086]: info: Connection to go-librespot Websocket closed Dec 12 17:31:18 gbvpi-bedroom volumio[5086]: info: BOOT COMPLETED Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: info: Getting Spotify volume Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: errno: -111, Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: code: 'ECONNREFUSED', Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: syscall: 'connect', Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: address: '127.0.0.1', Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: port: 9879, Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: response: undefined Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: } Dec 12 17:31:20 gbvpi-bedroom volumio[5086]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 17:31:20 gbvpi-bedroom sudo[5696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 17:30' Dec 12 17:31:20 gbvpi-bedroom sudo[5696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Dec 12 17:31:20 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:20 gbvpi-bedroom sudo[5696]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:21 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:21 gbvpi-bedroom go-librespot[5698]: go-librespot daemon starting... Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=debug msg="app state loaded" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:21 gbvpi-bedroom vtcs[5616]: [2025-12-12 17:31:21.037] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 12 17:31:21 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 12 17:31:21 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 12 17:31:21 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:21 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:21.041 [5595.5595] INFO SampleApp: Socket closed Dec 12 17:31:21 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: volumio.service: Consumed 20.421s CPU time. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05: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]" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05: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]" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05: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]" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=info msg="zeroconf server listening on port 42389" Dec 12 17:31:21 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3286. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: volumio.service: Consumed 20.421s CPU time. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 12 17:31:21 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=debug msg="obtained new client token: AAC7NFZWVQYLQDiE8bNYf95kdM9ueVuVi7jO8MpFksNgBl6agPts/g3ZAs7+u+C6cundg816OcumtWtgzFtnW8H4q6YPmi3dcN7UvfUojmEfz3xVTbe93LwjALPY93d5D863NNCdwcZU13AOWUy4WOJDUCnXuD1WC3j493V7gLxgJCU2O817JZWeFyLjcWvw9hYYCwTeSikExs4CuZTvLcvsrmjEX526WN7XO01btmMpCY5HUbUjle2x4w==" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=debug msg="completed challenge" Dec 12 17:31:21 gbvpi-bedroom go-librespot[5702]: time="2025-12-12T17:31:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ----- Volumio3 ---- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ----- System startup ---- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: MYVOLUMIO Environment detected Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Plugin folders cleanup Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning into folder /volumio/app/plugins/ Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category audio_interface Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category miscellanea Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category music_service Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category plugins.json Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category system_controller Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category user_interface Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning into folder /data/plugins/ Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Scanning category music_service Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Plugin folders cleanup completed Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ----- Core plugins startup ---- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Loading plugins from folder /volumio/app/plugins/ Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Adding plugin upnp to MyMusic Plugins Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Loading plugins from folder /data/plugins/ Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Loading plugin "system"... Dec 12 17:31:22 gbvpi-bedroom volumio[5716]: info: Loading plugin "appearance"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "network"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Refreshing Cached IP Addresses Dec 12 17:31:23 gbvpi-bedroom sudo[5744]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 17:31:23 gbvpi-bedroom sudo[5744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:23 gbvpi-bedroom sudo[5744]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:23 gbvpi-bedroom sudo[5746]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 17:31:23 gbvpi-bedroom sudo[5746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:23 gbvpi-bedroom sudo[5746]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "services"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "alsa_controller"... Dec 12 17:31:23 gbvpi-bedroom sudo[5754]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 12 17:31:23 gbvpi-bedroom sudo[5754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "wizard"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "networkfs"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Starting Udev Watcher for removable devices Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Ignoring mount for partition: boot Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Ignoring mount for partition: volumio Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Ignoring mount for partition: volumio_data Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "volumio_command_line_client"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "upnp"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: [1765578683525] Starting Upmpd Daemon Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "my_music"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "mpd"... Dec 12 17:31:23 gbvpi-bedroom volumio[5716]: info: Loading plugin "upnp_browser"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Starting UPNP Browser Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "alarm-clock"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "airplay_emulation"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Starting Shairport Sync Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "last_100"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "webradio"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "i2s_dacs"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: I2S DAC not set, start Auto-detection Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "volumiodiscovery"... Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: *** WARNING *** For more information see Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: *** WARNING *** For more information see Dec 12 17:31:24 gbvpi-bedroom node[5716]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:24 gbvpi-bedroom node[5716]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:24 gbvpi-bedroom node[5716]: *** WARNING *** For more information see Dec 12 17:31:24 gbvpi-bedroom node[5716]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:24 gbvpi-bedroom node[5716]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:24 gbvpi-bedroom node[5716]: *** WARNING *** For more information see Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:24 gbvpi-bedroom volumio[5716]: info: Loading plugin "jellyfin"... Dec 12 17:31:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Dec 12 17:31:24 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:24 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:24 gbvpi-bedroom go-librespot[5779]: go-librespot daemon starting... Dec 12 17:31:24 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:24-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:24 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:24-05:00" level=debug msg="app state loaded" Dec 12 17:31:24 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "spop"... Dec 12 17:31:25 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:25-05: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]" Dec 12 17:31:25 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:25-05: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]" Dec 12 17:31:25 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:25-05: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]" Dec 12 17:31:25 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:25-05:00" level=info msg="zeroconf server listening on port 36873" Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "outputs"... Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "albumart"... Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Plugin example_plugin is not enabled Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "inputs"... Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "updater_comm"... Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Plugin mpdemulation is not enabled Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "rest_api"... Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading plugin "websocket"... Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Starting Socket.io Server version 1.7.4 Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Loading i18n strings for locale en Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: Updating browse sources language Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:25 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:25-05:00" level=debug msg="obtained new client token: AAAYto39lv6HaUesezTxWT4B1Uu/lKkspvvPYkV/X0rfC+vgg45mn/nx2ZhYfofDwFdjBS+H7I24LK2DBgsQczNJnxSCZX+FdQg3gq2PtTZV32SnzuFDf4fcgLvmz50p+EkWgjEkP3HYT0PLZax8Mha4+xwpidnGcjiq5JiWEEGEWlvj7vdHfJL4NAfhDkKzlwJOOWJ/DB9QddaB9z0sEMOJzYBwjsGZMcb9Hhsbm60Jr0pcqgVSgBmkjw==" Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::initPlayerControls Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: Express server listening on port 3000 Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: [Metrics] WebUI: 3s 790.25ms Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::resetVolumioState Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::getcurrentVolume Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioRetrievevolume Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: Volumio Network Manager: Network status updated: 2 Dec 12 17:31:25 gbvpi-bedroom volumio[5787]: Forking 3 albumart workers Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:25 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: VolumeController:: Volume=91 Mute =false Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::pushState Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 17:31:25 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::updateTrackBlock Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrackBlock Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioRetrievevolume Dec 12 17:31:26 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:26] [connect] Successful connection Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Reloading queue from file Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::setRepeat true single undefined Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::pushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::setRandom null Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::pushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Setting Device type: Raspberry PI Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 12 17:31:26 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:26-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:26 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:26-05:00" level=debug msg="completed challenge" Dec 12 17:31:26 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765578686 101 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: VolumeController:: Volume=91 Mute =false Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreStateMachine::pushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Completed loading Core Plugins Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Preparing to generate the ALSA configuration file Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Asound.conf file written Dec 12 17:31:26 gbvpi-bedroom sudo[5843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 17:31:26 gbvpi-bedroom sudo[5843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:26 gbvpi-bedroom go-librespot[5780]: time="2025-12-12T17:31:26-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:26 gbvpi-bedroom sudo[5843]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Output device has changed, restarting MPD Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Output device has changed, restarting Shairport Sync Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:26 gbvpi-bedroom sudo[5849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:31:26 gbvpi-bedroom sudo[5849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:26 gbvpi-bedroom sudo[5849]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:26 gbvpi-bedroom sudo[5851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:31:26 gbvpi-bedroom sudo[5851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: ___________ START PLUGINS ___________ Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: ControllerMpd::onStart: Initializing MPD Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Creating MPD Configuration file Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: [1765578686453] CoreMusicLibrary::Adding element Media Servers Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:26 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: UPNP Browser: Client initialized successfully Dec 12 17:31:26 gbvpi-bedroom sudo[5860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:31:26 gbvpi-bedroom sudo[5860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:26 gbvpi-bedroom sudo[5860]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:26 gbvpi-bedroom sudo[5861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:31:26 gbvpi-bedroom sudo[5861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:26 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 17:31:26 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 17:31:26 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.270s CPU time. Dec 12 17:31:26 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 17:31:26 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 17:31:26 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: [1765578686584] CoreMusicLibrary::Adding element Last_100 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: [1765578686588] CoreMusicLibrary::Adding element Webradio Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Initializing BBC Radios Dec 12 17:31:26 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 17:31:26 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Discovery: Getting this device information Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 17:31:26 gbvpi-bedroom volumio[5802]: Starting albumart workers Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: [1765578686745] CoreMusicLibrary::Adding element Jellyfin Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: Cannot find translation for source Jellyfin Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"http://cdn-profiles.tunein.com/s28808/images/logoq.jpg?t=1","mute":false,"status":"stop","track":"WFMU","volume":91},"type":"device"} Dec 12 17:31:26 gbvpi-bedroom sudo[5877]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 17:31:26 gbvpi-bedroom sudo[5877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 17:31:26 gbvpi-bedroom sudo[5877]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: Creating Spotify config file Dec 12 17:31:26 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:26 gbvpi-bedroom volumio[5804]: Starting albumart workers Dec 12 17:31:26 gbvpi-bedroom volumio[5803]: Starting albumart workers Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Volumio Calling Home Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Discovery: Found device GBVPi-Bedroom Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Discovery: Found device GBVPi-Bedroom Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: MPD Permissions set Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: MPD Permissions set Dec 12 17:31:27 gbvpi-bedroom sudo[5754]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Spotify config file written Dec 12 17:31:27 gbvpi-bedroom sudo[5912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 12 17:31:27 gbvpi-bedroom sudo[5912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: No need to fix Spotify hosts Dec 12 17:31:27 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:27 gbvpi-bedroom go-librespot[5916]: go-librespot daemon starting... Dec 12 17:31:27 gbvpi-bedroom sudo[5912]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05:00" level=debug msg="app state loaded" Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Volumio called home Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Starting Shairport Sync Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Starting Shairport Sync Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: Starting Shairport Sync Dec 12 17:31:27 gbvpi-bedroom sudo[5934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:27 gbvpi-bedroom sudo[5934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:27 gbvpi-bedroom sudo[5936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:27 gbvpi-bedroom sudo[5936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:27 gbvpi-bedroom volumio[5716]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 12 17:31:27 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 17:31:27 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 17:31:27 gbvpi-bedroom sudo[5938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:27 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:27 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.639s CPU time. Dec 12 17:31:27 gbvpi-bedroom sudo[5938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:27 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05: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]" Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05: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]" Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05: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]" Dec 12 17:31:27 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:27-05:00" level=info msg="zeroconf server listening on port 41287" Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:28 gbvpi-bedroom sudo[5934]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:28 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 17:31:28 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 17:31:28 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:28 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:28 gbvpi-bedroom sudo[5936]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: Shairport-Sync Started Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: Error adding Membership: Error: addMembership EINVAL Dec 12 17:31:28 gbvpi-bedroom sudo[5938]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: Shairport-Sync Started Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: Shairport-Sync Started Dec 12 17:31:28 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:28-05:00" level=debug msg="obtained new client token: AACCe6yXdJnatgI79q36KN6HDgCdzk2pKpOOR7ngee/ZCKSR+bqJip7oTBCLxmhjfZOZrNRMDxBdpXTmr7yajTtsUJWmhRJWIHoaJn97gwvsRLqy8P9GT3uKncPL9Bu+25VuEd8y3d9T4SGQU/OoQOljkb1mQugb7hZ9wpoSs1PZn8xbnnYLJupJ/xnkIg9Cbgk60Q0U2mMjOP3GCj/DUFQ4cFY/XVnCfrvTMQzqnO4MrrfoXk9T09I=" Dec 12 17:31:28 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:28 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:28-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:28 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:28-05:00" level=debug msg="completed challenge" Dec 12 17:31:28 gbvpi-bedroom go-librespot[5925]: time="2025-12-12T17:31:28-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:28 gbvpi-bedroom mpd[5889]: 2025-12-12T17:31:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 17:31:28 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 17:31:28 gbvpi-bedroom sudo[5851]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:28 gbvpi-bedroom sudo[5861]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: Completed starting Core Plugins Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: ----- MyVolumio plugins startup ---- Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: ------------------------------------------- Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: error: MPD error: The expression evaluated to a falsy value: Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: assert.ok(self.idling) Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: error: The expression evaluated to a falsy value: Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: assert.ok(self.idling) Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: info: MPD running with PID5889 Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: ,establishing connection Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: error: updateQueue error: null Dec 12 17:31:28 gbvpi-bedroom volumio[5716]: error: updateQueue error: null Dec 12 17:31:30 gbvpi-bedroom volumio[5716]: info: go-librespot daemon successfully initialized Dec 12 17:31:30 gbvpi-bedroom volumio[5716]: info: Discovery: Browse raised the following error Error: dns service error: unknown Dec 12 17:31:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Dec 12 17:31:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:31 gbvpi-bedroom go-librespot[5966]: go-librespot daemon starting... Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05:00" level=debug msg="app state loaded" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:31 gbvpi-bedroom sudo[5974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 17:31:31 gbvpi-bedroom sudo[5974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:31 gbvpi-bedroom sudo[5976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 17:31:31 gbvpi-bedroom sudo[5976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:31 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 17:31:31 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 17:31:31 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:31 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:31 gbvpi-bedroom sudo[5974]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:31 gbvpi-bedroom sudo[5976]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:31 gbvpi-bedroom mpd_monitor.sh[5979]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 17:31:31 gbvpi-bedroom volumio[5716]: info: Successfully started MPD Monitor Dec 12 17:31:31 gbvpi-bedroom volumio[5716]: info: Successfully started MPD Monitor Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05: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]" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05: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]" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05: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]" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05:00" level=info msg="zeroconf server listening on port 40997" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05:00" level=debug msg="obtained new client token: AAABqMZqF/NlSaz+4b1j5GajJ1t1dED2Qjf/zn/TbFwF43RRPdZBL21edAlpJaOHBnjCJkCZJMZFvEeZG6C6eYR/t0FeprQP1TTWP3x9byaOw1+wd0OxU7Xp+KoPYrDLMou8+d4ngnRBuWfoL3/wUGKOCjgkBszc3945agBDgXcdySa9qQIRXByEnAlXne5TVrnqp9aS5k1Iu14Ww+IeAWtN98i0xoPlkmJgVaswpSgYN9aB2/0STKndaA==" Dec 12 17:31:31 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:33 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:33-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:33 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:33-05:00" level=debug msg="completed challenge" Dec 12 17:31:33 gbvpi-bedroom go-librespot[5967]: time="2025-12-12T17:31:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:33 gbvpi-bedroom sudo[6000]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 17:31:33 gbvpi-bedroom sudo[6000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:33 gbvpi-bedroom sudo[6002]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 17:31:33 gbvpi-bedroom sudo[6002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:33 gbvpi-bedroom sudo[6000]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:33 gbvpi-bedroom sudo[6002]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:33 gbvpi-bedroom sudo[6004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 12 17:31:33 gbvpi-bedroom sudo[6004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:33 gbvpi-bedroom sudo[6004]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:33 gbvpi-bedroom volumio[5716]: info: Upmpdcli Daemon Started Dec 12 17:31:33 gbvpi-bedroom volumio[5716]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 12 17:31:33 gbvpi-bedroom volumio[5716]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:33 gbvpi-bedroom volumio[5716]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: Listing playlists Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: Listing playlists Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: Listing playlists Dec 12 17:31:34 gbvpi-bedroom volumio[5716]: info: Listing playlists Dec 12 17:31:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Dec 12 17:31:36 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:36 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:36 gbvpi-bedroom go-librespot[6008]: go-librespot daemon starting... Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=debug msg="app state loaded" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05: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]" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05: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]" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05: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]" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=info msg="zeroconf server listening on port 42373" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=debug msg="obtained new client token: AAAmBwdnHCvl70w7XbS3mjkDS8R9XIpZih2uP70upWI3Y0YA9bCmgz6plc/cm7pXaJyJrzZOjWo4UbP3ypMMBFvPVB9eh6L9aTwSDikW6pxQX4T52vNyJELb1MoURmDym4UCOuh5cWfxDGgJU1Avh9Vnur+jCf4Dqcuik1dEXjFHHrmTlxElbEY5rozcG8+8Q3k7UJn0RBv4nc2b9pU0qK65DcTjenCIKe/Rt8I4cS2qb1v6y5xKCo39BA==" Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=debug msg="new websocket client" Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Connection to go-librespot Websocket established Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=debug msg="completed challenge" Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin bluetooth to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin multiroom to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin metavolumio to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin cd_controller to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 12 17:31:36 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 12 17:31:36 gbvpi-bedroom go-librespot[6009]: time="2025-12-12T17:31:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: Starting MyVolumio Remote Streaming Endpoints Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: MyVolumio login type: Token Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: Streaming services startup Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: Starting Streaming Daemon Dec 12 17:31:37 gbvpi-bedroom sudo[6017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 12 17:31:37 gbvpi-bedroom sudo[6017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 12 17:31:37 gbvpi-bedroom sudo[6017]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: info: Connection to go-librespot Websocket closed Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: error: Cannot start Volumio Streaming Daemon Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 17:31:37 gbvpi-bedroom volumio[5716]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MyVolumio token set successfully Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MYVOLUMIO: Adding device Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MYVOLUMIO: Evaluating Server Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MyVolumio Plan changed: premium Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Removing browser output: myVolumio user plan is not superstar Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Removing audio output: Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MYVOLUMIO: Adding device Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MYVOLUMIO: Evaluating Server Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Remote config written successfully Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Starting Tunnel 1 Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Starting Tunnel Connection Checker Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Completed starting MyVolumio Plugin Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MYVolumio Device enabled Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: MyVolumio status changed Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Streaming services startup Dec 12 17:31:38 gbvpi-bedroom volumio[5716]: info: Starting Streaming Daemon Dec 12 17:31:38 gbvpi-bedroom sudo[6062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 12 17:31:38 gbvpi-bedroom sudo[6062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 12 17:31:39 gbvpi-bedroom sudo[6062]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 12 17:31:39 gbvpi-bedroom sudo[6066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 12 17:31:39 gbvpi-bedroom sudo[6066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:39 gbvpi-bedroom sudo[6066]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: MRS: MultiRoom plugin initialized Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: MRS: STOPPING SNAPCLIENT Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: MRS: Snap server stop Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: MRS: STOPPING volumioStreaming Dec 12 17:31:39 gbvpi-bedroom sudo[6083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 12 17:31:39 gbvpi-bedroom sudo[6083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:39 gbvpi-bedroom sudo[6085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 12 17:31:39 gbvpi-bedroom sudo[6085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:39 gbvpi-bedroom sudo[6088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 12 17:31:39 gbvpi-bedroom sudo[6088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 12 17:31:39 gbvpi-bedroom sudo[6091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 12 17:31:39 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:39 gbvpi-bedroom sudo[6091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 12 17:31:39 gbvpi-bedroom sudo[6091]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:39 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Preparing to generate the ALSA configuration file Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:40 gbvpi-bedroom go-librespot[6094]: go-librespot daemon starting... Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=debug msg="app state loaded" Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Getting Spotify volume Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Reading ALSA contributions from plugins. Dec 12 17:31:40 gbvpi-bedroom sudo[6083]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Setting Geolocation for MyVolumio to us1 Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Setting Geolocation for MyVolumio to us1 Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: Removed streaming files Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: error: Cannot start Volumio Streaming Daemon Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 17:31:40 gbvpi-bedroom sudo[6085]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:40 gbvpi-bedroom sudo[6088]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: SNAPCLIENT STOPPED Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: volumioStreaming STOPPED Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: SNAPSERVER STOPPED Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05: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]" Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05: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]" Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05: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]" Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Asound.conf file written Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=info msg="zeroconf server listening on port 41155" Dec 12 17:31:40 gbvpi-bedroom sudo[6104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 17:31:40 gbvpi-bedroom sudo[6104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:40 gbvpi-bedroom sudo[6104]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Output device has changed, restarting MPD Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Output device has changed, restarting Shairport Sync Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:40 gbvpi-bedroom sudo[6110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:31:40 gbvpi-bedroom sudo[6110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:40 gbvpi-bedroom sudo[6112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:31:40 gbvpi-bedroom sudo[6112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 17:31:40 gbvpi-bedroom sudo[6110]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=debug msg="obtained new client token: AADAT2XpTVNdvRomyrgqVlCFqYfL0MNP23m7pkSaBlRXwvcM/7DjON8qKerqGT+upa0mG1cM3T8ak+hEVljL7wbHfIe6iS6Nqsq5xr9jE+0oUQKWulc+abnsujPawwTGsM2scmZ4jmklToqrICtLIkfS78G+9BeeLLNcw0BZsz/Imri2vc+v7yLjl+Hh5x9NEMamr/0RQskyt4F6QzrM2xZP+F5E3DWZ4axHokSqLrYJD0G1TprJyEg+wQ==" Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: Pushing multiroomSync output for this device Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: Pushing multiroomSync output Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding audio output: Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding audio output: Dec 12 17:31:40 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.49811 Dec 12 17:31:40 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 17:31:40 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.799s CPU time. Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:40 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:40 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.49811 disconnected from D-Bus Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding METAVOLUMIO REST API Endpoints Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Preparing CD Folders Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding CD REST API Endpoints Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Starting UDEV Watcher for CD Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: Detecting CD presence with UDEV Dec 12 17:31:40 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 17:31:40 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 17:31:40 gbvpi-bedroom sudo[6130]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 17:31:40 gbvpi-bedroom sudo[6130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 17:31:40 gbvpi-bedroom sudo[6130]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=debug msg="completed challenge" Dec 12 17:31:40 gbvpi-bedroom go-librespot[6095]: time="2025-12-12T17:31:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:41 gbvpi-bedroom mpd[6133]: 2025-12-12T17:31:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 17:31:41 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 17:31:41 gbvpi-bedroom sudo[6112]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Dec 12 17:31:43 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:44 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:44 gbvpi-bedroom go-librespot[6150]: go-librespot daemon starting... Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=debug msg="app state loaded" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05: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]" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05: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]" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05: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]" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=info msg="zeroconf server listening on port 44847" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=debug msg="obtained new client token: AAAG+Mvva6z99ACQpR9ZGT7tMdYlDEdzmwNGvxmTdk9pNcy4XN05Zin7jCJLCGqggA5/TmBKYDczIe34oAl3hUWdVkarvpdmOdWhJM58iv1KQM/kqAg98JERjR0ycHlpua5yH4YO/1FgM/ckaRL/Q0LCaM8/Xzy4T4VOMCFS5DwlV/jFZi1vRuyKfCYBDCx2pW1I1ZApx/kpvsR80fAzl07mhXFXAtmbfroORjcygbaVrXa6io5Ts96Upw==" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=debug msg="completed challenge" Dec 12 17:31:44 gbvpi-bedroom go-librespot[6151]: time="2025-12-12T17:31:44-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding inputs REST Endpoints Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Scanning Audio Inputs Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Checking against Known Cards name Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding Server instance for streaming Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: error: Hi Res Audio Failed Login: Missing Login Data Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 12 17:31:45 gbvpi-bedroom sudo[6162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 12 17:31:45 gbvpi-bedroom sudo[6162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding TIDAL REST API Endpoints Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Stopping AccessToken refresher cron for QOBUZ Dec 12 17:31:45 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 12 17:31:45 gbvpi-bedroom sudo[6169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 12 17:31:45 gbvpi-bedroom sudo[6169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:45 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 12 17:31:45 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 12 17:31:45 gbvpi-bedroom sudo[6162]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: AccessToken refresher cron started for QOBUZ Dec 12 17:31:45 gbvpi-bedroom sudo[6169]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Adding QOBUZ REST API Endpoints Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: SPOTIFY: SPOTIFY VOLUME undefined Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: SPOTIFY: VOLUMIO VOLUME 91 Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Aligning Spotify Volume to Volumio Volume Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Setting Spotify Volume from Volumio: 91 Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Initializing connection to go-librespot Websocket Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Updating MyVolumio device info Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Updating MyVolumio device info Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:45 gbvpi-bedroom sudo[6172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 12 17:31:45 gbvpi-bedroom sudo[6172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: MRS: Getting audio outputs on start Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: MRS: Requesting all other devices output Dec 12 17:31:45 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 12 17:31:45 gbvpi-bedroom qobuz-connect[5595]: 20251212 17:31:45.671 [5595.5595] INFO SampleApp: Stopping Local configuration server Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: info: Successfully Added MyVolumio device Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: Error: socket hang up Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: at connResetException (node:internal/errors:720:14) Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: at Socket.emit (node:events:526:35) Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: code: 'ECONNRESET', Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: response: undefined Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: } Dec 12 17:31:45 gbvpi-bedroom volumio[5716]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 17:31:46 gbvpi-bedroom sudo[6189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 17:30' Dec 12 17:31:46 gbvpi-bedroom sudo[6189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:46 gbvpi-bedroom sudo[6189]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:46 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 12 17:31:46 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:46 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:46 gbvpi-bedroom sudo[6172]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Dec 12 17:31:47 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:47 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:47 gbvpi-bedroom go-librespot[6198]: go-librespot daemon starting... Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05:00" level=debug msg="app state loaded" Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:47 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:47] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 12 17:31:47 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:47] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: Error: Application ID was not specified! Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -m|--manufacturer: Manufacturer of the device Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -n|--deviceName: Device name Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -l|--model: Device's model name Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -s|--serialNumber: Device's serial number Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -o|--outputDevice: ALSA PCM device to play audio to Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -p|--port: Port to run the local configuration HTTP server on Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 12 17:31:47 gbvpi-bedroom qobuz-connect[6197]: -h|--help: Print this help Dec 12 17:31:47 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:47 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:47 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 12 17:31:47 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 12 17:31:47 gbvpi-bedroom systemd[1]: volumio.service: Consumed 19.078s CPU time. Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05: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]" Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05: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]" Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05: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]" Dec 12 17:31:47 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:47-05:00" level=info msg="zeroconf server listening on port 46207" Dec 12 17:31:47 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 12 17:31:47 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 12 17:31:48 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:48-05:00" level=debug msg="obtained new client token: AAAJp5TvDdI0Z2/dOerxt5BzffM9ESTKeOgMzQuVy5KP1WlxZaalYKzaesEoPzUzG3HMfUqWtFNyPIQ070Ju1xYW0s6fKClBkzq3rvHYA2XMnPe+R4SzeePh+WSFkCXzXwRTcWJ8Kb4ZiFMgd1tRtdwuJooikCTKYsnUTyRtRb4p8dqZKl4PYG3EzVLU4Dgtz8KyouwrVZsUQPJY857yCdW5uREHnS8SoS/xcOhH2i/IbD9fNweCJxY=" Dec 12 17:31:48 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:48 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:48-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:48 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:48-05:00" level=debug msg="completed challenge" Dec 12 17:31:48 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3287. Dec 12 17:31:48 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 12 17:31:48 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 12 17:31:48 gbvpi-bedroom systemd[1]: volumio.service: Consumed 19.078s CPU time. Dec 12 17:31:48 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 12 17:31:48 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 12 17:31:48 gbvpi-bedroom go-librespot[6199]: time="2025-12-12T17:31:48-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ----- Volumio3 ---- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ----- System startup ---- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: MYVOLUMIO Environment detected Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Plugin folders cleanup Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning into folder /volumio/app/plugins/ Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category audio_interface Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category miscellanea Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category music_service Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category plugins.json Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category system_controller Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category user_interface Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning into folder /data/plugins/ Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Scanning category music_service Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Plugin folders cleanup completed Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ----- Core plugins startup ---- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Loading plugins from folder /volumio/app/plugins/ Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Adding plugin upnp to MyMusic Plugins Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Loading plugins from folder /data/plugins/ Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Loading plugin "system"... Dec 12 17:31:49 gbvpi-bedroom volumio[6218]: info: Loading plugin "appearance"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "network"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Refreshing Cached IP Addresses Dec 12 17:31:50 gbvpi-bedroom sudo[6246]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 17:31:50 gbvpi-bedroom sudo[6246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:50 gbvpi-bedroom sudo[6248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "services"... Dec 12 17:31:50 gbvpi-bedroom sudo[6248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:50 gbvpi-bedroom sudo[6246]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "alsa_controller"... Dec 12 17:31:50 gbvpi-bedroom sudo[6248]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:50 gbvpi-bedroom sudo[6256]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 12 17:31:50 gbvpi-bedroom sudo[6256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "wizard"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "networkfs"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Starting Udev Watcher for removable devices Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Ignoring mount for partition: boot Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Ignoring mount for partition: volumio Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Ignoring mount for partition: volumio_data Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "volumio_command_line_client"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "upnp"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: [1765578710498] Starting Upmpd Daemon Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "my_music"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "mpd"... Dec 12 17:31:50 gbvpi-bedroom volumio[6218]: info: Loading plugin "upnp_browser"... Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Starting UPNP Browser Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "alarm-clock"... Dec 12 17:31:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Dec 12 17:31:51 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:51 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:51 gbvpi-bedroom go-librespot[6279]: go-librespot daemon starting... Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "airplay_emulation"... Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Starting Shairport Sync Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05:00" level=debug msg="app state loaded" Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "last_100"... Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "webradio"... Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "i2s_dacs"... Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: I2S DAC not set, start Auto-detection Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "volumiodiscovery"... Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: *** WARNING *** For more information see Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:51 gbvpi-bedroom node[6218]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: *** WARNING *** For more information see Dec 12 17:31:51 gbvpi-bedroom node[6218]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:51 gbvpi-bedroom node[6218]: *** WARNING *** For more information see Dec 12 17:31:51 gbvpi-bedroom node[6218]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 12 17:31:51 gbvpi-bedroom node[6218]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 17:31:51 gbvpi-bedroom node[6218]: *** WARNING *** For more information see Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:51 gbvpi-bedroom volumio[6218]: info: Loading plugin "jellyfin"... Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05: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]" Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05: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]" Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05: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]" Dec 12 17:31:51 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:51-05:00" level=info msg="zeroconf server listening on port 35259" Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "spop"... Dec 12 17:31:52 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:52-05:00" level=debug msg="obtained new client token: AAARNElzP7Bb9mO/Ei1oUMhTQHIe/QyWWKTW3WV2TjN0ty4es74/TihS9Lo9l0nnyrF6WeEvigUXRIM5BliAvdTSY4dn5+MAhZq66VfWfQRmFzsNAUjz+rM3ln8o3mRWknIF5AlpZOpJh9ZYFaEgKF3kVIrAEDPm3L7AA0RnxSP2Oeenr9oSXFAcHe5TGpzInYeEz6uXBsRQqoE81NUHjQkTsPaC4bAHqp8lqb0TdrKmnt/9seV6ANw=" Dec 12 17:31:52 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "outputs"... Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "albumart"... Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Plugin example_plugin is not enabled Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "inputs"... Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "updater_comm"... Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Plugin mpdemulation is not enabled Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "rest_api"... Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading plugin "websocket"... Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Starting Socket.io Server version 1.7.4 Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Loading i18n strings for locale en Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: Updating browse sources language Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:52 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:52-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:52 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:52-05:00" level=debug msg="completed challenge" Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::initPlayerControls Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: Express server listening on port 3000 Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: [Metrics] WebUI: 3s 795.83ms Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::resetVolumioState Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::getcurrentVolume Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioRetrievevolume Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Volumio Network Manager: Network status updated: 2 Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: VolumeController:: Volume=91 Mute =false Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::pushState Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:52 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:52] [connect] Successful connection Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 17:31:52 gbvpi-bedroom go-librespot[6280]: time="2025-12-12T17:31:52-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::updateTrackBlock Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrackBlock Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioRetrievevolume Dec 12 17:31:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:52 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 1. Dec 12 17:31:52 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:52 gbvpi-bedroom volumio[6292]: Forking 3 albumart workers Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Reloading queue from file Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::setRepeat true single undefined Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::pushState Dec 12 17:31:52 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::setRandom null Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::pushState Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: Setting Device type: Raspberry PI Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 12 17:31:52 gbvpi-bedroom volumio[6218]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 12 17:31:52 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 17:31:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765578712 101 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: No valid Plugin REST Endpoint Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: 20251212 17:31:53.111 [6309.6309] ERROR SampleApp: api request was not successful Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: Error: Application ID was not specified! Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -m|--manufacturer: Manufacturer of the device Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -n|--deviceName: Device name Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -l|--model: Device's model name Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -s|--serialNumber: Device's serial number Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -o|--outputDevice: ALSA PCM device to play audio to Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -p|--port: Port to run the local configuration HTTP server on Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 12 17:31:53 gbvpi-bedroom qobuz-connect[6309]: -h|--help: Print this help Dec 12 17:31:53 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:53 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: VolumeController:: Volume=91 Mute =false Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::pushState Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioPushState Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Completed loading Core Plugins Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Preparing to generate the ALSA configuration file Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Asound.conf file written Dec 12 17:31:53 gbvpi-bedroom sudo[6350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 17:31:53 gbvpi-bedroom sudo[6350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:53 gbvpi-bedroom sudo[6350]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Output device has changed, restarting MPD Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Output device has changed, restarting Shairport Sync Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:53 gbvpi-bedroom sudo[6356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:31:53 gbvpi-bedroom sudo[6356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:53 gbvpi-bedroom sudo[6356]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: ___________ START PLUGINS ___________ Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: ControllerMpd::onStart: Initializing MPD Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Creating MPD Configuration file Dec 12 17:31:53 gbvpi-bedroom sudo[6358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:31:53 gbvpi-bedroom sudo[6358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: [1765578713345] CoreMusicLibrary::Adding element Media Servers Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 17:31:53 gbvpi-bedroom sudo[6366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:31:53 gbvpi-bedroom sudo[6366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: UPNP Browser: Client initialized successfully Dec 12 17:31:53 gbvpi-bedroom sudo[6366]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:53 gbvpi-bedroom sudo[6368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:31:53 gbvpi-bedroom sudo[6368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:53 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.287s CPU time. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: [1765578713494] CoreMusicLibrary::Adding element Last_100 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:53 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: [1765578713515] CoreMusicLibrary::Adding element Webradio Dec 12 17:31:53 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Initializing BBC Radios Dec 12 17:31:53 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Discovery: Getting this device information Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 17:31:53 gbvpi-bedroom sudo[6382]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 17:31:53 gbvpi-bedroom sudo[6382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: [1765578713675] CoreMusicLibrary::Adding element Jellyfin Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: Cannot find translation for source Jellyfin Dec 12 17:31:53 gbvpi-bedroom sudo[6382]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"http://cdn-profiles.tunein.com/s28808/images/logoq.jpg?t=1","mute":false,"status":"stop","track":"WFMU","volume":91},"type":"device"} Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Creating Spotify config file Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:53 gbvpi-bedroom volumio[6314]: Starting albumart workers Dec 12 17:31:53 gbvpi-bedroom volumio[6218]: info: Volumio Calling Home Dec 12 17:31:53 gbvpi-bedroom volumio[6316]: Starting albumart workers Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Discovery: Found device GBVPi-Bedroom Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Discovery: Found device GBVPi-Bedroom Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: MPD Permissions set Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: MPD Permissions set Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Spotify config file written Dec 12 17:31:54 gbvpi-bedroom sudo[6408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 12 17:31:54 gbvpi-bedroom sudo[6408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:54 gbvpi-bedroom volumio[6317]: Starting albumart workers Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:54 gbvpi-bedroom go-librespot[6410]: go-librespot daemon starting... Dec 12 17:31:54 gbvpi-bedroom sudo[6408]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05:00" level=debug msg="app state loaded" Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:54 gbvpi-bedroom sudo[6256]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: No need to fix Spotify hosts Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Volumio called home Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05: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]" Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05: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]" Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05: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]" Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05:00" level=info msg="zeroconf server listening on port 37655" Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Starting Shairport Sync Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Starting Shairport Sync Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Starting Shairport Sync Dec 12 17:31:54 gbvpi-bedroom sudo[6436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:54 gbvpi-bedroom sudo[6436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:31:54 gbvpi-bedroom sudo[6438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:54 gbvpi-bedroom sudo[6438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:54 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 17:31:54 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 17:31:54 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:54 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.684s CPU time. Dec 12 17:31:54 gbvpi-bedroom sudo[6441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:31:54 gbvpi-bedroom sudo[6441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:54 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:54-05:00" level=debug msg="obtained new client token: AACsbH1HwpOs200S7BZPWyIgG3EQXqcJxsX1ssECz5J0aZvPDPaMbmp5Q9sV4pBPJ9m16Mwrl7ePiuEEfpAyXibm6M1pSxk4rHqmNScB2H3MUe/O9Y6CPk/ONNuT/LwGmzFvaIkH5xaC6FR0RgXi5B1OkhNkNj+bWH3M8J1JKREU3ZFNAEvrDorKIMvTp0XQ+LpbeK1eGegYhTJA1KIqf/8UiZP/RVxMrjUD1G2Qh7j+WRXQDyT5CSQiQw==" Dec 12 17:31:54 gbvpi-bedroom volumio[6218]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 12 17:31:55 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:55 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:55 gbvpi-bedroom sudo[6436]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:55 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:55-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:55 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 17:31:55 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 17:31:55 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:55 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:55-05:00" level=debug msg="completed challenge" Dec 12 17:31:55 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:31:55 gbvpi-bedroom sudo[6441]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: Shairport-Sync Started Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: Error adding Membership: Error: addMembership EINVAL Dec 12 17:31:55 gbvpi-bedroom sudo[6438]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: Shairport-Sync Started Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: Shairport-Sync Started Dec 12 17:31:55 gbvpi-bedroom go-librespot[6416]: time="2025-12-12T17:31:55-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:31:55 gbvpi-bedroom mpd[6397]: 2025-12-12T17:31:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 17:31:55 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 17:31:55 gbvpi-bedroom sudo[6368]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:55 gbvpi-bedroom sudo[6358]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: Completed starting Core Plugins Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: ----- MyVolumio plugins startup ---- Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: ------------------------------------------- Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: error: MPD error: The expression evaluated to a falsy value: Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: assert.ok(self.idling) Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: error: The expression evaluated to a falsy value: Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: assert.ok(self.idling) Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: info: MPD running with PID6397 Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: ,establishing connection Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: error: updateQueue error: null Dec 12 17:31:55 gbvpi-bedroom volumio[6218]: error: updateQueue error: null Dec 12 17:31:57 gbvpi-bedroom volumio[6218]: info: go-librespot daemon successfully initialized Dec 12 17:31:57 gbvpi-bedroom volumio[6218]: info: Discovery: Browse raised the following error Error: dns service error: unknown Dec 12 17:31:58 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 2. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:58 gbvpi-bedroom go-librespot[6471]: go-librespot daemon starting... Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=debug msg="app state loaded" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:31:58 gbvpi-bedroom volumio[6218]: info: No valid Plugin REST Endpoint Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: 20251212 17:31:58.316 [6473.6473] ERROR SampleApp: api request was not successful Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: Error: Application ID was not specified! Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -m|--manufacturer: Manufacturer of the device Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -n|--deviceName: Device name Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -l|--model: Device's model name Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -s|--serialNumber: Device's serial number Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -o|--outputDevice: ALSA PCM device to play audio to Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -p|--port: Port to run the local configuration HTTP server on Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 12 17:31:58 gbvpi-bedroom qobuz-connect[6473]: -h|--help: Print this help Dec 12 17:31:58 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:58 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05: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]" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05: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]" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05: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]" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=info msg="zeroconf server listening on port 39287" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=debug msg="obtained new client token: AACgaosdM/Nb9k7OJgTJEUBfSuTZM7uoVnBPtlXG7wSlu8XSgyxOGh1mLiuL+0YK1VzNX411O4fxBwISolZLM2oTB/i3SulSY1vEobtG0XmYJ4MwvpQv6kQ/9Ta4APkGnoRuzUaAEFtTmY3dWPjF2loS8+yCKITFVHdz9WDYJQsteuDnt21l1PRPYxaTT1uT0zwlhIb+JdeDtvmsUjzcc6KsqAFPy3IECk0HU9pA8eLX+0y30fId/Z2jQQ==" Dec 12 17:31:58 gbvpi-bedroom sudo[6481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 17:31:58 gbvpi-bedroom sudo[6481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:31:58 gbvpi-bedroom sudo[6484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 17:31:58 gbvpi-bedroom sudo[6484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 17:31:58 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=debug msg="completed keyexchange" Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=debug msg="completed challenge" Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:58 gbvpi-bedroom mpd_monitor.sh[6486]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 17:31:58 gbvpi-bedroom sudo[6481]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:58 gbvpi-bedroom volumio[6218]: info: Successfully started MPD Monitor Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 17:31:58 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:58 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 17:31:58 gbvpi-bedroom sudo[6484]: pam_unix(sudo:session): session closed for user root Dec 12 17:31:58 gbvpi-bedroom volumio[6218]: info: Successfully started MPD Monitor Dec 12 17:31:58 gbvpi-bedroom mpd_monitor.sh[6489]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 17:31:58 gbvpi-bedroom go-librespot[6472]: time="2025-12-12T17:31:58-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:31:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:31:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:00 gbvpi-bedroom sudo[6508]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 17:32:00 gbvpi-bedroom sudo[6508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:00 gbvpi-bedroom sudo[6508]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:00 gbvpi-bedroom sudo[6510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 17:32:00 gbvpi-bedroom sudo[6510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:00 gbvpi-bedroom sudo[6510]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:00 gbvpi-bedroom sudo[6513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 12 17:32:00 gbvpi-bedroom sudo[6513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:00 gbvpi-bedroom sudo[6513]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:00 gbvpi-bedroom volumio[6218]: info: Upmpdcli Daemon Started Dec 12 17:32:00 gbvpi-bedroom volumio[6218]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 12 17:32:00 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:00 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Dec 12 17:32:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:02 gbvpi-bedroom go-librespot[6516]: go-librespot daemon starting... Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=debug msg="app state loaded" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05: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]" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05: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]" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05: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]" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=info msg="zeroconf server listening on port 35071" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=debug msg="obtained new client token: AADfjYceOMiamaPbDbiLkjh6MqfksZ8qtraw/lh8q9UfNkBs0uPiqGWfIiaURlVGhFWWCiM8IB0yk75oONQyqps6Wc+fGOMIvvTdhYKRC7U+K4Eot9dVEg3UDlwaE4sXnDI0nLiYt2uU/Kn/ItNwNrxTe1d7Su7Ih3CCZQRPyz3LUeJAdO8LQiJIgTmvLZ74XOL+KfB5iJYsay9gF/zRmsc1YeYL4LRm+S9MwCZLXGp7VpZUDiQcxxk5sQ==" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=debug msg="completed challenge" Dec 12 17:32:02 gbvpi-bedroom go-librespot[6517]: time="2025-12-12T17:32:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:03 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 3. Dec 12 17:32:03 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:32:03 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: No valid Plugin REST Endpoint Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: 20251212 17:32:03.543 [6524.6524] ERROR SampleApp: api request was not successful Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: Error: Application ID was not specified! Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -m|--manufacturer: Manufacturer of the device Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -n|--deviceName: Device name Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -l|--model: Device's model name Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -s|--serialNumber: Device's serial number Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -o|--outputDevice: ALSA PCM device to play audio to Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -p|--port: Port to run the local configuration HTTP server on Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 12 17:32:03 gbvpi-bedroom qobuz-connect[6524]: -h|--help: Print this help Dec 12 17:32:03 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:03 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin bluetooth to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin multiroom to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin metavolumio to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin cd_controller to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 12 17:32:03 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: Starting MyVolumio Remote Streaming Endpoints Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: MyVolumio login type: Token Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: Streaming services startup Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: Starting Streaming Daemon Dec 12 17:32:04 gbvpi-bedroom sudo[6526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 12 17:32:04 gbvpi-bedroom sudo[6526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 12 17:32:04 gbvpi-bedroom sudo[6526]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: error: Cannot start Volumio Streaming Daemon Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:04 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MyVolumio token set successfully Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MYVOLUMIO: Adding device Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MYVOLUMIO: Evaluating Server Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MyVolumio Plan changed: premium Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Removing browser output: myVolumio user plan is not superstar Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Removing audio output: Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MYVOLUMIO: Adding device Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MYVOLUMIO: Evaluating Server Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Remote config written successfully Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Starting Tunnel 1 Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Starting Tunnel Connection Checker Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Completed starting MyVolumio Plugin Dec 12 17:32:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Dec 12 17:32:05 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:05 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:05 gbvpi-bedroom go-librespot[6556]: go-librespot daemon starting... Dec 12 17:32:05 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:05-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:05 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:05-05:00" level=debug msg="app state loaded" Dec 12 17:32:05 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MYVolumio Device enabled Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: MyVolumio status changed Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Streaming services startup Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: Starting Streaming Daemon Dec 12 17:32:05 gbvpi-bedroom sudo[6579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 12 17:32:05 gbvpi-bedroom sudo[6579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 12 17:32:05 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 12 17:32:05 gbvpi-bedroom sudo[6579]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05: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]" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05: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]" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05: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]" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05:00" level=info msg="zeroconf server listening on port 33501" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05:00" level=debug msg="obtained new client token: AAARWJoABteJRr3idE76QueA8ZO4FCwxWhJxESCwPTqVCxmW0c0mFhc10pjEFjjAG8tyGyGyd+4Yt1rMBgoywLXuLkq7WyPREwmbQnleXMpuDTIUVqovKIB8TJpc1Hq3YlNqNC4Gl0412JhhCajNCIdfH3n9DoezzFueKUYTjvAelpm2J/TjJ+pEDUuh+fDbPFLW4Tl/hdc8WcEk80tQ0QXBobP9uNnjCmqjFyRNKs1/ldua1/1E1N0=" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05:00" level=debug msg="completed challenge" Dec 12 17:32:06 gbvpi-bedroom go-librespot[6564]: time="2025-12-12T17:32:06-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 12 17:32:06 gbvpi-bedroom sudo[6585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 12 17:32:06 gbvpi-bedroom sudo[6585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:06 gbvpi-bedroom sudo[6585]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: MRS: MultiRoom plugin initialized Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: MRS: STOPPING SNAPCLIENT Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: MRS: Snap server stop Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: MRS: STOPPING volumioStreaming Dec 12 17:32:06 gbvpi-bedroom sudo[6602]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 12 17:32:06 gbvpi-bedroom sudo[6602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 12 17:32:06 gbvpi-bedroom sudo[6604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 12 17:32:06 gbvpi-bedroom sudo[6604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:06 gbvpi-bedroom sudo[6606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 12 17:32:06 gbvpi-bedroom sudo[6606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:06 gbvpi-bedroom sudo[6610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 12 17:32:06 gbvpi-bedroom sudo[6610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:06 gbvpi-bedroom sudo[6610]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 12 17:32:06 gbvpi-bedroom sudo[6604]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:06 gbvpi-bedroom sudo[6606]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:06 gbvpi-bedroom sudo[6602]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: Preparing to generate the ALSA configuration file Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: Setting Geolocation for MyVolumio to us4 Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:06 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Setting Geolocation for MyVolumio to us4 Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: Removed streaming files Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: volumioStreaming STOPPED Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: SNAPSERVER STOPPED Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: SNAPCLIENT STOPPED Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: error: Cannot start Volumio Streaming Daemon Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Asound.conf file unchanged, so no further update is needed Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Output device has changed, restarting MPD Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Output device has changed, restarting Shairport Sync Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:07 gbvpi-bedroom sudo[6616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 17:32:07 gbvpi-bedroom sudo[6616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:07 gbvpi-bedroom sudo[6614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 17:32:07 gbvpi-bedroom sudo[6614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:07 gbvpi-bedroom sudo[6614]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 12 17:32:07 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: Pushing multiroomSync output for this device Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: Pushing multiroomSync output Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding audio output: Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding audio output: Dec 12 17:32:07 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 17:32:07 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 17:32:07 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.909s CPU time. Dec 12 17:32:07 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 17:32:07 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 17:32:07 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 12 17:32:07 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.49821 Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding METAVOLUMIO REST API Endpoints Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Preparing CD Folders Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding CD REST API Endpoints Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Starting UDEV Watcher for CD Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: Detecting CD presence with UDEV Dec 12 17:32:07 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 12 17:32:07 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.49821 disconnected from D-Bus Dec 12 17:32:07 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 17:32:07 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 17:32:07 gbvpi-bedroom sudo[6634]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 17:32:07 gbvpi-bedroom sudo[6634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 17:32:07 gbvpi-bedroom sudo[6634]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:08 gbvpi-bedroom mpd[6636]: 2025-12-12T17:32:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 17:32:08 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 17:32:08 gbvpi-bedroom sudo[6616]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:08 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 4. Dec 12 17:32:08 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:32:08 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:32:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Dec 12 17:32:09 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:09 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:09 gbvpi-bedroom go-librespot[6640]: go-librespot daemon starting... Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=debug msg="app state loaded" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05: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]" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05: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]" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05: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]" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=info msg="zeroconf server listening on port 45155" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=debug msg="obtained new client token: AAAuTLWbIRFmpF2ipdvgL6Cw5DW9YA4hf0bYNnOzEhACHPKjUKFA/2X6CygyAzUB8xI73O0NKyV6Wk2myi1xkUEqJ0rXY5UavICohQVZ6ZKscOIoGmJh1YoB7cJoLAjp5En3cjmHSB1TvVbot7TGXsRXoha6q5o6BHyeOtLNHfb6YIX7JafAftM1zav5X95QxfYQp4z4DUms37qZcsy8k2+E8PqggdCWy+92WD1QP++P5jFQJO8EqjKLLQ==" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=debug msg="completed challenge" Dec 12 17:32:09 gbvpi-bedroom go-librespot[6641]: time="2025-12-12T17:32:09-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding inputs REST Endpoints Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Scanning Audio Inputs Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Checking against Known Cards name Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding Server instance for streaming Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: error: Hi Res Audio Failed Login: Missing Login Data Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 12 17:32:12 gbvpi-bedroom sudo[6666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 12 17:32:12 gbvpi-bedroom sudo[6666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding TIDAL REST API Endpoints Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Stopping AccessToken refresher cron for QOBUZ Dec 12 17:32:12 gbvpi-bedroom sudo[6673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 12 17:32:12 gbvpi-bedroom sudo[6673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:12 gbvpi-bedroom sudo[6666]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: AccessToken refresher cron started for QOBUZ Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding QOBUZ REST API Endpoints Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Updating MyVolumio device info Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Updating MyVolumio device info Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom sudo[6673]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: MRS: Getting audio outputs on start Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: MRS: Requesting all other devices output Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:12 gbvpi-bedroom sudo[6676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 12 17:32:12 gbvpi-bedroom sudo[6676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Successfully Added MyVolumio device Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Successfully Added MyVolumio device Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 12 17:32:12 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: MPD Permissions set Dec 12 17:32:12 gbvpi-bedroom sudo[6680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 12 17:32:12 gbvpi-bedroom sudo[6680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Executing endpoint qc_getconfig Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 17:32:12 gbvpi-bedroom sudo[6676]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:12 gbvpi-bedroom sudo[6680]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: error: updateQueue error: null Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioStop Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::stop Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Executing endpoint qc_getconfig Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.605 [6678.6678] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.609 [6678.6678] INFO VolumeManager: [0x1385588]: Setting new playback volume: 75 Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.609 [6678.6678] INFO VolumeManager: [0x1385588]: Setting new mute state: 0 Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.609 [6678.6678] INFO QobuzConnect: [0x1385f58]: Client initialized! Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.609 [6678.6678] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Starting Shairport Sync Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding audio output: Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.631 [6678.6678] INFO LocalConfigManager: [0x1384e68]: Starting Local Configuration server Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.631 [6678.6678] INFO SampleApp: Starting Local configuration server Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.631 [6678.6678] INFO SampleApp: Connected to UNIX socket client 0x136f818 Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Adding audio output: Dec 12 17:32:12 gbvpi-bedroom sudo[6702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 12 17:32:12 gbvpi-bedroom sudo[6702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:12 gbvpi-bedroom sudo[6704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 17:32:12 gbvpi-bedroom sudo[6704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Successfully Updated MyVolumio device Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 17:32:12 gbvpi-bedroom autossh[5568]: received signal to exit (15) Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 12 17:32:12 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Successfully Updated MyVolumio device Dec 12 17:32:12 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.632s CPU time. Dec 12 17:32:12 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 17:32:12 gbvpi-bedroom qobuz-connect[6678]: 20251212 17:32:12.755 [6678.6678] INFO SampleApp: Playback volume changed: 75 Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 17:32:12 gbvpi-bedroom sudo[6704]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Shairport-Sync Started Dec 12 17:32:12 gbvpi-bedroom sudo[6702]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: Remote SSH Started Dec 12 17:32:12 gbvpi-bedroom autossh[6712]: port set to 0, monitoring disabled Dec 12 17:32:12 gbvpi-bedroom autossh[6712]: starting ssh (count 1) Dec 12 17:32:12 gbvpi-bedroom autossh[6712]: ssh child pid is 6715 Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:12 gbvpi-bedroom volumiossh-tunnel[6715]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts. Dec 12 17:32:12 gbvpi-bedroom volumio[6218]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 17:32:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Dec 12 17:32:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:13 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:13 gbvpi-bedroom go-librespot[6730]: go-librespot daemon starting... Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=debug msg="app state loaded" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05: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]" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05: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]" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05: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]" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=info msg="zeroconf server listening on port 46371" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=debug msg="obtained new client token: AAADDXpZlKWF18CRWNsd7q5uazpNpBK11ztXb6TJJ8yHYJduu0CUaGp+VpGUJezDmkKuM7tYc4/AoqivjE2WUyWUQWDT1sEFZzHxXdk6DRkT3vzB5XTVMmPyd0MhnZvnbXNhpAbMb2w/r+HJb+x/zTHihTU2JXE3lznpzAQZF6XyVpmK9VQBciyWEFQCLboGkiwhYMETqTDKHs505Gte01I2do8uVsPcDPIkVhtdT1A/g8w+Fg+TmazvBg==" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=debug msg="completed challenge" Dec 12 17:32:13 gbvpi-bedroom go-librespot[6731]: time="2025-12-12T17:32:13-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:14 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:14 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:14 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:32:14 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:32:14 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:32:14 gbvpi-bedroom volumio[6218]: info: Listing playlists Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: TidalConnect service stoped! Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 12 17:32:15 gbvpi-bedroom sudo[6747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 12 17:32:15 gbvpi-bedroom sudo[6747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:15 gbvpi-bedroom sudo[6751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 17:32:15 gbvpi-bedroom sudo[6751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:15 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 12 17:32:15 gbvpi-bedroom sudo[6747]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:15 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 17:32:15 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 17:32:15 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 17:32:15 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 17:32:15 gbvpi-bedroom sudo[6751]: pam_unix(sudo:session): session closed for user root Dec 12 17:32:15 gbvpi-bedroom mpd_monitor.sh[6755]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Successfully started MPD Monitor Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Executing endpoint tc_getconfig Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 12 17:32:15 gbvpi-bedroom vtcs[6753]: STARTING TidalConnect services, version: 1.5.2.56 Dec 12 17:32:15 gbvpi-bedroom vtcs[6753]: STARTED TidalConnect services. Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Executing endpoint tc_connect Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Connecting to TidalConnect Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::servicePushState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::pushState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioPushState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: MRS: Pushing multiroomSync output update for this device Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: MRS: Pushing multiroomSync output Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::servicePushState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreStateMachine::pushState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioPushState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: MRS: Pushing multiroomSync output update for this device Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: MRS: Pushing multiroomSync output Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: CorePlayQueue::getTrack 0 Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 17:32:15 gbvpi-bedroom volumio[6218]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 17:32:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Dec 12 17:32:16 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:16 gbvpi-bedroom go-librespot[6773]: go-librespot daemon starting... Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05:00" level=debug msg="app state loaded" Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05: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]" Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05: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]" Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05: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]" Dec 12 17:32:16 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:16-05:00" level=info msg="zeroconf server listening on port 37441" Dec 12 17:32:17 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:17-05:00" level=debug msg="obtained new client token: AACBeKGuENpzEkteIt63YMoKb62fFTrridVYMwMHQ4C9Fzquq3tyTVjJUx/IQrvqk7bHQ5ngmfbmwQMtZOZkHgwf2mpVkFenkHhe7BKQtoYJKwDLvqWMsy3tgPDvW8ycR7dcv0emutM7XIhxA0wiZ+sKLWWc2F5MbAoxTm654PM7+0ixZBWUGNeXte3YNK4U/+bUoKypB3V1bkhXVi8GouwaXzGuMZW+GwE3SrF7e/Bb32hcuhPgMbU=" Dec 12 17:32:17 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:17 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:17-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:17 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:17-05:00" level=debug msg="completed challenge" Dec 12 17:32:17 gbvpi-bedroom go-librespot[6774]: time="2025-12-12T17:32:17-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: TidalConnect service started! Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: [Metrics] CommandRouter: 29s 248.39ms Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumiosetStartupVolume Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::Close All Modals sent Dec 12 17:32:18 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::Close All Modals sent Dec 12 17:32:19 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 12 17:32:19 gbvpi-bedroom volumio[6218]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 12 17:32:19 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:19 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 12 17:32:19 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 12 17:32:19 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 12 17:32:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Dec 12 17:32:20 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:20 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:20 gbvpi-bedroom go-librespot[6784]: go-librespot daemon starting... Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=debug msg="app state loaded" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05: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]" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05: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]" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05: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]" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=info msg="zeroconf server listening on port 42733" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=debug msg="obtained new client token: AACb6HBvzinqCWjYxTwRQ82mqDIAtBK55IK0cqnlID7mfR1W54GZyuRgwkKlpwJUXr9Ld2+xIJrWQTkDcWegXB2Al6q3Bu7zC1dBaFJxoTSCs2clRAoqEJdl+NZkR5oAbBjazR4ATS29YrFz4W/Pm+AxtD9ckkYBlE50KazPXzdzKKwTiG5iw/6XTgM2VzUpSaSZpCv+TSdkxBCP6IQSoyZkejc1quqYOOY9I3EeK9eyIMtoLgIoEDg4Ew==" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=debug msg="completed challenge" Dec 12 17:32:20 gbvpi-bedroom go-librespot[6799]: time="2025-12-12T17:32:20-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:21 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:21 gbvpi-bedroom volumio[6218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:23 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:32:23 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 17:32:23 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 12 17:32:24 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 12 17:32:24 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 12 17:32:24 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

CAUTION

\n
    \n
  • This build may break your network
    • \n
\n

FIX

\n
    \n
  • Wireless and network handling
    • \n
\n","title":"Update v4.080","updateavailable":true} Dec 12 17:32:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Dec 12 17:32:24 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 12 17:32:24 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:24 gbvpi-bedroom go-librespot[6810]: go-librespot daemon starting... Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=debug msg="app state loaded" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetState Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05: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]" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05: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]" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05: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]" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=info msg="zeroconf server listening on port 33655" Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: Initializing connection to go-librespot Websocket Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=debug msg="new websocket client" Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: Connection to go-librespot Websocket established Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=debug msg="obtained new client token: AACaIwaSQ3/o9XOT1VsS1kFarwmOg4uRI66+I0+V485NgtGPabb2uEgpz5eKkhMxArMK4Zj+BdQEOlv4RfGXS77o3zzFG9giC/TK2a0AMRItGfN1216zUya5GLZKoBdOIq4BafpXRZmlO2yWuf+YBVaYeBmRw0VFNNeb8BvUbzSXcVU14sQCgpZdUcwJrypJi5S20QZ+PcFBCYbmPrz7DJ73gNCHnLipvpWsbAmj5QBVGC2ChMZ0SJy3Hg==" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=debug msg="completed keyexchange" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=debug msg="completed challenge" Dec 12 17:32:24 gbvpi-bedroom go-librespot[6811]: time="2025-12-12T17:32:24-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 17:32:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 17:32:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 17:32:24 gbvpi-bedroom volumio[6218]: info: Connection to go-librespot Websocket closed Dec 12 17:32:25 gbvpi-bedroom volumio[6218]: info: BOOT COMPLETED Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: info: Getting Spotify volume Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: errno: -111, Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: code: 'ECONNREFUSED', Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: syscall: 'connect', Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: address: '127.0.0.1', Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: port: 9879, Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: response: undefined Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: } Dec 12 17:32:27 gbvpi-bedroom volumio[6218]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 17:32:27 gbvpi-bedroom sudo[6832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 17:31' Dec 12 17:32:27 gbvpi-bedroom sudo[6832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 17:32:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Dec 12 17:32:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:28 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 17:32:28 gbvpi-bedroom go-librespot[6834]: go-librespot daemon starting... Dec 12 17:32:28 gbvpi-bedroom go-librespot[6835]: time="2025-12-12T17:32:28-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 17:32:28 gbvpi-bedroom go-librespot[6835]: time="2025-12-12T17:32:28-05:00" level=debug msg="app state loaded" Dec 12 17:32:28 gbvpi-bedroom go-librespot[6835]: time="2025-12-12T17:32:28-05:00" level=info msg="api server listening on 127.0.0.1:9879" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="6a0bffa825dc2af90b21170949f5219ba5ab5701" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Dec 10 09:27:23 UTC 2025" VOLUMIO_VERSION="4.075" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4bd01f93a654c7068f4553fbd69478e2"