Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Starting UPNP Browser Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "alarm-clock"... Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "airplay_emulation"... Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Starting Shairport Sync Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "last_100"... Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "webradio"... Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "i2s_dacs"... Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: I2S DAC not set, start Auto-detection Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "volumiodiscovery"... Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 08 11:30:00 gbvpi-bedroom node[1247]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 11:30:00 gbvpi-bedroom node[1247]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: *** WARNING *** For more information see Dec 08 11:30:00 gbvpi-bedroom node[1247]: *** WARNING *** For more information see Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 08 11:30:00 gbvpi-bedroom node[1247]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 11:30:00 gbvpi-bedroom node[1247]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: *** WARNING *** For more information see Dec 08 11:30:00 gbvpi-bedroom node[1247]: *** WARNING *** For more information see Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 08 11:30:00 gbvpi-bedroom volumio[1247]: info: Loading plugin "jellyfin"... Dec 08 11:30:01 gbvpi-bedroom volumio[1247]: info: Loading plugin "spop"... Dec 08 11:30:02 gbvpi-bedroom sudo[1327]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:02 gbvpi-bedroom systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Loading plugin "outputs"... Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Loading plugin "albumart"... Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Plugin example_plugin is not enabled Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Loading plugin "inputs"... Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Loading plugin "updater_comm"... Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Plugin mpdemulation is not enabled Dec 08 11:30:03 gbvpi-bedroom volumio[1247]: info: Loading plugin "rest_api"... Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: Loading plugin "websocket"... Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: Starting Socket.io Server version 1.7.4 Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: Loading i18n strings for locale en Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: Updating browse sources language Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:04 gbvpi-bedroom dhcpcd[722]: timed out Dec 08 11:30:04 gbvpi-bedroom sh[702]: timed out Dec 08 11:30:04 gbvpi-bedroom sh[639]: ifup: failed to bring up eth0 Dec 08 11:30:04 gbvpi-bedroom systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:04 gbvpi-bedroom systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 08 11:30:04 gbvpi-bedroom volumio[1359]: Forking 3 albumart workers Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::initPlayerControls Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: Express server listening on port 3000 Dec 08 11:30:04 gbvpi-bedroom volumio[1247]: [Metrics] WebUI: 9s 793.80ms Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::resetVolumioState Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::getcurrentVolume Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioRetrievevolume Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: Volumio Network Manager: Network status updated: 2 Dec 08 11:30:05 gbvpi-bedroom systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:05 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:06 gbvpi-bedroom systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 08 11:30:06 gbvpi-bedroom systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: Reloading queue from file Dec 08 11:30:06 gbvpi-bedroom systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 11:30:06 gbvpi-bedroom upmpdcli[1411]: Could not open config: /tmp/upmpdcli.conf Dec 08 11:30:06 gbvpi-bedroom systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:06 gbvpi-bedroom systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: VolumeController:: Volume=91 Mute =false Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::updateTrackBlock Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrackBlock Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioRetrievevolume Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::setRepeat true single undefined Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::setRandom null Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: Setting Device type: Raspberry PI Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.92 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 1 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U1 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Discovery: Found device GBVPi-Bedroom Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U1 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: VolumeController:: Volume=91 Mute =false Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U1 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Discovery: Found device GBVPi-Bedroom Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Completed loading Core Plugins Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Preparing to generate the ALSA configuration file Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:07 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.92 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: Asound.conf file written Dec 08 11:30:08 gbvpi-bedroom sudo[1422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 08 11:30:08 gbvpi-bedroom sudo[1422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:08 gbvpi-bedroom sudo[1422]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: Output device has changed, restarting MPD Dec 08 11:30:08 gbvpi-bedroom sudo[1442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 08 11:30:08 gbvpi-bedroom sudo[1442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: Output device has changed, restarting Shairport Sync Dec 08 11:30:08 gbvpi-bedroom sudo[1442]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:08 gbvpi-bedroom sudo[1445]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 08 11:30:08 gbvpi-bedroom sudo[1445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: ___________ START PLUGINS ___________ Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: ControllerMpd::onStart: Initializing MPD Dec 08 11:30:08 gbvpi-bedroom volumio[1247]: info: Creating MPD Configuration file Dec 08 11:30:08 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 08 11:30:09 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 08 11:30:09 gbvpi-bedroom sudo[1453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 08 11:30:09 gbvpi-bedroom sudo[1453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:09 gbvpi-bedroom sudo[1453]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: [1765211409094] CoreMusicLibrary::Adding element Media Servers Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:09 gbvpi-bedroom sudo[1454]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 08 11:30:09 gbvpi-bedroom sudo[1454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 08 11:30:09 gbvpi-bedroom sudo[1458]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 08 11:30:09 gbvpi-bedroom sudo[1454]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: UPNP Browser: Client initialized successfully Dec 08 11:30:09 gbvpi-bedroom sudo[1457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 08 11:30:09 gbvpi-bedroom sudo[1457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:09 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 08 11:30:09 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 08 11:30:09 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 08 11:30:09 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 08 11:30:09 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 11:30:09 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 08 11:30:09 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: [1765211409576] CoreMusicLibrary::Adding element Last_100 Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: [1765211409606] CoreMusicLibrary::Adding element Webradio Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 11:30:09 gbvpi-bedroom sudo[1470]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 08 11:30:09 gbvpi-bedroom sudo[1470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 08 11:30:09 gbvpi-bedroom sudo[1471]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 08 11:30:09 gbvpi-bedroom sudo[1470]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:09 gbvpi-bedroom volumio[1247]: info: Initializing BBC Radios Dec 08 11:30:10 gbvpi-bedroom volumio[1371]: Starting albumart workers Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: [1765211410509] CoreMusicLibrary::Adding element Jellyfin Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: Cannot find translation for source Jellyfin Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: 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://192.168.1.97/albumart","artist":"","mute":false,"status":"stop","track":"","volume":91},"type":"device"} Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: Creating Spotify config file Dec 08 11:30:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:10 gbvpi-bedroom volumio[1372]: Starting albumart workers Dec 08 11:30:11 gbvpi-bedroom volumio[1370]: Starting albumart workers Dec 08 11:30:12 gbvpi-bedroom volumio-remote-updater[752]: [2025-12-08 11:30:12] [connect] Successful connection Dec 08 11:30:12 gbvpi-bedroom volumio[1247]: info: Volumio Calling Home Dec 08 11:30:13 gbvpi-bedroom mpd[1472]: 2025-12-08T11:30:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 08 11:30:13 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 08 11:30:13 gbvpi-bedroom sudo[1445]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:13 gbvpi-bedroom sudo[1457]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.92 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Dec 08 11:30:14 gbvpi-bedroom sudo[1510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 11:30:14 gbvpi-bedroom sudo[1510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:14 gbvpi-bedroom sudo[1510]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:14 gbvpi-bedroom sudo[1512]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 11:30:14 gbvpi-bedroom sudo[1512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:14 gbvpi-bedroom sudo[1512]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: Completed starting Core Plugins Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: ------------------------------------------- Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: ----- MyVolumio plugins startup ---- Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: ------------------------------------------- Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: MPD Permissions set Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: MPD Permissions set Dec 08 11:30:14 gbvpi-bedroom volumio-remote-updater[752]: [2025-12-08 11:30:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765211412 101 Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: 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: 6 Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: MPD running with PID1472 Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: ,establishing connection Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: Volumio called home Dec 08 11:30:14 gbvpi-bedroom volumio[1247]: info: Spotify config file written Dec 08 11:30:14 gbvpi-bedroom sudo[1519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 11:30:14 gbvpi-bedroom sudo[1519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:15 gbvpi-bedroom systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 11:30:15 gbvpi-bedroom systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 11:30:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:15 gbvpi-bedroom go-librespot[1521]: go-librespot daemon starting... Dec 08 11:30:15 gbvpi-bedroom sudo[1519]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-05:00" level=debug msg="app state loaded" Dec 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: error: MPD error: The expression evaluated to a falsy value: Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: assert.ok(self.idling) Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: error: The expression evaluated to a falsy value: Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: assert.ok(self.idling) Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: error: MPD error: The expression evaluated to a falsy value: Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: assert.ok(self.idling) Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: error: The expression evaluated to a falsy value: Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: assert.ok(self.idling) Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.92 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-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 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-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 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-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 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-05:00" level=info msg="zeroconf server listening on port 40941" Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:15-05:00" level=debug msg="obtained new client token: AAB7UUASLFBs63DuuWFXaFim1KLXIwZTndlXiNASOiC9en6+bhoTO0z6Xcod6n/tZo1i0/15lT6mUmVWxnWMWEdxgSMg2mv5fFi2QDvQ8xPFmpL8nSigMQXEg+ZeZkL8OR8S1pBeGl/WBOKdY+w/WA+S+k/xqWOTIdiLF6UBjOeaCQMuEfansycJLfCGrFU/uofDxHkpm3gxhTjj6kgQUBviAC721PeV/+2+V6/+JA+WZWZzubeJG0fKTA==" Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:15 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:16 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: No need to fix Spotify hosts Dec 08 11:30:16 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:16-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:16 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30:16-05:00" level=debug msg="completed challenge" Dec 08 11:30:16 gbvpi-bedroom go-librespot[1522]: time="2025-12-08T11:30: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 08 11:30:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: error: updateQueue error: null Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: Starting Shairport Sync Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: Starting Shairport Sync Dec 08 11:30:16 gbvpi-bedroom sudo[1541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 11:30:16 gbvpi-bedroom sudo[1541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:16 gbvpi-bedroom volumio[1247]: info: Starting Shairport Sync Dec 08 11:30:16 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 08 11:30:16 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 08 11:30:16 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:16 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.245s CPU time. Dec 08 11:30:16 gbvpi-bedroom sudo[1544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 11:30:16 gbvpi-bedroom sudo[1544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:17 gbvpi-bedroom sudo[1546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 11:30:17 gbvpi-bedroom sudo[1548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 08 11:30:17 gbvpi-bedroom sudo[1548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:17 gbvpi-bedroom sudo[1541]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:17 gbvpi-bedroom sudo[1546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 08 11:30:17 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: Shairport-Sync Started Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: Error adding Membership: Error: addMembership EINVAL Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:17 gbvpi-bedroom sudo[1544]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 08 11:30:17 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:17 gbvpi-bedroom sudo[1546]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: Shairport-Sync Started Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: Shairport-Sync Started Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:17 gbvpi-bedroom sudo[1593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 08 11:30:17 gbvpi-bedroom sudo[1593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 08 11:30:17 gbvpi-bedroom mpd_monitor.sh[1597]: MPD Monitor Service: Starting MPD Monitor Service Dec 08 11:30:17 gbvpi-bedroom sudo[1593]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:17 gbvpi-bedroom systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 08 11:30:17 gbvpi-bedroom volumio[1247]: info: Successfully started MPD Monitor Dec 08 11:30:18 gbvpi-bedroom sudo[1596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 08 11:30:18 gbvpi-bedroom sudo[1596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:18 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 08 11:30:18 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 08 11:30:18 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 08 11:30:18 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 08 11:30:18 gbvpi-bedroom mpd_monitor.sh[1616]: MPD Monitor Service: Starting MPD Monitor Service Dec 08 11:30:18 gbvpi-bedroom sudo[1596]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:18 gbvpi-bedroom volumio[1247]: info: Successfully started MPD Monitor Dec 08 11:30:19 gbvpi-bedroom systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 08 11:30:19 gbvpi-bedroom systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 08 11:30:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 08 11:30:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:19 gbvpi-bedroom go-librespot[1645]: go-librespot daemon starting... Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=debug msg="app state loaded" Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:19 gbvpi-bedroom volumio[1247]: info: go-librespot daemon successfully initialized Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30: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 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30: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 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30: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 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=info msg="zeroconf server listening on port 42239" Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=debug msg="obtained new client token: AABXSVBYn59C9xG+ttusSg1KH8hkkwJpwkKXJmDXMv32wc8ZsK+0QnHZTZTQkfNAetmJs+qCZ8xUHetXEW7uIPPxgHlFwPSdgWBcCC93Cb0nyug6BH6E+rxXzpfRvd2qCBuY15FRAwLI/b26bFazw5tQi5Xrn7cVHejNcvOT4E1B2oq35SS5BhLhQLeq+Y/RJzDpPAp+uZ2qUCyNd35frK/2zPhhtp4yx3970kZCBJnq43vxRJTFA9rjow==" Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:19 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30:19-05:00" level=debug msg="completed challenge" Dec 08 11:30:20 gbvpi-bedroom go-librespot[1646]: time="2025-12-08T11:30: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 08 11:30:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:20 gbvpi-bedroom volumio[1247]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 08 11:30:21 gbvpi-bedroom systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 08 11:30:21 gbvpi-bedroom systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 11:30:21 gbvpi-bedroom systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 11:30:21 gbvpi-bedroom sudo[1548]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: Upmpdcli Daemon Started Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U1 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetQueue Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::getQueue Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getQueue Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: Received Get System Info Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:21 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:22 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:30:22 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:30:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 08 11:30:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 08 11:30:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:23 gbvpi-bedroom go-librespot[1672]: go-librespot daemon starting... Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=debug msg="app state loaded" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin bluetooth to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin multiroom to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin metavolumio to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin cd_controller to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 08 11:30:23 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-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 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-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 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=info msg="zeroconf server listening on port 35893" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=debug msg="obtained new client token: AADBmmYsAsxdR31VR9kOGMkQUISDxTzr70Rlrx40myywZcdX0L42hoaTP/jaeZGf3Y8uy0slkiOFMHaKLZ+BFYpmDYOhwJeok/vciQ7GuIaITJbG4wSmKLUtRvz4fmrtenM4CTwOxnqC4cmbl7Q7Zz9bF0VTHmp0DLWRRLP2t3Cr0FvORjQy2oMGkPuoi2WcP9vi0zlNo5BNNXSn4ntiguRZCdHaMLEqJWGb0RAV9Bc/KPolV6gls9ItCw==" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30:23-05:00" level=debug msg="completed challenge" Dec 08 11:30:23 gbvpi-bedroom go-librespot[1673]: time="2025-12-08T11:30: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 08 11:30:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 08 11:30:26 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:26 gbvpi-bedroom go-librespot[1681]: go-librespot daemon starting... Dec 08 11:30:26 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:26 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:26-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:26 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:26-05:00" level=debug msg="app state loaded" Dec 08 11:30:26 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-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 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-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 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-05:00" level=info msg="zeroconf server listening on port 35359" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-05:00" level=debug msg="obtained new client token: AAA50JF5Os+gPVVD8wW4sSmKxKgjdAUFpaYXJ9IvKGTggH/niiAHh4Pi43cClCWwZYy3QkJSoIISx/bPz1Wb0ImuKVOEU0UPdu/0Ql4U5nB6G5zAxd+lHjACU3vRrDOwbhI2wJWxjxs0tsVhpJwCYqFahxEVFDlFDVIsMi7RrcCCWKdDqqtbjHEviRRzniLI1bUXDMC6VYRGQr88t2MJ9e8I6o/Af+pUSKCnKlDT4+R9PTTEjk7S0r2kFg==" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-05:00" level=debug msg="completed challenge" Dec 08 11:30:27 gbvpi-bedroom go-librespot[1682]: time="2025-12-08T11:30:27-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 08 11:30:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:29 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 08 11:30:29 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 08 11:30:29 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:29 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:29 gbvpi-bedroom volumio[1247]: info: Starting MyVolumio Remote Streaming Endpoints Dec 08 11:30:29 gbvpi-bedroom volumio[1247]: info: MyVolumio login type: Token Dec 08 11:30:30 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 08 11:30:30 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 08 11:30:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 08 11:30:30 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:30 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:30 gbvpi-bedroom go-librespot[1703]: go-librespot daemon starting... Dec 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-05:00" level=debug msg="app state loaded" Dec 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-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 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-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 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-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 08 11:30:30 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:30-05:00" level=info msg="zeroconf server listening on port 40591" Dec 08 11:30:31 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:31-05:00" level=debug msg="obtained new client token: AABbIbDehkQZkNoGOTk+xCxw3mKONKeWKD0kKOTKOla1N2Vqbb3E9ebCaAzmnqktic5hRAWUc0qERKWcdUSe9tfOFENlpLn7is882fP/3xwmYuzz0fRd8uAejRinDdYXpkarYjuNdIWNil8em3FPAhJ4gCwizRzy1TvsD8gXppgWU4+rPCV9wNKl9NBYask+gDCOmOre9fATJy/zbG+WIGsRZM+VzBzEOyWUF4Rn7l/RC7p+H8YK" Dec 08 11:30:31 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:31 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:31-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:31 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30:31-05:00" level=debug msg="completed challenge" Dec 08 11:30:31 gbvpi-bedroom go-librespot[1704]: time="2025-12-08T11:30: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 08 11:30:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 08 11:30:34 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:34 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:34 gbvpi-bedroom go-librespot[1712]: go-librespot daemon starting... Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=debug msg="app state loaded" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-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 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-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 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-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 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=info msg="zeroconf server listening on port 43133" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=debug msg="obtained new client token: AACtx5+ehMREk76ZaLGbqfnqilVloxEFCA/+ncEWTpCTSZE9v3t+Jh642k/WnfqABfZjIrwrRfNq2VhKepUX6HVNbh1fv3p4ly4pkD77Q0MjVMopiiauOv/YJJejxmmcUZx1MjKYankqkllH3wzJCxcXMMM8cvPTWE1LFigJGFipDUDkEc8H6zr9d9hzJEFEClq5pY4DMgg09XrrBrEW5oqlpx4+MCt7eqGRe7+Io17erMyhAQg48ilGOg==" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-05:00" level=debug msg="completed challenge" Dec 08 11:30:34 gbvpi-bedroom go-librespot[1713]: time="2025-12-08T11:30:34-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 08 11:30:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:35 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 08 11:30:35 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 08 11:30:35 gbvpi-bedroom volumio[1247]: info: Streaming services startup Dec 08 11:30:35 gbvpi-bedroom volumio[1247]: info: Starting Streaming Daemon Dec 08 11:30:35 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 08 11:30:35 gbvpi-bedroom sudo[1721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 08 11:30:35 gbvpi-bedroom sudo[1721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:35 gbvpi-bedroom sudo[1721]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:35 gbvpi-bedroom upmpdcli[1727]: writing RSA key Dec 08 11:30:35 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: error: Cannot start Volumio Streaming Daemon Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Discovery: Found device NorthPi-Soundstation Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:36 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:37 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:37 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:37 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 08 11:30:37 gbvpi-bedroom volumio[1247]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 08 11:30:37 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 08 11:30:37 gbvpi-bedroom sudo[1735]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 08 11:30:37 gbvpi-bedroom sudo[1735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:37 gbvpi-bedroom sudo[1735]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:37 gbvpi-bedroom sudo[1740]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 08 11:30:37 gbvpi-bedroom sudo[1750]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 08 11:30:37 gbvpi-bedroom sudo[1743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 08 11:30:37 gbvpi-bedroom sudo[1743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:37 gbvpi-bedroom sudo[1750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:37 gbvpi-bedroom sudo[1740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:37 gbvpi-bedroom sudo[1750]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:37 gbvpi-bedroom sudo[1743]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:37 gbvpi-bedroom sudo[1740]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:37 gbvpi-bedroom sudo[1760]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 11:30:37 gbvpi-bedroom sudo[1760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:37 gbvpi-bedroom sudo[1757]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 11:30:37 gbvpi-bedroom sudo[1757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:37 gbvpi-bedroom sudo[1760]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:37 gbvpi-bedroom sudo[1757]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 08 11:30:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:38 gbvpi-bedroom go-librespot[1766]: go-librespot daemon starting... Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=debug msg="app state loaded" Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: MyVolumio token set successfully Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: MYVOLUMIO: Adding device Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: MYVOLUMIO: Evaluating Server Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30: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 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30: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 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30: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 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=info msg="zeroconf server listening on port 43791" Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 08 11:30:38 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=debug msg="obtained new client token: AACuqoHd6TvNN0apxZv69ryzXeBb5M/Ua4Ne5Y2jCNWT4fmAnSjHP2qmEQFsn1jaxHKxkAgB/yi441kmnXWelq2Zo6pxGs4jb2UF9YmK/34BgNArc3oxuWqbfIn0ulkPduAf0q6d7JjtXpc88zsgYVcBR2zIygVUYJ/Jv0NurbpoEM/T+CHYZDbX591xHP8Ygn5iItaPZDVPwTEEpSBj3drosHTsYkMxpnirkUWVnLEGDtrRl1r+m7+2Ow==" Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-05:00" level=debug msg="completed challenge" Dec 08 11:30:38 gbvpi-bedroom go-librespot[1769]: time="2025-12-08T11:30:38-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 08 11:30:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: MyVolumio Plan changed: premium Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: Removing browser output: myVolumio user plan is not superstar Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: Removing audio output: Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: MYVOLUMIO: Adding device Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: MYVOLUMIO: Evaluating Server Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97:3000 from 192.168.1.92 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: Setting Geolocation for MyVolumio to us4 Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:39 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Remote config written successfully Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Starting Tunnel 1 Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Starting Tunnel Connection Checker Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Completed starting MyVolumio Plugin Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Setting Geolocation for MyVolumio to us1 Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: MYVolumio Device enabled Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: MyVolumio status changed Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Streaming services startup Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Starting Streaming Daemon Dec 08 11:30:40 gbvpi-bedroom sudo[1830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 08 11:30:40 gbvpi-bedroom sudo[1830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:40 gbvpi-bedroom sudo[1830]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: Successfully Added MyVolumio device Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: error: Cannot start Volumio Streaming Daemon Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 08 11:30:40 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 08 11:30:41 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 08 11:30:41 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:41 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:41 gbvpi-bedroom go-librespot[1833]: go-librespot daemon starting... Dec 08 11:30:41 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:41-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:41 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:41-05:00" level=debug msg="app state loaded" Dec 08 11:30:41 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-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 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-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 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-05:00" level=info msg="zeroconf server listening on port 39879" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-05:00" level=debug msg="obtained new client token: AAC9fnUf+QUTTnd9q5B1r4HRXR8UT3gwkKI5KBg41QHyLJC9lznEku8JVK7BVwhA0sZIm8yhL760gelrXG+0+CcK8loEq2JrLAawm+CW79X8HI/Y4/dTJurAt/Q5Oi1Mh9fiWQSVNPEWIXMi9ojlAlhLkRBtsu03NE1hvw+l+EoKA2gtOe0xbscaCNO+/6ZfhJ/z9Q/m43vA7CtUq+mbdTqbibmgjjfqTbvvxhFsGvnNWJuRtC5ny5n5Dw==" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30:42-05:00" level=debug msg="completed challenge" Dec 08 11:30:42 gbvpi-bedroom go-librespot[1834]: time="2025-12-08T11:30: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 08 11:30:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:43 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 08 11:30:43 gbvpi-bedroom sudo[1844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 08 11:30:43 gbvpi-bedroom sudo[1844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:43 gbvpi-bedroom sudo[1844]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:43 gbvpi-bedroom volumio[1247]: info: MRS: MultiRoom plugin initialized Dec 08 11:30:43 gbvpi-bedroom volumio[1247]: info: MRS: STOPPING SNAPCLIENT Dec 08 11:30:43 gbvpi-bedroom volumio[1247]: info: MRS: Snap server stop Dec 08 11:30:43 gbvpi-bedroom sudo[1861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 08 11:30:43 gbvpi-bedroom sudo[1861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:43 gbvpi-bedroom volumio[1247]: info: MRS: STOPPING volumioStreaming Dec 08 11:30:43 gbvpi-bedroom sudo[1863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 08 11:30:43 gbvpi-bedroom sudo[1863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:44 gbvpi-bedroom sudo[1866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 08 11:30:44 gbvpi-bedroom sudo[1866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:44 gbvpi-bedroom sudo[1868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 08 11:30:44 gbvpi-bedroom sudo[1868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:44 gbvpi-bedroom sudo[1861]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:44 gbvpi-bedroom sudo[1868]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:44 gbvpi-bedroom sudo[1866]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:44 gbvpi-bedroom sudo[1863]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 08 11:30:44 gbvpi-bedroom volumio[1247]: info: Preparing to generate the ALSA configuration file Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Updating MyVolumio device info Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Updating MyVolumio device info Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Successfully Added MyVolumio device Dec 08 11:30:45 gbvpi-bedroom volumio-remote-updater[752]: Test mode enabled Dec 08 11:30:45 gbvpi-bedroom volumio-remote-updater[752]: Alpha mode disabled Dec 08 11:30:45 gbvpi-bedroom volumio-remote-updater[752]: Alpha legacy test mode disabled Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: MRS: Removed streaming files Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: MRS: volumioStreaming STOPPED Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: MRS: SNAPSERVER STOPPED Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: MRS: SNAPCLIENT STOPPED Dec 08 11:30:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 08 11:30:45 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:45 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:45 gbvpi-bedroom go-librespot[1878]: go-librespot daemon starting... Dec 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-05:00" level=debug msg="app state loaded" Dec 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 08 11:30:45 gbvpi-bedroom volumio[1247]: info: Successfully Updated MyVolumio device Dec 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-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 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-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 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-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 08 11:30:45 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:45-05:00" level=info msg="zeroconf server listening on port 34391" Dec 08 11:30:46 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:46-05:00" level=debug msg="obtained new client token: AACGjhyQOh6wy+N60jQuxhwDuvfZxwA5EHWdVn39HxiKYPwaIgRJnWQHoLRYVtSQNW3HLaUzjaL0pybAe+0VbEBkEfXgs9Xr+UFWEghYhAzerQX3BnY1/slJThD4aWTAL33fDG+EotBq5v2f8tXT8AQFLs8v3AIcev0Qjq8O/u0fp61UlfoqVrrODbQuL2f493sihG+zJP7KCjr214GEgq4NO7Y28com704xLMB5Ck0kBTcO0+YzvHQwuw==" Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Asound.conf file unchanged, so no further update is needed Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Output device has changed, restarting MPD Dec 08 11:30:46 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:46 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:46-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:46 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:46-05:00" level=debug msg="completed challenge" Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Output device has changed, restarting Shairport Sync Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:46 gbvpi-bedroom sudo[1889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 08 11:30:46 gbvpi-bedroom go-librespot[1879]: time="2025-12-08T11:30:46-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 08 11:30:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:46 gbvpi-bedroom sudo[1889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:46 gbvpi-bedroom sudo[1887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 08 11:30:46 gbvpi-bedroom sudo[1887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:46 gbvpi-bedroom sudo[1887]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 08 11:30:46 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 08 11:30:46 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 08 11:30:46 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 08 11:30:46 gbvpi-bedroom systemd[1]: mpd.service: Consumed 3.048s CPU time. Dec 08 11:30:46 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 08 11:30:46 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 08 11:30:46 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output for this device Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding audio output: Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding audio output: Dec 08 11:30:46 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 08 11:30:46 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding METAVOLUMIO REST API Endpoints Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 08 11:30:46 gbvpi-bedroom sudo[1902]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 08 11:30:46 gbvpi-bedroom sudo[1902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 08 11:30:46 gbvpi-bedroom sudo[1902]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Preparing CD Folders Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding CD REST API Endpoints Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Starting UDEV Watcher for CD Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: Detecting CD presence with UDEV Dec 08 11:30:46 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 08 11:30:46 gbvpi-bedroom bluetoothd[732]: Path / reserved for Adv Monitor app :1.24 Dec 08 11:30:46 gbvpi-bedroom bluetoothd[732]: Adv Monitor app :1.24 disconnected from D-Bus Dec 08 11:30:48 gbvpi-bedroom mpd[1906]: 2025-12-08T11:30:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 08 11:30:48 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 08 11:30:48 gbvpi-bedroom sudo[1889]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 08 11:30:49 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:49 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:49 gbvpi-bedroom go-librespot[1926]: go-librespot daemon starting... Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=debug msg="app state loaded" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30: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-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-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 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-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 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=info msg="zeroconf server listening on port 45705" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=debug msg="obtained new client token: AABkrqVa1pDAVdJ7v0b27kZ4R1IZxF4EqDzzbMLmL2lU9c//bbX9C8XTDv0+6TaQBPWwGwIZ2ZFQtv58PvEhHCJsWxdEkkX91sCYEAhSOj1TOVsUVe4gEmUILpqld0sSjHNlVvR2Em+R+W8b8qfai4PnLHhD0ILolP8Q+1tSEK1DjnHffRlGR/F7j3gEXzChik1nHatHI7vTCpzJtMlW1ihW7ScxePAWRbPxkGALVmlfBQC0VnskVOt/DA==" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30:49-05:00" level=debug msg="completed challenge" Dec 08 11:30:49 gbvpi-bedroom go-librespot[1927]: time="2025-12-08T11:30: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 08 11:30:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:49 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding inputs REST Endpoints Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Scanning Audio Inputs Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Checking against Known Cards name Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding Server instance for streaming Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: error: Hi Res Audio Failed Login: Missing Login Data Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 08 11:30:52 gbvpi-bedroom sudo[1939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 08 11:30:52 gbvpi-bedroom sudo[1939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 08 11:30:52 gbvpi-bedroom sudo[1939]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 08 11:30:52 gbvpi-bedroom sudo[1947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 08 11:30:52 gbvpi-bedroom sudo[1947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding TIDAL REST API Endpoints Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Stopping AccessToken refresher cron for QOBUZ Dec 08 11:30:52 gbvpi-bedroom sudo[1947]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:52 gbvpi-bedroom sudo[1949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 08 11:30:52 gbvpi-bedroom sudo[1949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:52 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 08 11:30:52 gbvpi-bedroom sudo[1949]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: AccessToken refresher cron started for QOBUZ Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Adding QOBUZ REST API Endpoints Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetBrowseSources Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: MRS: Getting audio outputs on start Dec 08 11:30:52 gbvpi-bedroom volumio[1247]: info: MRS: Requesting all other devices output Dec 08 11:30:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 08 11:30:53 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:53 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:53 gbvpi-bedroom go-librespot[1955]: go-librespot daemon starting... Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=debug msg="app state loaded" Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-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 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-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 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=info msg="zeroconf server listening on port 42287" Dec 08 11:30:53 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=debug msg="obtained new client token: AAAksrpklpgdVU7GOJnrnS0+CkCKewUzx3+hOqNNy4JVvxls4oBYyAsWa8ZGm6kpkxkH6I4IXekjLv035rQDkLtc+8DwK0aN4V+49mNUn7MnTi0vV281Ul64Pp2pEqC1hz267qUwAtt+oYOZC6HDw5B9YSH+gSCOB/akdtU3/B/1I2mUrqGREiKlrJwz/ElRriBOMdobHil+xGVMlxCLcShWqrcZnqlFJ4M+vLn2ZFc7P/0DNYmbRdXQqQ==" Dec 08 11:30:53 gbvpi-bedroom sudo[1966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 08 11:30:53 gbvpi-bedroom sudo[1966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:53 gbvpi-bedroom volumio[1247]: info: MPD Permissions set Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30:53-05:00" level=debug msg="completed challenge" Dec 08 11:30:53 gbvpi-bedroom volumio[1247]: info: Successfully Updated MyVolumio device Dec 08 11:30:53 gbvpi-bedroom systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Dec 08 11:30:53 gbvpi-bedroom sudo[1966]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:53 gbvpi-bedroom go-librespot[1956]: time="2025-12-08T11:30: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 08 11:30:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:53 gbvpi-bedroom volumiobt[1970]: INFO [BTSTART] Ensuring Bluetooth directory exists... Dec 08 11:30:53 gbvpi-bedroom sudo[1971]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Dec 08 11:30:53 gbvpi-bedroom sudo[1971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:53 gbvpi-bedroom sudo[1971]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:53 gbvpi-bedroom sudo[1973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Dec 08 11:30:53 gbvpi-bedroom sudo[1973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:53 gbvpi-bedroom sudo[1973]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:53 gbvpi-bedroom volumiobt[1975]: INFO [BTSTART] Powering on Bluetooth if needed... Dec 08 11:30:53 gbvpi-bedroom bluetoothd[732]: Adv Monitor app :1.25 disconnected from D-Bus Dec 08 11:30:53 gbvpi-bedroom volumiobt[1978]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [176B blob data] Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [157B blob data] Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [157B blob data] Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [157B blob data] Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [113B blob data] Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [bluetoothctl]> discoverable on Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [bluetoothctl]> pairable on Dec 08 11:30:53 gbvpi-bedroom bluetoothd[732]: Path / reserved for Adv Monitor app :1.26 Dec 08 11:30:53 gbvpi-bedroom bluetoothd[732]: Adv Monitor app :1.26 disconnected from D-Bus Dec 08 11:30:53 gbvpi-bedroom volumiobt[1979]: [bluetoothctl]> Dec 08 11:30:53 gbvpi-bedroom volumiobt[1980]: INFO [BTSTART] Registering Bluetooth agent... Dec 08 11:30:53 gbvpi-bedroom volumiobt[1981]: [NEW] Media /org/bluez/hci0 Dec 08 11:30:53 gbvpi-bedroom volumiobt[1981]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Dec 08 11:30:53 gbvpi-bedroom volumiobt[1981]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Dec 08 11:30:53 gbvpi-bedroom volumiobt[1981]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Dec 08 11:30:53 gbvpi-bedroom bluetoothd[732]: Adv Monitor app :1.27 disconnected from D-Bus Dec 08 11:30:53 gbvpi-bedroom volumiobt[1982]: No agent is registered Dec 08 11:30:53 gbvpi-bedroom volumiobt[1982]: [NEW] Media /org/bluez/hci0 Dec 08 11:30:53 gbvpi-bedroom volumiobt[1982]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Dec 08 11:30:53 gbvpi-bedroom volumiobt[1982]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Dec 08 11:30:53 gbvpi-bedroom volumiobt[1982]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Dec 08 11:30:53 gbvpi-bedroom bluetoothd[732]: Path / reserved for Adv Monitor app :1.28 Dec 08 11:30:53 gbvpi-bedroom bluetoothd[732]: Adv Monitor app :1.28 disconnected from D-Bus Dec 08 11:30:53 gbvpi-bedroom volumiobt[1983]: INFO [BTSTART] Agent registered successfully. Dec 08 11:30:53 gbvpi-bedroom volumiobt[1984]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: socket hang up Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioStop Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::stop Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: error: updateQueue error: null Dec 08 11:30:54 gbvpi-bedroom sudo[1987]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 08 11:30:54 gbvpi-bedroom sudo[1987]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:54 gbvpi-bedroom systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 11:30:54 gbvpi-bedroom systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 11:30:54 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 08 11:30:54 gbvpi-bedroom sudo[1987]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:54 gbvpi-bedroom autossh[1996]: port set to 0, monitoring disabled Dec 08 11:30:54 gbvpi-bedroom autossh[1996]: starting ssh (count 1) Dec 08 11:30:54 gbvpi-bedroom autossh[1996]: ssh child pid is 1999 Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:54 gbvpi-bedroom volumiossh-tunnel[1999]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 08 11:30:54 gbvpi-bedroom volumiobt[1985]: INFO:a2dp-agent:Connecting to system bus. Dec 08 11:30:54 gbvpi-bedroom volumiobt[1985]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Dec 08 11:30:54 gbvpi-bedroom volumiobt[1985]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Dec 08 11:30:54 gbvpi-bedroom volumiobt[1985]: INFO:a2dp-agent:Registering agent. Dec 08 11:30:54 gbvpi-bedroom volumiobt[1985]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Dec 08 11:30:54 gbvpi-bedroom volumiobt[1985]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Dec 08 11:30:54 gbvpi-bedroom volumio[1247]: info: Remote SSH Started Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Executing endpoint qc_getconfig Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.790 [1951.1951] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Starting Shairport Sync Dec 08 11:30:55 gbvpi-bedroom sudo[2006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 11:30:55 gbvpi-bedroom sudo[2006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.884 [1951.1951] INFO VolumeManager: [0x1892588]: Setting new playback volume: 75 Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.884 [1951.1951] INFO VolumeManager: [0x1892588]: Setting new mute state: 0 Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.884 [1951.1951] INFO QobuzConnect: [0x1892f58]: Client initialized! Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.884 [1951.1951] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.894 [1951.1951] INFO LocalConfigManager: [0x1891e68]: Starting Local Configuration server Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.894 [1951.1951] INFO SampleApp: Starting Local configuration server Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.895 [1951.1951] INFO SampleApp: Connected to UNIX socket client 0x187c818 Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 08 11:30:55 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 08 11:30:55 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 08 11:30:55 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:55 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.296s CPU time. Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: TidalConnect service stoped! Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:30:55 gbvpi-bedroom qobuz-connect[1951]: 20251208 11:30:55.941 [1951.1951] INFO SampleApp: Playback volume changed: 75 Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Adding audio output: Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 08 11:30:55 gbvpi-bedroom volumio[1247]: info: Adding audio output: Dec 08 11:30:55 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 11:30:55 gbvpi-bedroom sudo[2006]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: info: Shairport-Sync Started Dec 08 11:30:56 gbvpi-bedroom sudo[2034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 08 11:30:56 gbvpi-bedroom sudo[2034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:56 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 08 11:30:56 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:56 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:30:56 gbvpi-bedroom go-librespot[2036]: go-librespot daemon starting... Dec 08 11:30:56 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 08 11:30:56 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 08 11:30:56 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 08 11:30:56 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 08 11:30:56 gbvpi-bedroom mpd_monitor.sh[2038]: MPD Monitor Service: Starting MPD Monitor Service Dec 08 11:30:56 gbvpi-bedroom sudo[2034]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:56 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:56-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:30:56 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:56-05:00" level=debug msg="app state loaded" Dec 08 11:30:56 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:56-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:30:56 gbvpi-bedroom sudo[2045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:56 gbvpi-bedroom volumio[1247]: info: Successfully started MPD Monitor Dec 08 11:30:56 gbvpi-bedroom sudo[2045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-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 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-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 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-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 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-05:00" level=info msg="zeroconf server listening on port 33509" Dec 08 11:30:57 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 08 11:30:57 gbvpi-bedroom sudo[2045]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-05:00" level=debug msg="obtained new client token: AAAaIpJsznhUXIAWoyEsO90rfvsNyou6PPOM11pVD/mIRs8djEQL9MHzArI+nEGOrZfl0tKdwLyDXqVPm2ed2a5Je/i0vifFryKL5EF2NrxHX3WJNKD9f9FnqaV8Tu94s+FS/jpP7yNrPFESksQKCbNI5rfpdoAV11hr2SQ4JKLX3A3wHtVNh5pnK/l2iK7BFpG3slm/L28AanJ0Ncjh2twpDwbKMbnbKsTVMXf7adA8kYQq1tYb/EA=" Dec 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-05:00" level=debug msg="completed keyexchange" Dec 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-05:00" level=debug msg="completed challenge" Dec 08 11:30:57 gbvpi-bedroom go-librespot[2037]: time="2025-12-08T11:30:57-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 08 11:30:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:30:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:30:57 gbvpi-bedroom sudo[2055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 11:30:57 gbvpi-bedroom sudo[2055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:57 gbvpi-bedroom sudo[2055]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:57 gbvpi-bedroom sudo[2058]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 11:30:57 gbvpi-bedroom sudo[2058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:57 gbvpi-bedroom sudo[2058]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: Executing endpoint tc_getconfig Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 08 11:30:57 gbvpi-bedroom vtcs[2052]: STARTING TidalConnect services, version: 1.5.2.56 Dec 08 11:30:57 gbvpi-bedroom vtcs[2052]: STARTED TidalConnect services. Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U1 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: Executing endpoint tc_connect Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: Connecting to TidalConnect Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::servicePushState Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:57 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: verbose: CURRENT POSITION 0 Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::syncState stateService stop Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::syncState currentStatus stop Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: No code Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::servicePushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getTrack 0 Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: verbose: CURRENT POSITION 0 Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::syncState stateService stop Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::syncState currentStatus stop Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: No code Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::pushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 08 11:30:58 gbvpi-bedroom volumio[1247]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 08 11:30:59 gbvpi-bedroom sudo[2083]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 11:30:59 gbvpi-bedroom sudo[2083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:59 gbvpi-bedroom sudo[2083]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:59 gbvpi-bedroom sudo[2091]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 11:30:59 gbvpi-bedroom sudo[2091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:30:59 gbvpi-bedroom sudo[2091]: pam_unix(sudo:session): session closed for user root Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: verbose: New Socket.io Connection to 192.168.1.97 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 16; SM-S908U1 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.174 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: Received Get System Info Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:30:59 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: TidalConnect service started! Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: [Metrics] CommandRouter: 64s 450.30ms Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumiosetStartupVolume Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::Close All Modals sent Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::Close All Modals sent Dec 08 11:31:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 08 11:31:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:31:00 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:31:00 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:00 gbvpi-bedroom go-librespot[2094]: go-librespot daemon starting... Dec 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:00-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:00-05:00" level=debug msg="app state loaded" Dec 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:00-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 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:00-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 08 11:31:00 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:00-05:00" level=info msg="zeroconf server listening on port 39845" Dec 08 11:31:01 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:01-05:00" level=debug msg="obtained new client token: AACA5cE0oJkw7nOFY7dWy9TMmEDcoK3gfjyLXd1RhmRuvYnRi5vZ0FK8DqrYKGoHm1/1GrsvPf8NCubafgoMUJA3vdOlceIoUR+oQhfJ/HwMyFygl4sbSsKbKi/Kxte8bUpTtTNt32vadj+f6g30mEW5T5lST804NwDqvuiKM5ecbfTiANaFpa1D7278e1eimBCiBfE9PTk9T6OQ034sbEkcGdbHDYpg1fyaclhPOGIGF9JMzdjeNq4=" Dec 08 11:31:01 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 08 11:31:01 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:01-05:00" level=debug msg="completed keyexchange" Dec 08 11:31:01 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:01-05:00" level=debug msg="completed challenge" Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 08 11:31:01 gbvpi-bedroom go-librespot[2095]: time="2025-12-08T11:31:01-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 08 11:31:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:31:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: Received Get System Info Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: Discovery: A device disappeared from network Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: Discovery: Device northpi-soundstation disappeared from network Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: Received Get System Info Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:01 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:31:03 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:31:03 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:31:03 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetQueue Dec 08 11:31:03 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::getQueue Dec 08 11:31:03 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::getQueue Dec 08 11:31:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 08 11:31:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:04 gbvpi-bedroom go-librespot[2108]: go-librespot daemon starting... Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=debug msg="app state loaded" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-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 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-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 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-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 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=info msg="zeroconf server listening on port 44523" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=debug msg="obtained new client token: AADmHVGCnpwc/1yS9zAXYwFK0deBszvzlnM9b9Zk10kksAIt9YX1tqt8bYUQlaXs8U7QcIRR7JyYnMFhiHlApbGSPZt6xs9LpAV2DeoRwNO1MQpoqwlLKrF2zsawcBAB4u1dqLbq4w/M280fRsqc3CDeXaG0MDTzK9Osca93VfhI7Wmfr/K4N/qnilARtDdBZN7AaP5lxJVuwfcTTeq4H4ckrROWuhjCsIZ3YTxK6y7dpGr9Qil61WIMyg==" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=debug msg="completed keyexchange" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-05:00" level=debug msg="completed challenge" Dec 08 11:31:04 gbvpi-bedroom go-librespot[2109]: time="2025-12-08T11:31:04-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 08 11:31:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:31:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:31:05 gbvpi-bedroom volumio[1247]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 08 11:31:05 gbvpi-bedroom volumio[1247]: info: Discovery: Found device NorthPi-Soundstation Dec 08 11:31:05 gbvpi-bedroom volumio[1247]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 08 11:31:05 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: jellyfin , handleBrowseUri Dec 08 11:31:05 gbvpi-bedroom volumio[1247]: info: [jellyfin-browse] browseUri: jellyfin Dec 08 11:31:05 gbvpi-bedroom volumio[1247]: info: Preload queue cleared Dec 08 11:31:06 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:31:06 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:31:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:06 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:07 gbvpi-bedroom volumio[1247]: info: BOOT COMPLETED Dec 08 11:31:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 08 11:31:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:08 gbvpi-bedroom go-librespot[2119]: go-librespot daemon starting... Dec 08 11:31:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=debug msg="app state loaded" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-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 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-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 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-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 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=info msg="zeroconf server listening on port 40339" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=debug msg="obtained new client token: AACS2aYJIeHhzV+MXASgTHorw3LuRJv2kTUYDmM0degUc6TjYHDTjoOoIVUmmCb+kbMKIoY69uw8Up3YEyipUWX7fdaVhy0pF71GIxmQMg7hDyBNOUDO+xtd/OgHTRepqHP9sJHZ6wmyJ15tBC/7Iqq2Xo27wMsCQM0HuKjZlfEEQL1OXsynAhitKgeLMpwHd+cI6fcCpnbUIL7Hwh+xtXv5Wn9pI3rOrSx2YnWTekVHr3E78+QiIRHGUA==" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=debug msg="completed keyexchange" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-05:00" level=debug msg="completed challenge" Dec 08 11:31:08 gbvpi-bedroom go-librespot[2120]: time="2025-12-08T11:31:08-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 08 11:31:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:31:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:31:09 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 08 11:31:09 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:31:09 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:31:10 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: jellyfin , handleBrowseUri Dec 08 11:31:10 gbvpi-bedroom volumio[1247]: info: [jellyfin-browse] browseUri: jellyfin Dec 08 11:31:10 gbvpi-bedroom volumio[1247]: info: Preload queue cleared Dec 08 11:31:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 08 11:31:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:11 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:11 gbvpi-bedroom go-librespot[2142]: go-librespot daemon starting... Dec 08 11:31:11 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:11-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:11 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:11-05:00" level=debug msg="app state loaded" Dec 08 11:31:11 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-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 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-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 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-05:00" level=info msg="zeroconf server listening on port 39853" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-05:00" level=debug msg="obtained new client token: AACg9H+/tAmwURtUXxIU/qjt6QjU+xbztMTWq091syZuL82LSgkFhnZNUYNOpA3qaIkrDPsDHSlkCWapugyXN2pbcu5ZeqD2ZYAWBp8qjG2MwcZmTRpez3og3jp+w2yCgdpPWY0oXZ5+IsER0ujV1MjdRToDsrctV/s8UxDD8naKuzvKqYWtYpVRy2xjXbRO7YPYmzNdsIGi4kSy2Nz7T65ed4hkhlZ5QvLhRxEbGBoYSpQCNeLgSiU=" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-05:00" level=debug msg="completed keyexchange" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31:12-05:00" level=debug msg="completed challenge" Dec 08 11:31:12 gbvpi-bedroom go-librespot[2143]: time="2025-12-08T11:31: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 08 11:31:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:31:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:31:12 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:31:12 gbvpi-bedroom volumio[1247]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:31:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 08 11:31:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:15 gbvpi-bedroom go-librespot[2152]: go-librespot daemon starting... Dec 08 11:31:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-05:00" level=debug msg="app state loaded" Dec 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:31:15 gbvpi-bedroom volumio[1247]: info: Initializing connection to go-librespot Websocket Dec 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-05:00" level=debug msg="new websocket client" Dec 08 11:31:15 gbvpi-bedroom volumio[1247]: info: Connection to go-librespot Websocket established Dec 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-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 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-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 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-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 08 11:31:15 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:15-05:00" level=info msg="zeroconf server listening on port 42169" Dec 08 11:31:16 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:16-05:00" level=debug msg="obtained new client token: AACHTZ+7f/pB2P+qXXblOICUv+saV+s9lpQS+ebY6pqT3AgJbeehrOrOGqNVmavvArQpXM2zMSryig+9Wr6km5WfiYmS/bDI5enSg18OVwR7YxXr47rspGPgjP/KEKF/THhsjR/3X/7O3Ti0xs8Ipqa2H+XgTjKXtmcaOwvsinZ2o7DLihHa/yf9A81/uc6X3299D6Wvj0bwAraLqKwBc2cxpOfrv8Thu5CfhG1raKDoblm3VgO7+R8=" Dec 08 11:31:16 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:31:16 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:16-05:00" level=debug msg="completed keyexchange" Dec 08 11:31:16 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31:16-05:00" level=debug msg="completed challenge" Dec 08 11:31:16 gbvpi-bedroom go-librespot[2153]: time="2025-12-08T11:31: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 08 11:31:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:31:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:31:16 gbvpi-bedroom volumio[1247]: info: Connection to go-librespot Websocket closed Dec 08 11:31:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:16 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:16 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Listing playlists Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioClearQueue Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::ClearQueue Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::stop Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreStateMachine::serviceStop Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Received STOP, but no service to execute it Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::clearPlayQueue Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CorePlayQueue::saveQueue Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushState Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output update for this device Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: MRS: Pushing multiroomSync output Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioPushQueue Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Received Get System Version Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Received Get System Info Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: Discovery: Getting this device information Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::volumioGetState Dec 08 11:31:17 gbvpi-bedroom volumio[1247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: info: Getting Spotify volume Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: errno: -111, Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: code: 'ECONNREFUSED', Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: syscall: 'connect', Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: address: '127.0.0.1', Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: port: 9879, Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: response: undefined Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: } Dec 08 11:31:18 gbvpi-bedroom volumio[1247]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 11:31:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 08 11:31:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:19 gbvpi-bedroom go-librespot[2175]: go-librespot daemon starting... Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=debug msg="app state loaded" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31: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-gew1.spotify.com:80]" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-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 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-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 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=info msg="zeroconf server listening on port 38439" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=debug msg="obtained new client token: AACOCVLux7ObZM/UnC7wsEWAGTYqV82zZ75izwyuA8XyZdpCLsRwqruGH3KqBYpymJ3EtgSVuW3Xsy68svKQ/y6abB5d5sKrfMh4Ut1xdx6QFH4h7P9Rr4G2nv7NX4b0zMg/B32aVjoaw2Ddm5ohLK51FIRktTi1eilgiCCOwc6cQaTwe9ZJyDkBepzmpclwRItrjJyZSsh1GdBvGC47gWI1RQIabON91YF+lC1FVTxqyVEZqT00+wxINw==" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=debug msg="completed keyexchange" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-05:00" level=debug msg="completed challenge" Dec 08 11:31:19 gbvpi-bedroom go-librespot[2176]: time="2025-12-08T11:31:19-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 08 11:31:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 11:31:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 11:31:22 gbvpi-bedroom sudo[2200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-08 11:30' Dec 08 11:31:22 gbvpi-bedroom sudo[2200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 11:31:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 08 11:31:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 11:31:23 gbvpi-bedroom go-librespot[2202]: go-librespot daemon starting... Dec 08 11:31:23 gbvpi-bedroom go-librespot[2203]: time="2025-12-08T11:31:23-05:00" level=info msg="running go-librespot 0.4.0" Dec 08 11:31:23 gbvpi-bedroom go-librespot[2203]: time="2025-12-08T11:31:23-05:00" level=debug msg="app state loaded" Dec 08 11:31:23 gbvpi-bedroom go-librespot[2203]: time="2025-12-08T11:31:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"