Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 12 05:51:00 gbvpi-bedroom sudo[32180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 12 05:51:00 gbvpi-bedroom sudo[32180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom sudo[32180]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: MultiRoom plugin initialized Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: STOPPING SNAPCLIENT Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: Snap server stop Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: STOPPING volumioStreaming Dec 12 05:51:00 gbvpi-bedroom sudo[32197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 12 05:51:00 gbvpi-bedroom sudo[32197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 12 05:51:00 gbvpi-bedroom sudo[32199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 12 05:51:00 gbvpi-bedroom sudo[32199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom sudo[32201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 12 05:51:00 gbvpi-bedroom sudo[32201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 12 05:51:00 gbvpi-bedroom sudo[32204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 12 05:51:00 gbvpi-bedroom sudo[32204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom sudo[32204]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 12 05:51:00 gbvpi-bedroom sudo[32197]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 12 05:51:00 gbvpi-bedroom sudo[32201]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom sudo[32199]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Preparing to generate the ALSA configuration file Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Setting Geolocation for MyVolumio to us4 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Setting Geolocation for MyVolumio to us1 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Reading ALSA contributions from plugins. Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: Removed streaming files Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: volumioStreaming STOPPED Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: SNAPSERVER STOPPED Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: SNAPCLIENT STOPPED Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: error: Cannot start Volumio Streaming Daemon Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Asound.conf file written Dec 12 05:51:00 gbvpi-bedroom sudo[32211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 05:51:00 gbvpi-bedroom sudo[32211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom sudo[32211]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Output device has changed, restarting MPD Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Output device has changed, restarting Shairport Sync Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:00 gbvpi-bedroom sudo[32217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 05:51:00 gbvpi-bedroom sudo[32217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom sudo[32217]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:00 gbvpi-bedroom sudo[32219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 05:51:00 gbvpi-bedroom sudo[32219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: Pushing multiroomSync output for this device Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: Pushing multiroomSync output Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding audio output: Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding audio output: Dec 12 05:51:00 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.881s CPU time. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 05:51:00 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.39244 Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding METAVOLUMIO REST API Endpoints Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Preparing CD Folders Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding CD REST API Endpoints Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Starting UDEV Watcher for CD Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: Detecting CD presence with UDEV Dec 12 05:51:00 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 12 05:51:00 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.39244 disconnected from D-Bus Dec 12 05:51:00 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 05:51:00 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 05:51:01 gbvpi-bedroom sudo[32237]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 05:51:01 gbvpi-bedroom sudo[32237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 05:51:01 gbvpi-bedroom sudo[32237]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:02 gbvpi-bedroom mpd[32239]: 2025-12-12T05:51:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 05:51:02 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 05:51:02 gbvpi-bedroom sudo[32219]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 12 05:51:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:02 gbvpi-bedroom go-librespot[32242]: go-librespot daemon starting... Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=debug msg="app state loaded" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-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 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-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 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=info msg="zeroconf server listening on port 38315" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=debug msg="obtained new client token: AABSg///KvWt0ucVRZHQT3LDRQmargD9vX2DZgzxO9wCmwgrMS+x5ptoRDgzMZp6g1G5AHN2sSHrD9LHga1C9CmH9XUNEiZnEM4aeTUJhylO2l7h6UJdrnq3Th7Gb3CWsyW7a5tc4EPj2Csbmu6bTywsw+tXuX6ktlj410JYVtoUhzpze+mpwM+Ikuhc22NqG2yDz5RgPV3xBxx8ed0UYGN6SZ7MVIr29nJECasaF3rHJPMIgi3DO4QXgQ==" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:02 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:02-05:00" level=debug msg="completed challenge" Dec 12 05:51:03 gbvpi-bedroom go-librespot[32243]: time="2025-12-12T05:51:03-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 05:51:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Adding inputs REST Endpoints Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Scanning Audio Inputs Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Checking against Known Cards name Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Adding Server instance for streaming Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: error: Hi Res Audio Failed Login: Missing Login Data Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 12 05:51:05 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 12 05:51:06 gbvpi-bedroom sudo[32269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 12 05:51:06 gbvpi-bedroom sudo[32269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Adding TIDAL REST API Endpoints Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Stopping AccessToken refresher cron for QOBUZ Dec 12 05:51:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 12 05:51:06 gbvpi-bedroom sudo[32276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:06 gbvpi-bedroom sudo[32276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: AccessToken refresher cron started for QOBUZ Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Adding QOBUZ REST API Endpoints Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Updating MyVolumio device info Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Updating MyVolumio device info Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: MRS: Getting audio outputs on start Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: MRS: Requesting all other devices output Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Successfully Added MyVolumio device Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Successfully Added MyVolumio device Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:06 gbvpi-bedroom go-librespot[32278]: go-librespot daemon starting... Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 12 05:51:06 gbvpi-bedroom sudo[32276]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: MPD Permissions set Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:06 gbvpi-bedroom sudo[32269]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=debug msg="app state loaded" Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:06 gbvpi-bedroom sudo[32288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 12 05:51:06 gbvpi-bedroom sudo[32288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:06 gbvpi-bedroom sudo[32287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 12 05:51:06 gbvpi-bedroom sudo[32287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[31744]: 20251212 05:51:06.204 [31744.31744] INFO SampleApp: Stopping Local configuration server Dec 12 05:51:06 gbvpi-bedroom sudo[32287]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: error: updateQueue error: null Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Successfully Updated MyVolumio device Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioStop Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreStateMachine::stop Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Successfully Updated MyVolumio device Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Starting Shairport Sync Dec 12 05:51:06 gbvpi-bedroom sudo[32306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 12 05:51:06 gbvpi-bedroom sudo[32306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Adding audio output: Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51: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 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51: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 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51: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 05:51:06 gbvpi-bedroom sudo[32308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 05:51:06 gbvpi-bedroom sudo[32308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=info msg="zeroconf server listening on port 35847" Dec 12 05:51:06 gbvpi-bedroom autossh[31725]: received signal to exit (15) Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Adding audio output: Dec 12 05:51:06 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 05:51:06 gbvpi-bedroom sudo[32306]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Remote SSH Started Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=debug msg="obtained new client token: AABq8E10o/BkMRHDmEhTEeLUzoqlHV/eDH6UIxXjTZAlDLLZxqp/qOWkILiBBjzSrtBlYlCDHY5AEXaxlU8KfVtFs56Yh3PA/4ACrs1WELhbcmmi/BYomOek1JHw1ArHSvnTGZbnL3miDcU+ePPK3x678Q2T0tg+TBKmDua/DlyUNTfTLf1inxUVqvGuJTc2+eFVOX1SFoFUP6PxuS2AG9ZzazLcoDd3vAAtGXlOS9/AzQuadL8y17YjbQ==" Dec 12 05:51:06 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.631s CPU time. Dec 12 05:51:06 gbvpi-bedroom autossh[32312]: port set to 0, monitoring disabled Dec 12 05:51:06 gbvpi-bedroom autossh[32312]: starting ssh (count 1) Dec 12 05:51:06 gbvpi-bedroom autossh[32312]: ssh child pid is 32315 Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:51:06 gbvpi-bedroom sudo[32308]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51:06-05:00" level=debug msg="completed challenge" Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Shairport-Sync Started Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: 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 05:51:06 gbvpi-bedroom volumiossh-tunnel[32315]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 05:51:06 gbvpi-bedroom go-librespot[32280]: time="2025-12-12T05:51: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 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 05:51:06 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 05:51:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:06 gbvpi-bedroom sudo[32288]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: Executing endpoint qc_getconfig Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.696 [32331.32331] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.700 [32331.32331] INFO VolumeManager: [0x684588]: Setting new playback volume: 75 Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.700 [32331.32331] INFO VolumeManager: [0x684588]: Setting new mute state: 0 Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.700 [32331.32331] INFO QobuzConnect: [0x684f58]: Client initialized! Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.700 [32331.32331] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.711 [32331.32331] INFO LocalConfigManager: [0x683e68]: Starting Local Configuration server Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.711 [32331.32331] INFO SampleApp: Starting Local configuration server Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.711 [32331.32331] INFO SampleApp: Connected to UNIX socket client 0x66e818 Dec 12 05:51:06 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:06.846 [32331.32331] INFO SampleApp: Playback volume changed: 75 Dec 12 05:51:06 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: TidalConnect service stoped! Dec 12 05:51:09 gbvpi-bedroom sudo[32338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 05:51:09 gbvpi-bedroom sudo[32338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:09 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 05:51:09 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 05:51:09 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 12 05:51:09 gbvpi-bedroom sudo[32350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 12 05:51:09 gbvpi-bedroom sudo[32350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:09 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 05:51:09 gbvpi-bedroom mpd_monitor.sh[32348]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 05:51:09 gbvpi-bedroom sudo[32338]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Successfully started MPD Monitor Dec 12 05:51:09 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 12 05:51:09 gbvpi-bedroom sudo[32350]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Executing endpoint tc_getconfig Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 12 05:51:09 gbvpi-bedroom vtcs[32357]: STARTING TidalConnect services, version: 1.5.2.56 Dec 12 05:51:09 gbvpi-bedroom vtcs[32357]: STARTED TidalConnect services. Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Executing endpoint tc_connect Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Connecting to TidalConnect Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::servicePushState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreStateMachine::pushState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioPushState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: MRS: Pushing multiroomSync output update for this device Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: MRS: Pushing multiroomSync output Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::servicePushState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreStateMachine::pushState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioPushState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: MRS: Pushing multiroomSync output update for this device Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: MRS: Pushing multiroomSync output Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 05:51:09 gbvpi-bedroom volumio[31811]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 05:51:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 12 05:51:09 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:09 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:09 gbvpi-bedroom go-librespot[32372]: go-librespot daemon starting... Dec 12 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:09-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:09-05:00" level=debug msg="app state loaded" Dec 12 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:09-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51: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 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51: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 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51: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 05:51:09 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:09-05:00" level=info msg="zeroconf server listening on port 44337" Dec 12 05:51:10 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:10-05:00" level=debug msg="obtained new client token: AABTWC+CwG4UO6rJWr1+fcOsUBBw04MP8mUN1NumhwKp1OlzoEuNHo3Ln78nlT5FNjSvo1Wm6KtgLYsrjcKG/1HJLN8/Of/vGVvxCqdTorZXsnvSc7sNMDEncS5Ati0sNanrsNiRAU82ShKPBGhwt9Yov2/hxq+iL/8G2IkxvXfAJhux+EtSeaZp1zF1MmBNlYIZridXvxXXpTMotAnjt29R4rqN14Y+f/WR5n97UZuEbHhihnpH6fs=" Dec 12 05:51:10 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:10 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:10-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:10 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51:10-05:00" level=debug msg="completed challenge" Dec 12 05:51:10 gbvpi-bedroom go-librespot[32373]: time="2025-12-12T05:51: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 05:51:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: TidalConnect service started! Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: [Metrics] CommandRouter: 29s 405.88ms Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumiosetStartupVolume Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::Close All Modals sent Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::Close All Modals sent Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 12 05:51:12 gbvpi-bedroom volumio[31811]: 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 05:51:12 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Dec 12 05:51:13 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:13 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:13 gbvpi-bedroom go-librespot[32380]: go-librespot daemon starting... Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=debug msg="app state loaded" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51: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 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51: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 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51: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 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=info msg="zeroconf server listening on port 41925" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=debug msg="obtained new client token: AAAyBmKRiDwa1nfJ9J5uQKtiA8uW6IfKf/DzyoAtslf4vdP/8AglDGbdAhU8zaMlLuynxFe3bnaCGkAZJRzgAqgIkWKQDgfml7yhEr5tE6wnV70CRVJFf4ALgSVYDtTgpNPBFALVOnNP11q0oZbu/CXN55Bkx3jPpcxrnIWwXQPtPuY2XI8zgIxyftqXN/m1nsLCfKwcxXnluPWfB8aU/AylLOWLGOSoxDqYWydZzhGQi57OV92+EUJkVg==" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51:13-05:00" level=debug msg="completed challenge" Dec 12 05:51:13 gbvpi-bedroom go-librespot[32381]: time="2025-12-12T05:51: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 05:51:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:13 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:15 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:15 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Dec 12 05:51:16 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:16 gbvpi-bedroom go-librespot[32405]: go-librespot daemon starting... Dec 12 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:16-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:16-05:00" level=debug msg="app state loaded" Dec 12 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:16-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 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:16-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 05:51:16 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:16-05:00" level=info msg="zeroconf server listening on port 38169" Dec 12 05:51:17 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:17-05:00" level=debug msg="obtained new client token: AADDkntjkAaMm3i3u9WRIoQ/oHbGtB6liNm8Q3IzoBPm21PeV/9QyUxWN5W945nMSUvl8DRaYAEpzz7FODhWH5BGaiad22Rg9575t6hMWpKn1ZkJNC5seXoFILk4wokvpkaG/GuIBlLRqZgvKzB0fbdyhI7gpiDbtEjvkX0eXyTotB1BBg/nuBpfsfNxkbEbB4fBQeWv0wgYqr6sMEPK7gYG9+8uVrGZ/OxTrf9S4MY9kqip7HwvkI0=" Dec 12 05:51:17 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:17 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:17-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:17 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51:17-05:00" level=debug msg="completed challenge" Dec 12 05:51:17 gbvpi-bedroom go-librespot[32406]: time="2025-12-12T05:51: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 05:51:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 12 05:51:17 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 12 05:51:17 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 12 05:51:17 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: 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 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 05:51:17 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:51:18 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:18 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:19 gbvpi-bedroom volumio[31811]: info: BOOT COMPLETED Dec 12 05:51:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Dec 12 05:51:20 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:20 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:20 gbvpi-bedroom go-librespot[32418]: go-librespot daemon starting... Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=debug msg="app state loaded" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-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 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-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 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=info msg="zeroconf server listening on port 46227" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=debug msg="obtained new client token: AABvqSVnd1Yi9+OwAZY3U0NFEgyLPkIKM2npKXWMOJrXbC3wJbQk/ZvfofFAE8tR+sa/ZMWgYAKDicwvXRrUUg0Quy6f6aEPEnkxC3oBfoFRSap+qK9aHfxSUEXcUewtJ7eSkjAbV77R9tUWGh5VD4bHrXnn/UiH3Ncc6yodsbcE9TgcQP8Ba1aqLe3RiHLQPfPLIG2/eg/NfMUy2pdUuCkudabKjk3j7rdmoVaPmdREdkUPsbJGvXxK9w==" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51:20-05:00" level=debug msg="completed challenge" Dec 12 05:51:20 gbvpi-bedroom go-librespot[32419]: time="2025-12-12T05:51: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 05:51:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:21 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:21 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:23 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:23 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:24 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:24 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Dec 12 05:51:24 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:24 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:24 gbvpi-bedroom go-librespot[32440]: go-librespot daemon starting... Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=debug msg="app state loaded" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51: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 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51: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 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51: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 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=info msg="zeroconf server listening on port 45917" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=debug msg="obtained new client token: AAAuKDqCe9uNtDe29mWCCGgqsCJRFpYZUEAkgIBaoCAj11nueYYC0iYzQ/uuzg8rEnUirreDm7IRfp+ezKCDJ0BFXVJJsqLT95Cusp1N9Th/OUlxlQOxTtz/C0gH2Iyz+82/7S50iNNxqNx9NTpfmWifYEAYF/YKEYB8j6H9pq9jcVFSU6yxjlotvWENIQ4GAg29sp45h1wS1BFX/O8ztwD6TygCQDE8WtexHpnmHShVSTs/jmGWOxeM9A==" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51:24-05:00" level=debug msg="completed challenge" Dec 12 05:51:24 gbvpi-bedroom go-librespot[32441]: time="2025-12-12T05:51: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 05:51:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:27 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:27 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Dec 12 05:51:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:28 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:28 gbvpi-bedroom go-librespot[32448]: go-librespot daemon starting... Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=debug msg="app state loaded" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-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 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-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 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-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 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=info msg="zeroconf server listening on port 37939" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=debug msg="obtained new client token: AAC7nVvDu6qkuoLLQGE/Z6WrDucV5dKhsio/yFfuQXsoqxtDzjIfLTjM6XR3EARBTnujiYOZOOYc6w5bAg/0i2axi1cF00Bv4u81dPnYUu/7TAroFEaku9KYlcYd9qSGyFbh/N1I2kRouaRQuSVx9zJAXDDk/rdiU+shDq1DbVquiJsgk8/k/m1/EiQBiRWgJGpUMpm5OjCLffrmqHfXK3Z+YNxOIhs5q2dcto/6gr7xx+d0FtT9sFL22w==" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51:28-05:00" level=debug msg="completed challenge" Dec 12 05:51:28 gbvpi-bedroom go-librespot[32449]: time="2025-12-12T05:51: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 05:51:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:30 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:30 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Dec 12 05:51:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:31 gbvpi-bedroom go-librespot[32460]: go-librespot daemon starting... Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=debug msg="app state loaded" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-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 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-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 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=info msg="zeroconf server listening on port 40919" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=debug msg="obtained new client token: AAD78FT8J9UxEfLqKl0eY7DKU/FVMoBogCfXPkaybbnbHUf1cZ0PCkYewCtvac+xR4kOu3WqWOu6hrJ+XcupvGAaQbLFy5eEtcl9LK+0JoaLDM3lRqWzgRzoNGc52sQ//CxzGYDCVPRA808bODc5EaYGboD60NEPQ+tMQgTYObIsBQgMHQg3H99cTAd6yXbCwaxLiiVvaa+0dhZkrK36Yjf0c2nyvpVs72LlqRNe5OcR3Xf9k70WkvHHFw==" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-05:00" level=debug msg="completed challenge" Dec 12 05:51:31 gbvpi-bedroom go-librespot[32461]: time="2025-12-12T05:51:31-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 05:51:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:33 gbvpi-bedroom volumio[31811]: info: Listing playlists Dec 12 05:51:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Dec 12 05:51:35 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:35 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:35 gbvpi-bedroom go-librespot[32482]: go-librespot daemon starting... Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=debug msg="app state loaded" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-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 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-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 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-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 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=info msg="zeroconf server listening on port 38429" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=debug msg="obtained new client token: AADREGWq/mEJWgSaZ88mTAY3NCF6/se2QDCP18uXAIjiwRxgWG6vbg8j5tmwmSJFftad9gdnyKrzLO9bkDmDmAEXYX6gYkWNHpskXn//oObB9er2VpZlWJJKhvcHkHLthqnPB6inNNqNCKU2DH8EAdoRsISMsK+O6ExElCnkKspRbDMpqhFM/1je4ckHYDr5ZWrdBumAY2LxI0++eugt3hMn/QmlzlA8ch/fIo30uGaA/tzN80BUAgf5nw==" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-05:00" level=debug msg="completed challenge" Dec 12 05:51:35 gbvpi-bedroom go-librespot[32483]: time="2025-12-12T05:51:35-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 05:51:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:36 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:36 gbvpi-bedroom volumio[31811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Dec 12 05:51:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:38 gbvpi-bedroom go-librespot[32490]: go-librespot daemon starting... Dec 12 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-05:00" level=debug msg="app state loaded" Dec 12 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-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 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-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 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-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 05:51:38 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:38-05:00" level=info msg="zeroconf server listening on port 44379" Dec 12 05:51:39 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:39-05:00" level=debug msg="obtained new client token: AAA0c2dOuDKxiZPlAQ25Ppj84JdvHhaTLQXfa+2TbiY3E9Tb1/T58sn4QkGT8NESvswUtpADzm1Asws8141x1AlEHhYczilg3fY+SYPSXtayRnO0Ly+al5YOI29yRu0XMA89N6kxuUcUR/Cbwt4lIUiE7oDkyYwlQDFcBFN2MAiSgQTKpWscBJCczje+8nQChoWxdDW/CC63nBT7R2H3pfkwVxrrPGkMkRHbjSOxD6+tK3eW9D1+uoU=" Dec 12 05:51:39 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:39 gbvpi-bedroom volumio[31811]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:39 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:39-05:00" level=debug msg="new websocket client" Dec 12 05:51:39 gbvpi-bedroom volumio[31811]: info: Connection to go-librespot Websocket established Dec 12 05:51:39 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:39-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:39 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:39-05:00" level=debug msg="completed challenge" Dec 12 05:51:39 gbvpi-bedroom go-librespot[32491]: time="2025-12-12T05:51:39-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 05:51:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:39 gbvpi-bedroom volumio[31811]: info: Connection to go-librespot Websocket closed Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: info: Getting Spotify volume Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: errno: -111, Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: code: 'ECONNREFUSED', Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: syscall: 'connect', Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: address: '127.0.0.1', Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: port: 9879, Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: response: undefined Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: } Dec 12 05:51:42 gbvpi-bedroom volumio[31811]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 05:51:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:42 gbvpi-bedroom go-librespot[32511]: go-librespot daemon starting... Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=debug msg="app state loaded" Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:42 gbvpi-bedroom sudo[32520]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 05:50' Dec 12 05:51:42 gbvpi-bedroom sudo[32520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-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 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-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 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-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 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=info msg="zeroconf server listening on port 45337" Dec 12 05:51:42 gbvpi-bedroom sudo[32520]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:42 gbvpi-bedroom vtcs[32357]: [2025-12-12 05:51:42.845] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 12 05:51:42 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:51:42.847 [32331.32331] INFO SampleApp: Socket closed Dec 12 05:51:42 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 05:51:42] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 12 05:51:42 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 05:51:42] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 12 05:51:42 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=debug msg="obtained new client token: AABnJiSqCUr07QHBkhseD6TTKuUQYnFQjkz8t8q31H+Cz4gi6Vjx25sWUhQFUa8qRF5cL34pbcL2tx2zz2WMwxe47fwn4yywhg0BAeuSHnV9rs2gYUmCTNNu6osCQXz5Y6Y8ELpyd75ocSG94JXjFPqPql9cdgoo+aa/09ihfQjAxVt2IwdznH2uiL8lb0/ggCD+WibAB+9qacBrcsnN98leZMSQ+EbNrhBvupVnH/xnth3LnNwNJOjVIA==" Dec 12 05:51:42 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.490s CPU time. Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-05:00" level=debug msg="completed challenge" Dec 12 05:51:42 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2601. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.490s CPU time. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 12 05:51:42 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 12 05:51:42 gbvpi-bedroom go-librespot[32512]: time="2025-12-12T05:51:42-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 05:51:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ----- Volumio3 ---- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ----- System startup ---- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: MYVOLUMIO Environment detected Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Plugin folders cleanup Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning into folder /volumio/app/plugins/ Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category audio_interface Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category miscellanea Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category music_service Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category plugins.json Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category system_controller Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category user_interface Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning into folder /data/plugins/ Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Scanning category music_service Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Plugin folders cleanup completed Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ----- Core plugins startup ---- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Loading plugins from folder /volumio/app/plugins/ Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Adding plugin upnp to MyMusic Plugins Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Loading plugins from folder /data/plugins/ Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Loading plugin "system"... Dec 12 05:51:44 gbvpi-bedroom volumio[32533]: info: Loading plugin "appearance"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "network"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Refreshing Cached IP Addresses Dec 12 05:51:45 gbvpi-bedroom sudo[32561]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 05:51:45 gbvpi-bedroom sudo[32561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:45 gbvpi-bedroom sudo[32561]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:45 gbvpi-bedroom sudo[32563]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 05:51:45 gbvpi-bedroom sudo[32563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "services"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "alsa_controller"... Dec 12 05:51:45 gbvpi-bedroom sudo[32563]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:45 gbvpi-bedroom sudo[32569]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 12 05:51:45 gbvpi-bedroom sudo[32569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "wizard"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "networkfs"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Starting Udev Watcher for removable devices Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Ignoring mount for partition: boot Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Ignoring mount for partition: volumio Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Ignoring mount for partition: volumio_data Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "volumio_command_line_client"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "upnp"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: [1765536705230] Starting Upmpd Daemon Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "my_music"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "mpd"... Dec 12 05:51:45 gbvpi-bedroom volumio[32533]: info: Loading plugin "upnp_browser"... Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Starting UPNP Browser Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "alarm-clock"... Dec 12 05:51:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Dec 12 05:51:46 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:46 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:46 gbvpi-bedroom go-librespot[32594]: go-librespot daemon starting... Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "airplay_emulation"... Dec 12 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-05:00" level=debug msg="app state loaded" Dec 12 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Starting Shairport Sync Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "last_100"... Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "webradio"... Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "i2s_dacs"... Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: I2S DAC not set, start Auto-detection Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "volumiodiscovery"... Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: *** WARNING *** For more information see Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: *** WARNING *** For more information see Dec 12 05:51:46 gbvpi-bedroom node[32533]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 12 05:51:46 gbvpi-bedroom node[32533]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 05:51:46 gbvpi-bedroom node[32533]: *** WARNING *** For more information see Dec 12 05:51:46 gbvpi-bedroom node[32533]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 12 05:51:46 gbvpi-bedroom node[32533]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 12 05:51:46 gbvpi-bedroom node[32533]: *** WARNING *** For more information see Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "jellyfin"... Dec 12 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-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 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-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 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-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 05:51:46 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:46-05:00" level=info msg="zeroconf server listening on port 36405" Dec 12 05:51:46 gbvpi-bedroom volumio[32533]: info: Loading plugin "spop"... Dec 12 05:51:47 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:47-05:00" level=debug msg="obtained new client token: AADGBZm3WS4uXUkIjA7GGPSR0owGmOk+UCO0ZofSWo4tLe96kgG8NSNjbUrkGJ6aTdCxR9eylwvI28VGBVrkI4q8sLZ6WWmBLfN59GBhCBnzZ/rN5ds92Vig/WAPV8WqJ11XUSmrXbq6WUx9cyiqmXgXsfmdd1oB4TJ9q9HjmZeR52AfrL+qTPSYmVmJedobARckTy3fjlEExw81086ZqCBRao9i6zy8H1F4QdfNCfLjJKtLj8EZJ2nN2Q==" Dec 12 05:51:47 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:47-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading plugin "outputs"... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading plugin "albumart"... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Plugin example_plugin is not enabled Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading plugin "inputs"... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading plugin "updater_comm"... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Plugin mpdemulation is not enabled Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading plugin "rest_api"... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading plugin "websocket"... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Starting Socket.io Server version 1.7.4 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Loading i18n strings for locale en Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: Updating browse sources language Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 05:51:47 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:47-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:47 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:47-05:00" level=debug msg="completed challenge" Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::initPlayerControls Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: Express server listening on port 3000 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: [Metrics] WebUI: 3s 805.74ms Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::resetVolumioState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::getcurrentVolume Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioRetrievevolume Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Volumio Network Manager: Network status updated: 2 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: VolumeController:: Volume=91 Mute =false Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::pushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioPushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::updateTrackBlock Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrackBlock Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioRetrievevolume Dec 12 05:51:47 gbvpi-bedroom go-librespot[32595]: time="2025-12-12T05:51:47-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 05:51:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Reloading queue from file Dec 12 05:51:47 gbvpi-bedroom volumio[32605]: Forking 3 albumart workers Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::setRepeat true single undefined Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::pushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioPushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::setRandom null Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::pushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioPushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Setting Device type: Raspberry PI Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: VolumeController:: Volume=91 Mute =false Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::pushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioPushState Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Completed loading Core Plugins Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Preparing to generate the ALSA configuration file Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Asound.conf file written Dec 12 05:51:47 gbvpi-bedroom sudo[32659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 05:51:47 gbvpi-bedroom sudo[32659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:47 gbvpi-bedroom sudo[32659]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Output device has changed, restarting MPD Dec 12 05:51:47 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 05:51:47] [connect] Successful connection Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Output device has changed, restarting Shairport Sync Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 05:51:47 gbvpi-bedroom sudo[32667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 05:51:47 gbvpi-bedroom sudo[32667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: ___________ START PLUGINS ___________ Dec 12 05:51:47 gbvpi-bedroom sudo[32667]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: ControllerMpd::onStart: Initializing MPD Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Creating MPD Configuration file Dec 12 05:51:47 gbvpi-bedroom sudo[32670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 05:51:47 gbvpi-bedroom sudo[32670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: [1765536707917] CoreMusicLibrary::Adding element Media Servers Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 05:51:47 gbvpi-bedroom sudo[32677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: UPNP Browser: Client initialized successfully Dec 12 05:51:47 gbvpi-bedroom sudo[32678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 05:51:47 gbvpi-bedroom sudo[32677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:47 gbvpi-bedroom sudo[32677]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:47 gbvpi-bedroom sudo[32678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:47 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 05:51:47 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:48 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.264s CPU time. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: [1765536708030] CoreMusicLibrary::Adding element Last_100 Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: [1765536708032] CoreMusicLibrary::Adding element Webradio Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Initializing BBC Radios Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 05:51:48 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Discovery: Getting this device information Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: [1765536708211] CoreMusicLibrary::Adding element Jellyfin Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: Cannot find translation for source Jellyfin Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: 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 05:51:48 gbvpi-bedroom volumio[32533]: info: Creating Spotify config file Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom sudo[32706]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 05:51:48 gbvpi-bedroom sudo[32706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 05:51:48 gbvpi-bedroom sudo[32706]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Volumio Calling Home Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Discovery: Found device GBVPi-Bedroom Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: Discovery: Found device GBVPi-Bedroom Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:48 gbvpi-bedroom volumio[32626]: Starting albumart workers Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: MPD Permissions set Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: MPD Permissions set Dec 12 05:51:48 gbvpi-bedroom volumio[32627]: Starting albumart workers Dec 12 05:51:48 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-12 05:51:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765536707 101 Dec 12 05:51:48 gbvpi-bedroom volumio[32628]: Starting albumart workers Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: 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 05:51:48 gbvpi-bedroom volumio[32533]: info: Spotify config file written Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: 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 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom sudo[32714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 12 05:51:48 gbvpi-bedroom sudo[32714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:48 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:49 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:49 gbvpi-bedroom go-librespot[32726]: go-librespot daemon starting... Dec 12 05:51:49 gbvpi-bedroom sudo[32714]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: No need to fix Spotify hosts Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=debug msg="app state loaded" Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:49 gbvpi-bedroom sudo[32569]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Volumio called home Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-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 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-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 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-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 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=info msg="zeroconf server listening on port 39105" Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Starting Shairport Sync Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Starting Shairport Sync Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Starting Shairport Sync Dec 12 05:51:49 gbvpi-bedroom sudo[32745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 05:51:49 gbvpi-bedroom sudo[32745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:49 gbvpi-bedroom sudo[32743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 05:51:49 gbvpi-bedroom sudo[32743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=debug msg="obtained new client token: AAAccB3b1ZstxPAkuG1vPr7NQwUFngemwiKWHPc79MrhO8ZR5Ovh+5vXWxPicxpFB40zl4+oLKRfhZ2w3qJsu8ehBH4GfldXcQPfV7m/Suvaagkqmv3vR+eEwKS5si3SFHDwwl/hvZwpm2I112M0IrANkla6FJ2pA3siY8OLrIPqwQrkWrZdIZD/xxV6mgqEJcxHmujTQ1nWOZbXKe3xpSEEaiMabKxq1V7p3Zl1RdYq4Bbuhupa7hWbgA==" Dec 12 05:51:49 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 05:51:49 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 05:51:49 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:51:49 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.698s CPU time. Dec 12 05:51:49 gbvpi-bedroom sudo[32749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 05:51:49 gbvpi-bedroom sudo[32749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-05:00" level=debug msg="completed challenge" Dec 12 05:51:49 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:51:49 gbvpi-bedroom sudo[32745]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:49 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 05:51:49 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 05:51:49 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:51:49 gbvpi-bedroom go-librespot[32727]: time="2025-12-12T05:51:49-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 05:51:49 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:51:49 gbvpi-bedroom sudo[32743]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:49 gbvpi-bedroom sudo[32749]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Shairport-Sync Started Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: Error adding Membership: Error: addMembership EINVAL Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Shairport-Sync Started Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: Shairport-Sync Started Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:49 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:50 gbvpi-bedroom mpd[32708]: 2025-12-12T05:51:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 05:51:50 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 05:51:50 gbvpi-bedroom sudo[32678]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:50 gbvpi-bedroom sudo[32670]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: info: Completed starting Core Plugins Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: info: ----- MyVolumio plugins startup ---- Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: info: ------------------------------------------- Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: error: MPD error: The expression evaluated to a falsy value: Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: assert.ok(self.idling) Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: error: The expression evaluated to a falsy value: Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: assert.ok(self.idling) Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: info: MPD running with PID32708 Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: ,establishing connection Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: error: updateQueue error: null Dec 12 05:51:50 gbvpi-bedroom volumio[32533]: error: updateQueue error: null Dec 12 05:51:52 gbvpi-bedroom volumio[32533]: info: go-librespot daemon successfully initialized Dec 12 05:51:52 gbvpi-bedroom volumio[32533]: info: Discovery: Browse raised the following error Error: dns service error: unknown Dec 12 05:51:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Dec 12 05:51:52 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:53 gbvpi-bedroom go-librespot[320]: go-librespot daemon starting... Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=debug msg="app state loaded" Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-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 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-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 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-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 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=info msg="zeroconf server listening on port 42403" Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=debug msg="obtained new client token: AAD1wfXBdBtN7mxq2QJSl+0ofpvXOWo2W+ZdLKJrh5Aj47CGK1pq8FeIQeVtbOkhb0lLHKAr3X//fQ7eaicC7p9TFt1ru0Bt3XShSpUCA+vhM3vpr+s4ooeCt08ns0U/9AINoZiKxVxejJBDXj+w4uU0memH8E+ryOLV/ZqT/PstKkFzx1I2iMFNWKMSMh+hJsyCFqkTJ342w2xqP5xqyl46v65PWVWvTyUliVnyBnyXxEIBQPaGv0lTog==" Dec 12 05:51:53 gbvpi-bedroom sudo[330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 05:51:53 gbvpi-bedroom sudo[330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:53 gbvpi-bedroom sudo[332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 05:51:53 gbvpi-bedroom sudo[332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 05:51:53 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-05:00" level=debug msg="completed challenge" Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 05:51:53 gbvpi-bedroom sudo[330]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:53 gbvpi-bedroom mpd_monitor.sh[335]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: Successfully started MPD Monitor Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 05:51:53 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 05:51:53 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 05:51:53 gbvpi-bedroom sudo[332]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:53 gbvpi-bedroom go-librespot[321]: time="2025-12-12T05:51:53-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 05:51:53 gbvpi-bedroom volumio[32533]: info: Successfully started MPD Monitor Dec 12 05:51:53 gbvpi-bedroom mpd_monitor.sh[339]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 05:51:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:51:53 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:51:55 gbvpi-bedroom sudo[360]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 12 05:51:55 gbvpi-bedroom sudo[360]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:55 gbvpi-bedroom sudo[360]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:55 gbvpi-bedroom sudo[362]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 12 05:51:55 gbvpi-bedroom sudo[362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:55 gbvpi-bedroom sudo[362]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:55 gbvpi-bedroom sudo[365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 12 05:51:55 gbvpi-bedroom sudo[365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:55 gbvpi-bedroom sudo[365]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:55 gbvpi-bedroom volumio[32533]: info: Upmpdcli Daemon Started Dec 12 05:51:55 gbvpi-bedroom volumio[32533]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 12 05:51:55 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:55 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:56 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Dec 12 05:51:56 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:56 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:51:56 gbvpi-bedroom go-librespot[368]: go-librespot daemon starting... Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=debug msg="app state loaded" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-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 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-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 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-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 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=info msg="zeroconf server listening on port 34869" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=debug msg="obtained new client token: AACsAiSUAHIQLapZp5TZjuxtu49L+y4w0KT8Lu6nzOzuxz88Fc73utvNGcc84r/9sViqWNYkSUr5b9grIy8sQw8d6g3MGyFQcD9TsxpNZxYENDAGvCKdriRdt/NC7IGkLjiQShpZ7ax65rhvoJ9z1l/ixMJIq+NgLWoilU12gAKEaQbLUHx8oziQf+VrJYPGIddwHteOHIyu8//07zZbfQDMZTPVxynxmE+7xPLJwBBgMPxHmrk0+ak9yA==" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=debug msg="completed keyexchange" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-05:00" level=debug msg="completed challenge" Dec 12 05:51:56 gbvpi-bedroom go-librespot[369]: time="2025-12-12T05:51:56-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 05:51:56 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:51:56 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin bluetooth to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin multiroom to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin metavolumio to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin cd_controller to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 12 05:51:58 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: Starting MyVolumio Remote Streaming Endpoints Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: MyVolumio login type: Token Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: Streaming services startup Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: Starting Streaming Daemon Dec 12 05:51:59 gbvpi-bedroom sudo[377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 12 05:51:59 gbvpi-bedroom sudo[377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 12 05:51:59 gbvpi-bedroom sudo[377]: pam_unix(sudo:session): session closed for user root Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: error: Cannot start Volumio Streaming Daemon Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 05:51:59 gbvpi-bedroom volumio[32533]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 12 05:51:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Dec 12 05:51:59 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:00 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:00 gbvpi-bedroom go-librespot[384]: go-librespot daemon starting... Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=debug msg="app state loaded" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-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 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-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 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-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 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=info msg="zeroconf server listening on port 46139" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=debug msg="obtained new client token: AABWY00zpkVupwNTxvfPc3+i0teNTQereYOlNIXe1Zu1hhe2/woRH5ID2+CWmpXfRgayAWkU6aAGj9xZNTCTViTqllDb+cLNlFq53YGNXt3dRO+8sgyNMV8GfWpPSrSWiw/hMc7PQfR2zwm53a2vE7Wq56pidRgB7iZyljbaSV8SVQdRZNNIEPhBVtm5HFeYocXlSq0Su+6v/bg00hZujx1c0jzwwFXUIVASQqRzMZ9UZpNbsM2Z0s6p1w==" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-05:00" level=debug msg="completed challenge" Dec 12 05:52:00 gbvpi-bedroom go-librespot[388]: time="2025-12-12T05:52:00-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 05:52:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MyVolumio token set successfully Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MYVOLUMIO: Adding device Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MYVOLUMIO: Evaluating Server Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MyVolumio Plan changed: premium Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Removing browser output: myVolumio user plan is not superstar Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Removing audio output: Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MYVOLUMIO: Adding device Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MYVOLUMIO: Evaluating Server Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Remote config written successfully Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Starting Tunnel 1 Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Starting Tunnel Connection Checker Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Completed starting MyVolumio Plugin Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MYVolumio Device enabled Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: MyVolumio status changed Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Streaming services startup Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: Starting Streaming Daemon Dec 12 05:52:00 gbvpi-bedroom sudo[436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 12 05:52:00 gbvpi-bedroom sudo[436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 12 05:52:00 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 12 05:52:00 gbvpi-bedroom sudo[436]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 12 05:52:01 gbvpi-bedroom sudo[441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 12 05:52:01 gbvpi-bedroom sudo[441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:01 gbvpi-bedroom sudo[441]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: MRS: MultiRoom plugin initialized Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: MRS: STOPPING SNAPCLIENT Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: MRS: Snap server stop Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: MRS: STOPPING volumioStreaming Dec 12 05:52:01 gbvpi-bedroom sudo[459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 12 05:52:01 gbvpi-bedroom sudo[459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:01 gbvpi-bedroom sudo[461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 12 05:52:01 gbvpi-bedroom sudo[461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:01 gbvpi-bedroom sudo[466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 12 05:52:01 gbvpi-bedroom sudo[466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:01 gbvpi-bedroom sudo[465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 12 05:52:01 gbvpi-bedroom sudo[466]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:01 gbvpi-bedroom sudo[465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 12 05:52:01 gbvpi-bedroom sudo[459]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 12 05:52:01 gbvpi-bedroom sudo[461]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 12 05:52:01 gbvpi-bedroom sudo[465]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: Preparing to generate the ALSA configuration file Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: Setting Geolocation for MyVolumio to us4 Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:01 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Reading ALSA contributions from plugins. Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Setting Geolocation for MyVolumio to us4 Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: Removed streaming files Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: volumioStreaming STOPPED Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: SNAPSERVER STOPPED Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: SNAPCLIENT STOPPED Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: error: Cannot start Volumio Streaming Daemon Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Asound.conf file written Dec 12 05:52:02 gbvpi-bedroom sudo[472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 12 05:52:02 gbvpi-bedroom sudo[472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:02 gbvpi-bedroom sudo[472]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Output device has changed, restarting MPD Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Output device has changed, restarting Shairport Sync Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:02 gbvpi-bedroom sudo[478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 12 05:52:02 gbvpi-bedroom sudo[478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:02 gbvpi-bedroom sudo[480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 12 05:52:02 gbvpi-bedroom sudo[480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 05:52:02 gbvpi-bedroom sudo[478]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 12 05:52:02 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: Pushing multiroomSync output for this device Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: Pushing multiroomSync output Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding audio output: Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding audio output: Dec 12 05:52:02 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 12 05:52:02 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 12 05:52:02 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.947s CPU time. Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:02 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 12 05:52:02 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 12 05:52:02 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding METAVOLUMIO REST API Endpoints Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Preparing CD Folders Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding CD REST API Endpoints Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Starting UDEV Watcher for CD Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: Detecting CD presence with UDEV Dec 12 05:52:02 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 12 05:52:02 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.39260 Dec 12 05:52:02 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.39260 disconnected from D-Bus Dec 12 05:52:02 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 12 05:52:02 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 12 05:52:02 gbvpi-bedroom sudo[498]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 12 05:52:02 gbvpi-bedroom sudo[498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 12 05:52:02 gbvpi-bedroom sudo[498]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Dec 12 05:52:03 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:03 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:03 gbvpi-bedroom go-librespot[501]: go-librespot daemon starting... Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=debug msg="app state loaded" Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:03 gbvpi-bedroom mpd[500]: 2025-12-12T05:52:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 12 05:52:03 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 12 05:52:03 gbvpi-bedroom sudo[480]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-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 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-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 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-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 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=info msg="zeroconf server listening on port 39455" Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=debug msg="obtained new client token: AAAWNcEhwU0olbHjcLeA6JxPa3CHKAB2D5ItVekHm1r/pf6T2Bz7pEelDDlOxqV8iIXb9JGsGChRFwbA72D+PghlSga4+dwZ00JswCT6lirf7LL7Zf428WSsFV1ATPyGMJSebkheb2HRxda6+HTMTcGEbSv0h+ik9gYU6bulbseF/IWB72MHg4geNs1Mzo+ZdxaPE02oUh6f9fOUY4hxDb7h9G9bmkJTQUACk0NFkQZUK0iroi/SVCC9WA==" Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:03 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:03-05:00" level=debug msg="completed challenge" Dec 12 05:52:05 gbvpi-bedroom go-librespot[502]: time="2025-12-12T05:52:05-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 05:52:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding inputs REST Endpoints Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Scanning Audio Inputs Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Checking against Known Cards name Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding Server instance for streaming Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: error: Hi Res Audio Failed Login: Missing Login Data Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 12 05:52:07 gbvpi-bedroom sudo[530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 12 05:52:07 gbvpi-bedroom sudo[530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding TIDAL REST API Endpoints Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Stopping AccessToken refresher cron for QOBUZ Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 12 05:52:07 gbvpi-bedroom sudo[537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 12 05:52:07 gbvpi-bedroom sudo[537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:07 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 32363 (vtcs) with signal SIGKILL. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 12 05:52:07 gbvpi-bedroom sudo[530]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: AccessToken refresher cron started for QOBUZ Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding QOBUZ REST API Endpoints Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Updating MyVolumio device info Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Updating MyVolumio device info Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: MRS: Getting audio outputs on start Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: MRS: Requesting all other devices output Dec 12 05:52:07 gbvpi-bedroom sudo[537]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:07 gbvpi-bedroom sudo[540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 12 05:52:07 gbvpi-bedroom sudo[540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Successfully Added MyVolumio device Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 12 05:52:07 gbvpi-bedroom qobuz-connect[32331]: 20251212 05:52:07.529 [32331.32331] INFO SampleApp: Stopping Local configuration server Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Successfully Added MyVolumio device Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: MPD Permissions set Dec 12 05:52:07 gbvpi-bedroom sudo[543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 12 05:52:07 gbvpi-bedroom sudo[543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:07 gbvpi-bedroom sudo[543]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioStop Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::stop Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: error: updateQueue error: null Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Starting Shairport Sync Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Successfully Updated MyVolumio device Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding audio output: Dec 12 05:52:07 gbvpi-bedroom sudo[559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 12 05:52:07 gbvpi-bedroom sudo[559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Adding audio output: Dec 12 05:52:07 gbvpi-bedroom sudo[561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 12 05:52:07 gbvpi-bedroom sudo[561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 12 05:52:07 gbvpi-bedroom autossh[32312]: received signal to exit (15) Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 12 05:52:07 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.631s CPU time. Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 12 05:52:07 gbvpi-bedroom sudo[561]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:07 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Shairport-Sync Started Dec 12 05:52:07 gbvpi-bedroom sudo[559]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: info: Remote SSH Started Dec 12 05:52:07 gbvpi-bedroom autossh[569]: port set to 0, monitoring disabled Dec 12 05:52:07 gbvpi-bedroom autossh[569]: starting ssh (count 1) Dec 12 05:52:07 gbvpi-bedroom autossh[569]: ssh child pid is 576 Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: 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 05:52:07 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:07 gbvpi-bedroom volumiossh-tunnel[576]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts. Dec 12 05:52:07 gbvpi-bedroom volumio[32533]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 05:52:08 gbvpi-bedroom volumio[32533]: info: Successfully Updated MyVolumio device Dec 12 05:52:08 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 12 05:52:08 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 05:52:08 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 12 05:52:08 gbvpi-bedroom sudo[540]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Dec 12 05:52:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:08 gbvpi-bedroom go-librespot[593]: go-librespot daemon starting... Dec 12 05:52:08 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:08-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:08 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:08-05:00" level=debug msg="app state loaded" Dec 12 05:52:08 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:08 gbvpi-bedroom volumio[32533]: info: Executing endpoint qc_getconfig Dec 12 05:52:08 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.937 [592.592] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 12 05:52:08 gbvpi-bedroom volumio[32533]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 12 05:52:08 gbvpi-bedroom volumio[32533]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.942 [592.592] INFO VolumeManager: [0x92588]: Setting new playback volume: 75 Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.942 [592.592] INFO VolumeManager: [0x92588]: Setting new mute state: 0 Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.942 [592.592] INFO QobuzConnect: [0x92f58]: Client initialized! Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.942 [592.592] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.966 [592.592] INFO LocalConfigManager: [0x91e68]: Starting Local Configuration server Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.966 [592.592] INFO SampleApp: Starting Local configuration server Dec 12 05:52:08 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:08.967 [592.592] INFO SampleApp: Connected to UNIX socket client 0x7c818 Dec 12 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52: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 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52: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 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52: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 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:09-05:00" level=info msg="zeroconf server listening on port 33697" Dec 12 05:52:09 gbvpi-bedroom qobuz-connect[592]: 20251212 05:52:09.087 [592.592] INFO SampleApp: Playback volume changed: 75 Dec 12 05:52:09 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:09-05:00" level=debug msg="obtained new client token: AACBTsYwNHT2muKbkmEsN06gqP+Xv29F3YMM4A5QBZhYH8PyxdNcBxJyUxlH4Ew+YR8C1O//0lkyzPLL2xwUyxYxvfNVZeCogojcP3moWycSePFGZu7vXI6FOiU9v1aycbQUNlQBqp8ekbIVra5XGS8C42cVPA4VOlFS591BhRbX2GyhRL5vvub/QCvlQYVndqPeEG7ZduVKiJhOTdmGFfZsZDeuCagIpXI2bCmSj5tFWK2aOjHTY8o=" Dec 12 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:09-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52:09-05:00" level=debug msg="completed challenge" Dec 12 05:52:09 gbvpi-bedroom go-librespot[594]: time="2025-12-12T05:52: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 05:52:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: TidalConnect service stoped! Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 12 05:52:10 gbvpi-bedroom sudo[615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 12 05:52:10 gbvpi-bedroom sudo[615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:10 gbvpi-bedroom sudo[619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 12 05:52:10 gbvpi-bedroom sudo[619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 05:52:10 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 12 05:52:10 gbvpi-bedroom sudo[615]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:10 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 12 05:52:10 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 12 05:52:10 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 12 05:52:10 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 12 05:52:10 gbvpi-bedroom sudo[619]: pam_unix(sudo:session): session closed for user root Dec 12 05:52:10 gbvpi-bedroom mpd_monitor.sh[623]: MPD Monitor Service: Starting MPD Monitor Service Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Successfully started MPD Monitor Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Executing endpoint tc_getconfig Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 12 05:52:10 gbvpi-bedroom vtcs[621]: STARTING TidalConnect services, version: 1.5.2.56 Dec 12 05:52:10 gbvpi-bedroom vtcs[621]: STARTED TidalConnect services. Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Executing endpoint tc_connect Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Connecting to TidalConnect Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::servicePushState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::pushState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioPushState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: MRS: Pushing multiroomSync output update for this device Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: MRS: Pushing multiroomSync output Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::servicePushState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreStateMachine::pushState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioPushState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: MRS: Pushing multiroomSync output update for this device Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: MRS: Pushing multiroomSync output Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: CorePlayQueue::getTrack 0 Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Dec 12 05:52:10 gbvpi-bedroom volumio[32533]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 12 05:52:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Dec 12 05:52:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:12 gbvpi-bedroom go-librespot[641]: go-librespot daemon starting... Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=debug msg="app state loaded" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-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 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-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 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-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 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=info msg="zeroconf server listening on port 35467" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=debug msg="obtained new client token: AABs8/QGeayyynmLBB3bn4SHW2rPRAeAUBk7fH6zXkbCZGNtN3yzJmQb1llb1uYmc1BoSGfTg7D16dMgF60hyfu+l1ej9AYdo67Zw/74b6Q9DGaXfbZufWBUx42ce+Z/9SPj8pbtswrV/JkRBElsMuiwECaqtU7zB4YauKLi6W4gNYKpDzyubemFRfqcVOLXaPWIH+LH0+JspfgcZgzqjfrl8MVgNB05J4CF0K+MwWwnAJaZQI3un6xKzg==" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-05:00" level=debug msg="completed challenge" Dec 12 05:52:12 gbvpi-bedroom go-librespot[642]: time="2025-12-12T05:52:12-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 05:52:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: TidalConnect service started! Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: [Metrics] CommandRouter: 29s 584.32ms Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumiosetStartupVolume Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::Close All Modals sent Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::Close All Modals sent Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:52:13 gbvpi-bedroom volumio[32533]: info: Listing playlists Dec 12 05:52:14 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 12 05:52:14 gbvpi-bedroom volumio[32533]: 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 05:52:14 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:14 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 12 05:52:14 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 12 05:52:14 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 12 05:52:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Dec 12 05:52:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:16 gbvpi-bedroom go-librespot[668]: go-librespot daemon starting... Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=debug msg="app state loaded" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-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 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-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 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=info msg="zeroconf server listening on port 35197" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=debug msg="obtained new client token: AAAvZ927/GHrkEdjsTRaBLBkAOQiGHmejEnEiezp/PrFTTft8AnzrWI1DVyNtU/ADFFR62hcrHg2uvjMxVmI1Keq3IkxQEooEvDdVJEwyu9DeFkUwMI3ty5S6iXxvRA2Hw2CApIfNV/nJnUD7mCieg0ORDjsvvMyfGImH8YVg3jnKzS2/s4adPjNje6FIM47toBp9stWGc7P6zlZ7ahE6+3aV0HotgsusPs4YD24fwzgoE9Pxtzzl8PvMg==" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-05:00" level=debug msg="completed challenge" Dec 12 05:52:16 gbvpi-bedroom go-librespot[669]: time="2025-12-12T05:52:16-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 05:52:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:16 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:16 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:18 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:52:18 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 12 05:52:18 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 12 05:52:18 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 12 05:52:18 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 12 05:52:18 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 12 05:52:18 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 12 05:52:18 gbvpi-bedroom volumio[32533]: 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 05:52:18 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:19 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Dec 12 05:52:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:19 gbvpi-bedroom go-librespot[680]: go-librespot daemon starting... Dec 12 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-05:00" level=debug msg="app state loaded" Dec 12 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-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 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-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 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-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 05:52:19 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:19-05:00" level=info msg="zeroconf server listening on port 45511" Dec 12 05:52:20 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:20-05:00" level=debug msg="obtained new client token: AAC2HMZNaG1oSLNsdjACwHYb9lMNjjuSv30LMyFOW4oWPaBN7DoUYHMdfOqzqHDrJHuSIcTS3NYZnf2+Oymb484ioXV3eswttdM7F10rBTleuiZBdTqkooI+RX0i4RigZxbw1glZqrjhXnKn51c5WNQdSwA5XF7EU1GM4QtRuaKh7rANOAPF9eI8tWFk2YyKV4G7rGZiXsJheguj2qedJCzn4RtfULOuv56xdPZH49Ut2LKsF1NNq88=" Dec 12 05:52:20 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:20 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:20-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:20 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52:20-05:00" level=debug msg="completed challenge" Dec 12 05:52:20 gbvpi-bedroom go-librespot[681]: time="2025-12-12T05:52: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 05:52:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:20 gbvpi-bedroom volumio[32533]: info: BOOT COMPLETED Dec 12 05:52:22 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:22 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Dec 12 05:52:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:23 gbvpi-bedroom go-librespot[689]: go-librespot daemon starting... Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=debug msg="app state loaded" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-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 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-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 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-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 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=info msg="zeroconf server listening on port 36193" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=debug msg="obtained new client token: AACZEd9tyzHUzTs1ezSocW2TjWY62YshBB+U621SuXyqCWZS3yHDX2iMsCQ4p8me641cejIFz1sODYf6fpfohF1/RA7OuCkdxUz8Psl/7ET8bH6QzPJFvHiOBiMrj/+2P5NnfIDntzZMroa2rEA6TqIuFkAXBb73lDyedwiSHWoU+mWaijx/yfC4211zM0YoAQ8RJDMSF+VV4I/RABj7uJWc3ps09fgL4fufbIQpIJRw+14ox7vCJRFhIg==" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-05:00" level=debug msg="completed challenge" Dec 12 05:52:23 gbvpi-bedroom go-librespot[690]: time="2025-12-12T05:52:23-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 05:52:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:23 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:23 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:25 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:25 gbvpi-bedroom volumio[32533]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 05:52:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Dec 12 05:52:26 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:26 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 05:52:26 gbvpi-bedroom go-librespot[714]: go-librespot daemon starting... Dec 12 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-05:00" level=info msg="running go-librespot 0.4.0" Dec 12 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-05:00" level=debug msg="app state loaded" Dec 12 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-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 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-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 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-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 05:52:26 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:26-05:00" level=info msg="zeroconf server listening on port 35165" Dec 12 05:52:27 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:27-05:00" level=debug msg="obtained new client token: AAB4SLEfJRP56Ee59sZ2DzVSBPs8wXiO/PBpqdedti0riqkEWyGys2szzf47lVdUykPeiwZepRhK5UWLHEKmN0tZ8hKexVzRXeAYO8FwO76KnbPTrXKwu6EJtwbTiWsmgwQe4pJ/mkX3BTGLyXNLnR/okYF7XWT5cjzMROwrJDH7z9pBCzcvHGQpzJf4yhKj28FtJNYeMywW9VMVEz4g95VDn6LtFQhPvbZDfce73Bku+asOF1UgrqI=" Dec 12 05:52:27 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 12 05:52:28 gbvpi-bedroom volumio[32533]: info: Initializing connection to go-librespot Websocket Dec 12 05:52:28 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:28-05:00" level=debug msg="new websocket client" Dec 12 05:52:28 gbvpi-bedroom volumio[32533]: info: Connection to go-librespot Websocket established Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: info: Getting Spotify volume Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: SPOTIFY: SPOTIFY VOLUME undefined Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: SPOTIFY: VOLUMIO VOLUME 91 Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: info: Aligning Spotify Volume to Volumio Volume Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: info: CoreCommandRouter::volumioGetState Dec 12 05:52:31 gbvpi-bedroom volumio[32533]: info: Setting Spotify Volume from Volumio: 91 Dec 12 05:52:32 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:32-05:00" level=debug msg="completed keyexchange" Dec 12 05:52:32 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:32-05:00" level=debug msg="completed challenge" Dec 12 05:52:32 gbvpi-bedroom go-librespot[715]: time="2025-12-12T05:52:32-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 05:52:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 05:52:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: Error: socket hang up Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: at connResetException (node:internal/errors:720:14) Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: at Socket.emit (node:events:526:35) Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: code: 'ECONNRESET', Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: response: undefined Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: } Dec 12 05:52:32 gbvpi-bedroom volumio[32533]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 05:52:33 gbvpi-bedroom sudo[739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 05:51' Dec 12 05:52:33 gbvpi-bedroom sudo[739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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"