Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Discovery: A device disappeared from network Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Discovery: Browse raised the following error TypeError: Cannot read properties of undefined (reading 'toLowerCase') Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: VolumeController:: Volume=91 Mute =false Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreStateMachine::pushState Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Completed loading Core Plugins Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Preparing to generate the ALSA configuration file Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Asound.conf file written Dec 07 08:16:00 gbvpi-bedroom sudo[8659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 08:16:00 gbvpi-bedroom sudo[8659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:00 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:16:00] [connect] Successful connection Dec 07 08:16:00 gbvpi-bedroom sudo[8659]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Output device has changed, restarting MPD Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Output device has changed, restarting Shairport Sync Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:00 gbvpi-bedroom sudo[8665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:16:00 gbvpi-bedroom sudo[8665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:00 gbvpi-bedroom sudo[8665]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:00 gbvpi-bedroom sudo[8667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:16:00 gbvpi-bedroom sudo[8667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: ___________ START PLUGINS ___________ Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: ControllerMpd::onStart: Initializing MPD Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Creating MPD Configuration file Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: [1765113360324] CoreMusicLibrary::Adding element Media Servers Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:00 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.309s CPU time. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 08:16:00 gbvpi-bedroom sudo[8676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 08:16:00 gbvpi-bedroom sudo[8676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:00 gbvpi-bedroom sudo[8676]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:00 gbvpi-bedroom sudo[8677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:16:00 gbvpi-bedroom sudo[8677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: [1765113360404] CoreMusicLibrary::Adding element Last_100 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: [1765113360408] CoreMusicLibrary::Adding element Webradio Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Initializing BBC Radios Dec 07 08:16:00 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 08:16:00 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Discovery: Getting this device information Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: [1765113360502] CoreMusicLibrary::Adding element Jellyfin Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: Cannot find translation for source Jellyfin Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: 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":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"} Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Creating Spotify config file Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:00 gbvpi-bedroom sudo[8696]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 08:16:00 gbvpi-bedroom sudo[8696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 08:16:00 gbvpi-bedroom sudo[8696]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:00 gbvpi-bedroom volumio[8531]: info: Volumio Calling Home Dec 07 08:16:00 gbvpi-bedroom volumio[8626]: Starting albumart workers Dec 07 08:16:00 gbvpi-bedroom volumio[8625]: Starting albumart workers Dec 07 08:16:01 gbvpi-bedroom volumio[8624]: Starting albumart workers Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: MPD Permissions set Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: MPD Permissions set Dec 07 08:16:01 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:16:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765113360 101 Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Spotify config file written Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom sudo[8711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 08:16:01 gbvpi-bedroom sudo[8711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: No need to fix Spotify hosts Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Starting Shairport Sync Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Starting Shairport Sync Dec 07 08:16:01 gbvpi-bedroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 07 08:16:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 07 08:16:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Starting Shairport Sync Dec 07 08:16:01 gbvpi-bedroom sudo[8725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:01 gbvpi-bedroom sudo[8725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:01 gbvpi-bedroom sudo[8727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:01 gbvpi-bedroom sudo[8727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:01 gbvpi-bedroom sudo[8570]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:01 gbvpi-bedroom go-librespot[8728]: go-librespot daemon starting... Dec 07 08:16:01 gbvpi-bedroom sudo[8737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:01 gbvpi-bedroom sudo[8737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:01 gbvpi-bedroom sudo[8711]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:01 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:01-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:01 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:01-05:00" level=debug msg="app state loaded" Dec 07 08:16:01 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:01 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:16:01 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:16:01 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:01 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.672s CPU time. Dec 07 08:16:01 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:01 gbvpi-bedroom sudo[8725]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:01 gbvpi-bedroom sudo[8737]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:01 gbvpi-bedroom sudo[8727]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Shairport-Sync Started Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: Error adding Membership: Error: addMembership EINVAL Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Shairport-Sync Started Dec 07 08:16:01 gbvpi-bedroom volumio[8531]: info: Shairport-Sync Started Dec 07 08:16:02 gbvpi-bedroom mpd[8706]: 2025-12-07T08:16:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 08:16:02 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 08:16:02 gbvpi-bedroom sudo[8667]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:02 gbvpi-bedroom sudo[8677]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: info: Completed starting Core Plugins Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: info: ------------------------------------------- Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: info: ----- MyVolumio plugins startup ---- Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: info: ------------------------------------------- Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: error: MPD error: The expression evaluated to a falsy value: Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: assert.ok(self.idling) Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: error: The expression evaluated to a falsy value: Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: assert.ok(self.idling) Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: info: MPD running with PID8706 Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: ,establishing connection Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: error: updateQueue error: null Dec 07 08:16:02 gbvpi-bedroom volumio[8531]: error: updateQueue error: null Dec 07 08:16:04 gbvpi-bedroom volumio[8531]: info: go-librespot daemon successfully initialized Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: Listing playlists Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: Listing playlists Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: Listing playlists Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: Listing playlists Dec 07 08:16:05 gbvpi-bedroom sudo[8778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:16:05 gbvpi-bedroom sudo[8778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:05 gbvpi-bedroom sudo[8780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:16:05 gbvpi-bedroom sudo[8780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:05 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 08:16:05 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 08:16:05 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 08:16:05 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 08:16:05 gbvpi-bedroom sudo[8778]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:05 gbvpi-bedroom sudo[8780]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:05 gbvpi-bedroom mpd_monitor.sh[8783]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: Successfully started MPD Monitor Dec 07 08:16:05 gbvpi-bedroom volumio[8531]: info: Successfully started MPD Monitor Dec 07 08:16:06 gbvpi-bedroom volumio[8531]: info: Volumio called home Dec 07 08:16:06 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 08:16:06 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:06-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 07 08:16:06 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:06-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 07 08:16:06 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:06-05:00" level=info msg="zeroconf server listening on port 32779" Dec 07 08:16:07 gbvpi-bedroom volumio[8531]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 08:16:07 gbvpi-bedroom sudo[8803]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 08:16:07 gbvpi-bedroom sudo[8803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:07 gbvpi-bedroom sudo[8805]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 08:16:07 gbvpi-bedroom sudo[8803]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:07 gbvpi-bedroom sudo[8805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:07 gbvpi-bedroom sudo[8805]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:07 gbvpi-bedroom sudo[8808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 08:16:07 gbvpi-bedroom sudo[8808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:07 gbvpi-bedroom sudo[8808]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:07 gbvpi-bedroom volumio[8531]: info: Upmpdcli Daemon Started Dec 07 08:16:07 gbvpi-bedroom volumio[8531]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: Discovery: Found device GBVPi-Bedroom Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: Discovery: Found device GBVPi-Bedroom Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:10 gbvpi-bedroom volumio[8531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 07 08:16:12 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:12-05:00" level=debug msg="obtained new client token: AACOvTxxjnpNaHVz6+Bz6CLozg+aGLA/Yo/pIuMRWIuImTpf/7HYP7KXPUnipY8BjKEpg/YB1+vytxjayvpFH2M+XWbLYU2J601Ngs4iyk9PqI4Q2r7u4x07R6ozWtbIISUdOuT2o6iFm18NIBFKeI0jiVm/VuOb8gkxHNPvfBVq8bAdj79ttTx88e0N4f7AAhCcgHZETjidulWnJYrqiA+xn58rsXqVND28BWMaI680H4035kHI+vdrfA==" Dec 07 08:16:15 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:15 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:15 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:15 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:15 gbvpi-bedroom volumio[8531]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 07 08:16:17 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:17 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:17-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:17 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:17-05:00" level=debug msg="completed challenge" Dec 07 08:16:17 gbvpi-bedroom go-librespot[8738]: time="2025-12-07T08:16:17-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 07 08:16:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 07 08:16:20 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:20 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:20 gbvpi-bedroom go-librespot[8825]: go-librespot daemon starting... Dec 07 08:16:20 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:20-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:20 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:20-05:00" level=debug msg="app state loaded" Dec 07 08:16:20 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:20-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Discovery: Found device NorthPi-Soundstation Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Discovery: this is already registered, 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Discovery: Found device NorthPi-Soundstation Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 08:16:20 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:20-05:00" level=debug msg="new websocket client" Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: Connection to go-librespot Websocket established Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:20 gbvpi-bedroom volumio[8531]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-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 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-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 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=info msg="zeroconf server listening on port 36179" Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=debug msg="obtained new client token: AAC2vRaYeE2oAKz+4BjMoJJlAtjPtomCGUx9cfKGpzRbZF6IH4R2v65lTUvnETHZDYcSkAGTAKmC+wvYOsWKTeH7ASyQyrq+E73nlgzwRBboqjEEycCRLfFNSvsRFEk5ESxsdBoovkPxXc4XLTcghnzFcP3UCVk952j1QXj319s2LjF99OGPGJu1cm8QrJfpGZVMN2hxDwdanK/IxLRiLhVmvR/EwMxk67icXz2sY/Jfpnk927ZU08U=" Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=debug msg="completed challenge" Dec 07 08:16:21 gbvpi-bedroom go-librespot[8826]: time="2025-12-07T08:16:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: MyVolumio login type: Token Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 08:16:21 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: Streaming services startup Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: Starting Streaming Daemon Dec 07 08:16:22 gbvpi-bedroom sudo[8834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 08:16:22 gbvpi-bedroom sudo[8834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 08:16:22 gbvpi-bedroom sudo[8834]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: Connection to go-librespot Websocket closed Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: error: Cannot start Volumio Streaming Daemon Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: MyVolumio token set successfully Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: MYVOLUMIO: Adding device Dec 07 08:16:22 gbvpi-bedroom volumio[8531]: info: MYVOLUMIO: Evaluating Server Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: MyVolumio Plan changed: premium Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Removing audio output: Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: MYVOLUMIO: Adding device Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: MYVOLUMIO: Evaluating Server Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Remote config written successfully Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Starting Tunnel 1 Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Starting Tunnel Connection Checker Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Completed starting MyVolumio Plugin Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: MYVolumio Device enabled Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: MyVolumio status changed Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Streaming services startup Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: Starting Streaming Daemon Dec 07 08:16:23 gbvpi-bedroom sudo[8879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 08:16:23 gbvpi-bedroom sudo[8879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 07 08:16:23 gbvpi-bedroom sudo[8879]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 07 08:16:23 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 07 08:16:24 gbvpi-bedroom sudo[8883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 07 08:16:24 gbvpi-bedroom sudo[8883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:24 gbvpi-bedroom sudo[8883]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: MRS: MultiRoom plugin initialized Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: MRS: STOPPING SNAPCLIENT Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: MRS: Snap server stop Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: MRS: STOPPING volumioStreaming Dec 07 08:16:24 gbvpi-bedroom sudo[8900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 07 08:16:24 gbvpi-bedroom sudo[8900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:24 gbvpi-bedroom sudo[8902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 07 08:16:24 gbvpi-bedroom sudo[8902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 07 08:16:24 gbvpi-bedroom sudo[8908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 07 08:16:24 gbvpi-bedroom sudo[8904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 07 08:16:24 gbvpi-bedroom sudo[8904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:24 gbvpi-bedroom sudo[8908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 07 08:16:24 gbvpi-bedroom sudo[8908]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 07 08:16:24 gbvpi-bedroom sudo[8902]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:24 gbvpi-bedroom sudo[8900]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 07 08:16:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 07 08:16:24 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: Preparing to generate the ALSA configuration file Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: Getting Spotify volume Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: Setting Geolocation for MyVolumio to us4 Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:24 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 07 08:16:24 gbvpi-bedroom go-librespot[8911]: go-librespot daemon starting... Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: Reading ALSA contributions from plugins. Dec 07 08:16:24 gbvpi-bedroom sudo[8904]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=debug msg="app state loaded" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: Setting Geolocation for MyVolumio to us1 Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: errno: -111, Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: code: 'ECONNREFUSED', Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: syscall: 'connect', Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: address: '127.0.0.1', Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: port: 9879, Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: response: undefined Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: } Dec 07 08:16:24 gbvpi-bedroom volumio[8531]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-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 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-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 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=info msg="zeroconf server listening on port 33709" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=debug msg="obtained new client token: AABP3JfT+ozEU5xzk49vmlM+Vgj2NGMBXOiwjR8ZcAdIaLfuhuVEJpVvT8FQ9PJGpo7VTFcrq9NqGOm4bJUtQG0WVks5JZbv1JYka7L8+B1MvCL795XqwYJQsiS/XhWnaqwppQeRqQWyxke6uEZNL8lea/h7k2zh4Ln2e5UY2XqerHp9zwzRtK++bGhw8mzYm9I5pwqJmokuBQHx6tZyXS+3CQyZk349X7Q8z1AbyIBl0rNByWGDzJ6WZw==" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=debug msg="completed challenge" Dec 07 08:16:24 gbvpi-bedroom go-librespot[8912]: time="2025-12-07T08:16:24-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:24 gbvpi-bedroom sudo[8933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 08:15' Dec 07 08:16:24 gbvpi-bedroom sudo[8933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:24 gbvpi-bedroom sudo[8933]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:25 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:16:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 07 08:16:25 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:16:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 07 08:16:25 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:25 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: volumio.service: Consumed 17.807s CPU time. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2586. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: volumio.service: Consumed 17.807s CPU time. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 07 08:16:25 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 08:16:26 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:26 gbvpi-bedroom volumio[8955]: info: ----- Volumio3 ---- Dec 07 08:16:26 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:26 gbvpi-bedroom volumio[8955]: info: ----- System startup ---- Dec 07 08:16:26 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: MYVOLUMIO Environment detected Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Plugin folders cleanup Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning into folder /volumio/app/plugins/ Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category audio_interface Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category miscellanea Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category music_service Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category plugins.json Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category system_controller Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category user_interface Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning into folder /data/plugins/ Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Scanning category music_service Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Plugin folders cleanup completed Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: ----- Core plugins startup ---- Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Loading plugins from folder /volumio/app/plugins/ Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Adding plugin upnp to MyMusic Plugins Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Loading plugins from folder /data/plugins/ Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Loading plugin "system"... Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Loading plugin "appearance"... Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Loading plugin "network"... Dec 07 08:16:27 gbvpi-bedroom volumio[8955]: info: Refreshing Cached IP Addresses Dec 07 08:16:27 gbvpi-bedroom sudo[8983]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 08:16:27 gbvpi-bedroom sudo[8983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:27 gbvpi-bedroom sudo[8985]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 08:16:27 gbvpi-bedroom sudo[8985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:27 gbvpi-bedroom sudo[8983]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "services"... Dec 07 08:16:28 gbvpi-bedroom sudo[8985]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "alsa_controller"... Dec 07 08:16:28 gbvpi-bedroom sudo[8994]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 07 08:16:28 gbvpi-bedroom sudo[8994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "wizard"... Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "networkfs"... Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Starting Udev Watcher for removable devices Dec 07 08:16:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 07 08:16:28 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Ignoring mount for partition: boot Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Ignoring mount for partition: volumio Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Ignoring mount for partition: volumio_data Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "volumio_command_line_client"... Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "upnp"... Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: [1765113388100] Starting Upmpd Daemon Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "my_music"... Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "mpd"... Dec 07 08:16:28 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:28 gbvpi-bedroom go-librespot[9016]: go-librespot daemon starting... Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=debug msg="app state loaded" Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:28 gbvpi-bedroom volumio[8955]: info: Loading plugin "upnp_browser"... Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-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 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-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 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=info msg="zeroconf server listening on port 37905" Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=debug msg="obtained new client token: AAD1mEAD4aUlAFaNi1zAZFkfoZVJ12P/m/OPn+g0l4rzObRlJnwSv/HiN/LNQEDS79ppwbgFjuh0mr/P2clYkoHl9Jc5Zt3xnMEe+0Nui0aU5rQ0UKXEIHeh59uPPomlP10SILI6McEprmL2WeLm8MKAJ81cmdx8zF+8+NIOZ6zWS7Vhek1mJfFkllVpwa3P/3oV5BPY0wGh63ajVT7SEMuR6bpEZ0Ke2SnFNq9u7utu+gm3LHevvJ+YHQ==" Dec 07 08:16:28 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:28-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:29 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:29-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:29 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:29-05:00" level=debug msg="completed challenge" Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "alarm-clock"... Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "airplay_emulation"... Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Starting Shairport Sync Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "last_100"... Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "webradio"... Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "i2s_dacs"... Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: I2S DAC not set, start Auto-detection Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "volumiodiscovery"... Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: *** WARNING *** For more information see Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: *** WARNING *** For more information see Dec 07 08:16:29 gbvpi-bedroom node[8955]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 08:16:29 gbvpi-bedroom node[8955]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:16:29 gbvpi-bedroom node[8955]: *** WARNING *** For more information see Dec 07 08:16:29 gbvpi-bedroom node[8955]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 08:16:29 gbvpi-bedroom node[8955]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:16:29 gbvpi-bedroom node[8955]: *** WARNING *** For more information see Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "jellyfin"... Dec 07 08:16:29 gbvpi-bedroom go-librespot[9017]: time="2025-12-07T08:16:29-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 07 08:16:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:29 gbvpi-bedroom volumio[8955]: info: Loading plugin "spop"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading plugin "outputs"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading plugin "albumart"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Plugin example_plugin is not enabled Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading plugin "inputs"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading plugin "updater_comm"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Plugin mpdemulation is not enabled Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading plugin "rest_api"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading plugin "websocket"... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Starting Socket.io Server version 1.7.4 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Loading i18n strings for locale en Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: Updating browse sources language Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::initPlayerControls Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: Express server listening on port 3000 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: [Metrics] WebUI: 3s 711.95ms Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::resetVolumioState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::getcurrentVolume Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Volumio Network Manager: Network status updated: 2 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: VolumeController:: Volume=91 Mute =false Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::pushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::updateTrackBlock Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrackBlock Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 08:16:30 gbvpi-bedroom volumio[9026]: Forking 3 albumart workers Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Reloading queue from file Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::setRepeat null single undefined Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::pushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::setRandom null Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::pushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Setting Device type: Raspberry PI Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: VolumeController:: Volume=91 Mute =false Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::pushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Completed loading Core Plugins Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Preparing to generate the ALSA configuration file Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Discovery: Found device GBVPi-Bedroom Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Discovery: Found device GBVPi-Bedroom Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Asound.conf file unchanged, so no further update is needed Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Output device has changed, restarting MPD Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Output device has changed, restarting Shairport Sync Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: ___________ START PLUGINS ___________ Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: ControllerMpd::onStart: Initializing MPD Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Creating MPD Configuration file Dec 07 08:16:30 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:16:30] [connect] Successful connection Dec 07 08:16:30 gbvpi-bedroom sudo[9080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:16:30 gbvpi-bedroom sudo[9080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:30 gbvpi-bedroom sudo[9082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:16:30 gbvpi-bedroom sudo[9082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:30 gbvpi-bedroom sudo[9080]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: [1765113390637] CoreMusicLibrary::Adding element Media Servers Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:30 gbvpi-bedroom sudo[9089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:16:30 gbvpi-bedroom sudo[9089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:30 gbvpi-bedroom sudo[9093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:30 gbvpi-bedroom sudo[9089]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:30 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 08:16:30 gbvpi-bedroom sudo[9093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:30 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 08:16:30 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 08:16:30 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.890s CPU time. Dec 07 08:16:30 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 08:16:30 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 08:16:30 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: [1765113390736] CoreMusicLibrary::Adding element Last_100 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: [1765113390739] CoreMusicLibrary::Adding element Webradio Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Initializing BBC Radios Dec 07 08:16:30 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 08:16:30 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Discovery: Getting this device information Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: [1765113390890] CoreMusicLibrary::Adding element Jellyfin Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:16:30 gbvpi-bedroom sudo[9107]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 08:16:30 gbvpi-bedroom sudo[9107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: Cannot find translation for source Jellyfin Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: 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":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"} Dec 07 08:16:30 gbvpi-bedroom sudo[9107]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: Creating Spotify config file Dec 07 08:16:30 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: Volumio Calling Home Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: MPD Permissions set Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: MPD Permissions set Dec 07 08:16:31 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:16:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765113390 101 Dec 07 08:16:31 gbvpi-bedroom volumio[9046]: Starting albumart workers Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: Spotify config file written Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom sudo[9127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 08:16:31 gbvpi-bedroom sudo[9127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:31 gbvpi-bedroom volumio[9049]: Starting albumart workers Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[9048]: Starting albumart workers Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: No need to fix Spotify hosts Dec 07 08:16:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:31 gbvpi-bedroom go-librespot[9139]: go-librespot daemon starting... Dec 07 08:16:31 gbvpi-bedroom sudo[9127]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:31 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:31-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:31 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:31-05:00" level=debug msg="app state loaded" Dec 07 08:16:31 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: Volumio called home Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: Starting Shairport Sync Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: Starting Shairport Sync Dec 07 08:16:31 gbvpi-bedroom volumio[8955]: info: Starting Shairport Sync Dec 07 08:16:31 gbvpi-bedroom sudo[9149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:31 gbvpi-bedroom sudo[9149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:31 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:16:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.661s CPU time. Dec 07 08:16:32 gbvpi-bedroom sudo[9147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:32 gbvpi-bedroom sudo[9147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Discovery: Found device NorthPi-Soundstation Dec 07 08:16:32 gbvpi-bedroom sudo[9151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:32 gbvpi-bedroom sudo[9151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:32 gbvpi-bedroom sudo[9149]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:16:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:16:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:16:32 gbvpi-bedroom sudo[8994]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:32 gbvpi-bedroom sudo[9151]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:32 gbvpi-bedroom sudo[9147]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-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 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-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 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-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 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-05:00" level=info msg="zeroconf server listening on port 38297" Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Shairport-Sync Started Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: Error adding Membership: Error: addMembership EINVAL Dec 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-05:00" level=debug msg="obtained new client token: AAB4N6bem5cUneamplWda/FFpONaDQtdjpV3l3aSgpUMdEY7xG4I0g0B48tueOrSkenfWZraubzDe1pVHlgZonl+mqLyMbIsjVf1Fn/7elbRqCCMQd44pY6z8LsUamyUXwGE+6u7j25FizlhF6ygRY0YfXPwhvdHECENnt8WEviCCtH53TUC+RiRMxELQHR/LuMldoo1Brr4YOrlrcRheKnLCPcDkzsPrPTbzTJ+5FTBcgVn/vUNh+LHUw==" Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Shairport-Sync Started Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Shairport-Sync Started Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-05:00" level=debug msg="completed challenge" Dec 07 08:16:32 gbvpi-bedroom go-librespot[9140]: time="2025-12-07T08:16:32-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:32 gbvpi-bedroom volumio[8955]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 08:16:32 gbvpi-bedroom mpd[9120]: 2025-12-07T08:16:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 08:16:32 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 08:16:32 gbvpi-bedroom sudo[9082]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:32 gbvpi-bedroom sudo[9093]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: info: Completed starting Core Plugins Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: info: ----- MyVolumio plugins startup ---- Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: info: ------------------------------------------- Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: error: MPD error: The expression evaluated to a falsy value: Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: assert.ok(self.idling) Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: error: The expression evaluated to a falsy value: Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: assert.ok(self.idling) Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: error: updateQueue error: null Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: info: MPD running with PID9120 Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: ,establishing connection Dec 07 08:16:33 gbvpi-bedroom volumio[8955]: error: updateQueue error: null Dec 07 08:16:34 gbvpi-bedroom volumio[8955]: info: go-librespot daemon successfully initialized Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:35 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:35 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 07 08:16:35 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:35 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:35 gbvpi-bedroom go-librespot[9196]: go-librespot daemon starting... Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=debug msg="app state loaded" Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-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 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-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 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=info msg="zeroconf server listening on port 41247" Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=debug msg="obtained new client token: AAAaT4GU75AeCMUXrX1SbG2zI4rGoZ2ISCD8Bl/fp04YD027sWhfWlA3aLUvQVAua/kWpLWiwLtu2Uh3WP/5R45SCAADUP2He3ZCML8apFFHRwuoP/QLRoh69yMwbitIO/6ZTipWFE+3F1SXItzI5LqbRQSDaIZpypU7VFqPX9rk8ZuELQLox5zoGYUTfDnijskCIIyh9ub9jz1OU7k0nR73o+HwjsyWDfvrhkM7gCZsDTjupzwMr1B7Ag==" Dec 07 08:16:35 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:36 gbvpi-bedroom sudo[9205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:16:36 gbvpi-bedroom sudo[9205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:36 gbvpi-bedroom sudo[9207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:16:36 gbvpi-bedroom sudo[9207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:36 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:36-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:36 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:36-05:00" level=debug msg="completed challenge" Dec 07 08:16:36 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 08:16:36 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 08:16:36 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 08:16:36 gbvpi-bedroom go-librespot[9197]: time="2025-12-07T08:16:36-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:36 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 08:16:36 gbvpi-bedroom sudo[9205]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:36 gbvpi-bedroom sudo[9207]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:36 gbvpi-bedroom volumio[8955]: info: Successfully started MPD Monitor Dec 07 08:16:36 gbvpi-bedroom mpd_monitor.sh[9210]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 08:16:36 gbvpi-bedroom volumio[8955]: info: Successfully started MPD Monitor Dec 07 08:16:37 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:37 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:38 gbvpi-bedroom volumio[8955]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 08:16:38 gbvpi-bedroom sudo[9230]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 08:16:38 gbvpi-bedroom sudo[9230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:38 gbvpi-bedroom sudo[9230]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:38 gbvpi-bedroom sudo[9232]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 08:16:38 gbvpi-bedroom sudo[9232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:38 gbvpi-bedroom sudo[9232]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:38 gbvpi-bedroom sudo[9235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 08:16:38 gbvpi-bedroom sudo[9235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:38 gbvpi-bedroom sudo[9235]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:38 gbvpi-bedroom volumio[8955]: info: Upmpdcli Daemon Started Dec 07 08:16:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 07 08:16:39 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:39 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:39 gbvpi-bedroom go-librespot[9238]: go-librespot daemon starting... Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=debug msg="app state loaded" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-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 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-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 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-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 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=info msg="zeroconf server listening on port 42299" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=debug msg="obtained new client token: AAAlDkd2VCo1SgoPR8O5OSYQMyFkF1o/qbHIpwnuqqqodS5d9y/gXL8ksKwm3fV8zHLizFqO8gYJVA1x33kJWks1MQAIej0RjGi6Zq/GipIOJ+874DP9LATtUvWdbHedPFwS5PiXN6MbWR9EK/5IfUZKgz7yLw4yjMC/xksK6/GLMU/Ob8miisao34jhUO4vebyaDI7OuBgTEtvsAk+nV+obdRTK1kJhOBFEg7Drs895uQ3Hx6s/UeHISQ==" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=debug msg="completed challenge" Dec 07 08:16:39 gbvpi-bedroom go-librespot[9239]: time="2025-12-07T08:16:39-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:40 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:40 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: MyVolumio login type: Token Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 08:16:41 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Streaming services startup Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Starting Streaming Daemon Dec 07 08:16:42 gbvpi-bedroom sudo[9247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 08:16:42 gbvpi-bedroom sudo[9247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 08:16:42 gbvpi-bedroom sudo[9247]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: error: Cannot start Volumio Streaming Daemon Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MyVolumio token set successfully Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MYVOLUMIO: Adding device Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MYVOLUMIO: Evaluating Server Dec 07 08:16:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 07 08:16:42 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:42 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:42 gbvpi-bedroom go-librespot[9256]: go-librespot daemon starting... Dec 07 08:16:42 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:42-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:42 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:42-05:00" level=debug msg="app state loaded" Dec 07 08:16:42 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:42-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MyVolumio Plan changed: premium Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Removing audio output: Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MYVOLUMIO: Adding device Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: MYVOLUMIO: Evaluating Server Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Remote config written successfully Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Starting Tunnel 1 Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Starting Tunnel Connection Checker Dec 07 08:16:42 gbvpi-bedroom volumio[8955]: info: Completed starting MyVolumio Plugin Dec 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-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 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-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 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-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 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-05:00" level=info msg="zeroconf server listening on port 41405" Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: MYVolumio Device enabled Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: MyVolumio status changed Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: Streaming services startup Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: Starting Streaming Daemon Dec 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-05:00" level=debug msg="obtained new client token: AAAUebRj+SVN4zTd7tzzW29qqPoBjM/TPwgTOPOUAzLGg2PtHeJ+zTceRYqneQqglqrZO9B/1nRCQFoMlIrRlbkrbSocLgbYWUZV1ru1K+iX3DQ+us8N19UncYwrc7LGPv0FXwdaLdG0JHAJUX5NjP3eC0tSn4D7vCxZ1vIMd8rCK+dnkcqv6Bj/jJe2SJigq8bTgH/VOEYBw2Wb4YWnLgjpaMexHfhmThtls30pMLbpFuYV/7htTfI=" Dec 07 08:16:43 gbvpi-bedroom sudo[9301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 08:16:43 gbvpi-bedroom sudo[9301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:43 gbvpi-bedroom sudo[9301]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-05:00" level=debug msg="completed challenge" Dec 07 08:16:43 gbvpi-bedroom go-librespot[9267]: time="2025-12-07T08:16:43-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 07 08:16:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 07 08:16:43 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 07 08:16:44 gbvpi-bedroom sudo[9305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 07 08:16:44 gbvpi-bedroom sudo[9305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom sudo[9305]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: MultiRoom plugin initialized Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: STOPPING SNAPCLIENT Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: Snap server stop Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: STOPPING volumioStreaming Dec 07 08:16:44 gbvpi-bedroom sudo[9322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 07 08:16:44 gbvpi-bedroom sudo[9322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 07 08:16:44 gbvpi-bedroom sudo[9324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 07 08:16:44 gbvpi-bedroom sudo[9324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom sudo[9329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 07 08:16:44 gbvpi-bedroom sudo[9329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom sudo[9328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 07 08:16:44 gbvpi-bedroom sudo[9328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom sudo[9329]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 07 08:16:44 gbvpi-bedroom sudo[9322]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom sudo[9324]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 07 08:16:44 gbvpi-bedroom sudo[9328]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Preparing to generate the ALSA configuration file Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Setting Geolocation for MyVolumio to us4 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Setting Geolocation for MyVolumio to us4 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Reading ALSA contributions from plugins. Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: Removed streaming files Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: volumioStreaming STOPPED Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: SNAPSERVER STOPPED Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: SNAPCLIENT STOPPED Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: error: Cannot start Volumio Streaming Daemon Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Asound.conf file written Dec 07 08:16:44 gbvpi-bedroom sudo[9336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 08:16:44 gbvpi-bedroom sudo[9336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom sudo[9336]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Output device has changed, restarting MPD Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Output device has changed, restarting Shairport Sync Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:44 gbvpi-bedroom sudo[9342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:16:44 gbvpi-bedroom sudo[9342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom sudo[9342]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:44 gbvpi-bedroom sudo[9344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:16:44 gbvpi-bedroom sudo[9344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 07 08:16:44 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output for this device Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding audio output: Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding audio output: Dec 07 08:16:44 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 08:16:44 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 08:16:44 gbvpi-bedroom systemd[1]: mpd.service: Consumed 2.007s CPU time. Dec 07 08:16:44 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 08:16:44 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 08:16:44 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:44 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.41605 Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding METAVOLUMIO REST API Endpoints Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Preparing CD Folders Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding CD REST API Endpoints Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Starting UDEV Watcher for CD Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: Detecting CD presence with UDEV Dec 07 08:16:44 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 07 08:16:44 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.41605 disconnected from D-Bus Dec 07 08:16:44 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 08:16:44 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 08:16:44 gbvpi-bedroom sudo[9362]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 08:16:44 gbvpi-bedroom sudo[9362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 08:16:44 gbvpi-bedroom sudo[9362]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:45 gbvpi-bedroom mpd[9364]: 2025-12-07T08:16:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 08:16:45 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 08:16:45 gbvpi-bedroom sudo[9344]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:46 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 07 08:16:46 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:46 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:46 gbvpi-bedroom go-librespot[9367]: go-librespot daemon starting... Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="app state loaded" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=info msg="zeroconf server listening on port 32951" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="obtained new client token: AAC5xBvnHA8Q+CXIAgsR/pjQ7alWlJAiBDOFX+fKsGRP5vVjuFcntVHjiNIK94XZkXiKhFXl3z5eom0DcxN6UqAQw9FJYkaWaEuKBdm2WBRmNU3Cyrz1In7/4XC7AxM1A7aZ0Bq5K7OQvj0LLFyvwdgnXCLAAsoJILmflsc33XtA65Yx1+s/rhRCbcbTsaL7yTMD5GVUYMnT2MpfZ/mAa0A/vQ527IgsR3RRcjwXY1GyKerkxvG7cyJbSA==" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:46 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:46-05:00" level=debug msg="completed challenge" Dec 07 08:16:47 gbvpi-bedroom go-librespot[9368]: time="2025-12-07T08:16:47-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 08:16:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding inputs REST Endpoints Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Scanning Audio Inputs Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Checking against Known Cards name Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding Server instance for streaming Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: error: Hi Res Audio Failed Login: Missing Login Data Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 07 08:16:49 gbvpi-bedroom sudo[9393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 07 08:16:49 gbvpi-bedroom sudo[9393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 07 08:16:49 gbvpi-bedroom sudo[9400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 07 08:16:49 gbvpi-bedroom sudo[9400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding TIDAL REST API Endpoints Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Stopping AccessToken refresher cron for QOBUZ Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 07 08:16:49 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 8436 (vtcs) with signal SIGKILL. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 07 08:16:49 gbvpi-bedroom sudo[9393]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: AccessToken refresher cron started for QOBUZ Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding QOBUZ REST API Endpoints Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Updating MyVolumio device info Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom sudo[9400]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Updating MyVolumio device info Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MRS: Getting audio outputs on start Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MRS: Requesting all other devices output Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:49 gbvpi-bedroom sudo[9403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 07 08:16:49 gbvpi-bedroom sudo[9403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Successfully Added MyVolumio device Dec 07 08:16:49 gbvpi-bedroom qobuz-connect[8407]: 20251207 08:16:49.706 [8407.8407] INFO SampleApp: Stopping Local configuration server Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Successfully Added MyVolumio device Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MRS: Adding multiroomSync output Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding audio output: Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MPD Permissions set Dec 07 08:16:49 gbvpi-bedroom sudo[9407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 07 08:16:49 gbvpi-bedroom sudo[9407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom sudo[9407]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: error: updateQueue error: null Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioStop Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::stop Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Starting Shairport Sync Dec 07 08:16:49 gbvpi-bedroom sudo[9422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 07 08:16:49 gbvpi-bedroom sudo[9422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding audio output: Dec 07 08:16:49 gbvpi-bedroom sudo[9424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Adding audio output: Dec 07 08:16:49 gbvpi-bedroom sudo[9424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Successfully Updated MyVolumio device Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:16:49 gbvpi-bedroom autossh[8380]: received signal to exit (15) Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 07 08:16:49 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.483s CPU time. Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Successfully Updated MyVolumio device Dec 07 08:16:49 gbvpi-bedroom sudo[9424]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:16:49 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 07 08:16:49 gbvpi-bedroom sudo[9422]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:49 gbvpi-bedroom volumio[8955]: info: Remote SSH Started Dec 07 08:16:49 gbvpi-bedroom autossh[9429]: port set to 0, monitoring disabled Dec 07 08:16:49 gbvpi-bedroom autossh[9429]: starting ssh (count 1) Dec 07 08:16:49 gbvpi-bedroom autossh[9429]: ssh child pid is 9432 Dec 07 08:16:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 07 08:16:50 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:50 gbvpi-bedroom volumio[8955]: info: Shairport-Sync Started Dec 07 08:16:50 gbvpi-bedroom volumiossh-tunnel[9432]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts. Dec 07 08:16:50 gbvpi-bedroom volumio[8955]: info: MRS: Pushing audio output on request Dec 07 08:16:50 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output Dec 07 08:16:50 gbvpi-bedroom volumio[8955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 07 08:16:50 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:50 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:50 gbvpi-bedroom go-librespot[9447]: go-librespot daemon starting... Dec 07 08:16:50 gbvpi-bedroom volumio[8955]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=debug msg="app state loaded" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-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 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-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 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-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 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=info msg="zeroconf server listening on port 37411" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=debug msg="obtained new client token: AABYdl9H20b5BnN5fRAw4bfuYk/hmul+sVLzIpHuWqpixxFX6o2f2wPG6qY7LN/I+3F1XzA67pq8eb7H4f8wk8Ew/TZOwgNMuM2tOIIQXdcx9XdJkDPI+zLDrsAi0a/rvi3CPBbmeYIu8yOM0O7KFgI7mPCETQmSiO1rRhOsT1vrjFyjiaagZJZLP4pVEvREEWCbsJA6InMpyQBrmJlRYaIfAr4YO4n0ov9IYhLnnKoj94Fw95SS1anWeQ==" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-05:00" level=debug msg="completed challenge" Dec 07 08:16:50 gbvpi-bedroom go-librespot[9448]: time="2025-12-07T08:16:50-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 07 08:16:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:51 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 07 08:16:51 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 08:16:51 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 08:16:51 gbvpi-bedroom sudo[9403]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:51 gbvpi-bedroom volumio[8955]: info: Executing endpoint qc_getconfig Dec 07 08:16:51 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.285 [9456.9456] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.289 [9456.9456] INFO VolumeManager: [0x1d87588]: Setting new playback volume: 75 Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.289 [9456.9456] INFO VolumeManager: [0x1d87588]: Setting new mute state: 0 Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.289 [9456.9456] INFO QobuzConnect: [0x1d87f58]: Client initialized! Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.289 [9456.9456] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 07 08:16:51 gbvpi-bedroom volumio[8955]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 07 08:16:51 gbvpi-bedroom volumio[8955]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.302 [9456.9456] INFO LocalConfigManager: [0x1d86e68]: Starting Local Configuration server Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.302 [9456.9456] INFO SampleApp: Starting Local configuration server Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.303 [9456.9456] INFO SampleApp: Connected to UNIX socket client 0x1d71818 Dec 07 08:16:51 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:16:51.436 [9456.9456] INFO SampleApp: Playback volume changed: 75 Dec 07 08:16:51 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: TidalConnect service stoped! Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 07 08:16:52 gbvpi-bedroom sudo[9471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 07 08:16:52 gbvpi-bedroom sudo[9471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:52 gbvpi-bedroom sudo[9475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:16:52 gbvpi-bedroom sudo[9475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:52 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 07 08:16:52 gbvpi-bedroom sudo[9471]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:52 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 08:16:52 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 08:16:52 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 08:16:52 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 08:16:52 gbvpi-bedroom sudo[9475]: pam_unix(sudo:session): session closed for user root Dec 07 08:16:52 gbvpi-bedroom mpd_monitor.sh[9479]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Successfully started MPD Monitor Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Executing endpoint tc_getconfig Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 07 08:16:52 gbvpi-bedroom vtcs[9477]: STARTING TidalConnect services, version: 1.5.2.56 Dec 07 08:16:52 gbvpi-bedroom vtcs[9477]: STARTED TidalConnect services. Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Executing endpoint tc_connect Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Connecting to TidalConnect Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::servicePushState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::pushState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output update for this device Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::servicePushState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreStateMachine::pushState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioPushState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output update for this device Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: MRS: Pushing multiroomSync output Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: CorePlayQueue::getTrack 0 Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 07 08:16:52 gbvpi-bedroom volumio[8955]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 07 08:16:53 gbvpi-bedroom volumio[8955]: info: MRS: Updating multiroomSync output Dec 07 08:16:53 gbvpi-bedroom volumio[8955]: info: MRS: Updating multiroomSync output Dec 07 08:16:53 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 07 08:16:53 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:53 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:53 gbvpi-bedroom go-librespot[9497]: go-librespot daemon starting... Dec 07 08:16:53 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:53-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:53 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:53-05:00" level=debug msg="app state loaded" Dec 07 08:16:53 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:53-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=info msg="zeroconf server listening on port 43957" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="obtained new client token: AAAD0GXqIvWxVmDIKtYmpXvJYsR+vgb81NpI0plyrJbE7MijLV8pw+GcDvGxcz2g1XHdAaPxMdjiWUqHvwmSUdtgJ6HoxPjDbq5Jq/6SGnHezneab9E0XpGVNK2XRFHjQG6vZDv/LNRxkLzYmgYxSdB/5y7goi371Lxx/qobPkxeUXTU4ebSIu2w5uVXGVzxYVGBWdq9FHhCGX++/eB6Aq1yKnQzXvwv+Jrt16m34iZP6Z8h8C5K4eU=" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-05:00" level=debug msg="completed challenge" Dec 07 08:16:54 gbvpi-bedroom go-librespot[9498]: time="2025-12-07T08:16:54-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 07 08:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: Listing playlists Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: TidalConnect service started! Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: [Metrics] CommandRouter: 28s 886.44ms Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumiosetStartupVolume Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::Close All Modals sent Dec 07 08:16:55 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::Close All Modals sent Dec 07 08:16:56 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 08:16:56 gbvpi-bedroom volumio[8955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 07 08:16:56 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:16:56 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 07 08:16:56 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 07 08:16:56 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 07 08:16:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 07 08:16:57 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:57 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:16:57 gbvpi-bedroom go-librespot[9509]: go-librespot daemon starting... Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=debug msg="app state loaded" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16: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-gew1.spotify.com:80]" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-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 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-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 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=info msg="zeroconf server listening on port 42451" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=debug msg="obtained new client token: AABMVlG7Dq5QsXsydJ5JXvR+KfJ47Wlqc3RrcFjSvhuonrWr2o0zr2JdRGdRx/PxNK9S/DTnvuZj4PPUQQ0FWGBqcf7inUapRz6YUmGI2gJuGJt8sFkit+l1CIHKdSzSEWb1yih3/ZyNZuLUqH+xaxQ2v0UUUrjjIljp9k/k7jb84RN40BONAsUSbTUzl3wYPYBz+2LypNhxs9Q4MY5/8ke3QDdRi5gilYJ2EH3SjvH5cGF1wRao9VIf4g==" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=debug msg="completed keyexchange" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16:57-05:00" level=debug msg="completed challenge" Dec 07 08:16:57 gbvpi-bedroom go-librespot[9510]: time="2025-12-07T08:16: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 07 08:16:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:16:57 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:16:58 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:16:58 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:17:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 07 08:17:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:00 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:00 gbvpi-bedroom go-librespot[9532]: go-librespot daemon starting... Dec 07 08:17:00 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:00-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:00 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:00-05:00" level=debug msg="app state loaded" Dec 07 08:17:00 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:00-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-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 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-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 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-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 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-05:00" level=info msg="zeroconf server listening on port 40343" Dec 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-05:00" level=debug msg="obtained new client token: AADXQgmtO8t8Vzhdux32/wsIjwzGhvWZ3NssgBe21ISJZWXBYLwIFFgj/ogcPId0fmBDDYDRTwiE/E/uONMWCUIKqIyTxsWhA6j499KnmQENDHYEH2oq6gxG5kL2kai0tf0yCIUJx1WZznZuI1o5e7RJ8xg8uto51VuFh8YJwARLo2Ai0GkVr8jVmBQaxKUruPrZVgy+JKjzd8PZNMMvth9MhEx1yqx0vxxb2uoB8MD5xdClgRU8TDo=" Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:01 gbvpi-bedroom volumio-remote-updater[11354]: Test mode enabled Dec 07 08:17:01 gbvpi-bedroom volumio-remote-updater[11354]: Alpha mode disabled Dec 07 08:17:01 gbvpi-bedroom volumio-remote-updater[11354]: Alpha legacy test mode disabled Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17:01-05:00" level=debug msg="completed challenge" Dec 07 08:17:01 gbvpi-bedroom go-librespot[9533]: time="2025-12-07T08:17: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 07 08:17:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

ANNOUNCEMENT

\n
    \n
  • Production line
    • \n
\n

FIX

\n
    \n
  • Nodejs 20.5.1 version pinning with static package fallback
    • \n
\n","title":"Update v4.073","updateavailable":true} Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetBrowseSources Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:17:01 gbvpi-bedroom volumio[8955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:17:02 gbvpi-bedroom volumio[8955]: info: BOOT COMPLETED Dec 07 08:17:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 07 08:17:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:04 gbvpi-bedroom go-librespot[9544]: go-librespot daemon starting... Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=debug msg="app state loaded" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-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 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-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 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=info msg="zeroconf server listening on port 45741" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=debug msg="obtained new client token: AABSXBG6sqjOoE6kKrXHliJwwcll39T9SV2JiEISxbP2xsN1upM63F5l4rgE2f3I7o7o/+Colc7MGrjLvhbaWxT04h3diKG8pi00O91Ml3lPaUfXPqYkP/bQh1TLQSPa00RVgjMA4/W8QKHvTDkuvpy41gbzeyWCen3V+9oyxCEVztRY3zav2YKl1ypkBQ4GBnlYXHphZGLMoAV+j6npStpIlHCkhPppUo8hG4CTTUXLxrFrVQNB7KO+rg==" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=debug msg="completed challenge" Dec 07 08:17:04 gbvpi-bedroom volumio[8955]: info: Initializing connection to go-librespot Websocket Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17:04-05:00" level=debug msg="new websocket client" Dec 07 08:17:04 gbvpi-bedroom volumio[8955]: info: Connection to go-librespot Websocket established Dec 07 08:17:04 gbvpi-bedroom go-librespot[9545]: time="2025-12-07T08:17: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 07 08:17:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:04 gbvpi-bedroom volumio[8955]: info: Connection to go-librespot Websocket closed Dec 07 08:17:05 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:05 gbvpi-bedroom volumio[8955]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:05 gbvpi-bedroom volumio[8955]: info: Discovery: Disconnected from remote: 192.168.1.28 Dec 07 08:17:05 gbvpi-bedroom volumio[8955]: info: MRS: Cleaning up device: 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 08:17:05 gbvpi-bedroom volumio[8955]: info: Removing audio output: Dec 07 08:17:06 gbvpi-bedroom volumio[8955]: info: Discovery: A device disappeared from network Dec 07 08:17:06 gbvpi-bedroom volumio[8955]: info: Discovery: Device northpi-soundstation disappeared from network Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: info: Getting Spotify volume Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: errno: -111, Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: code: 'ECONNREFUSED', Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: syscall: 'connect', Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: address: '127.0.0.1', Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: port: 9879, Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: response: undefined Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: } Dec 07 08:17:07 gbvpi-bedroom volumio[8955]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 08:17:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 07 08:17:07 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:07 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:07 gbvpi-bedroom go-librespot[9563]: go-librespot daemon starting... Dec 07 08:17:07 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:07-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:07 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:07-05:00" level=debug msg="app state loaded" Dec 07 08:17:07 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17: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-gew1.spotify.com:80]" Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-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 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-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 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-05:00" level=info msg="zeroconf server listening on port 42849" Dec 07 08:17:08 gbvpi-bedroom sudo[9588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 08:16' Dec 07 08:17:08 gbvpi-bedroom sudo[9588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-05:00" level=debug msg="obtained new client token: AACn+lMDAXBYHm7TrPqK0+UETNWeElToiYa5yWusbKrywh/GmfVfV1IRNL00wtlXl4gh8tHatAhrphtKlJIPPVNxGdpMygEVlrCiipkAjmyoIJrLdhjnGEOOB0knRvRuRZc2ozL1TjIjNFT4+FXbXvCEcPqvYwtj1xSlA05LjIthBG1v+mSDd/fklYXJM+ugXembLQi7YD9Z2C3nrHpagfqfVcTzEWVpqOtsoG2zcf7EBtksuBrUVuk=" Dec 07 08:17:08 gbvpi-bedroom sudo[9588]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:08 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:17:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 07 08:17:08 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:17:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 07 08:17:08 gbvpi-bedroom vtcs[9477]: [2025-12-07 08:17:08.358] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 07 08:17:08 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:17:08.358 [9456.9456] INFO SampleApp: Socket closed Dec 07 08:17:08 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17:08-05:00" level=debug msg="completed challenge" Dec 07 08:17:08 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.192s CPU time. Dec 07 08:17:08 gbvpi-bedroom go-librespot[9565]: time="2025-12-07T08:17: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 07 08:17:08 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2587. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.192s CPU time. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 07 08:17:08 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 08:17:09 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:09 gbvpi-bedroom volumio[9602]: info: ----- Volumio3 ---- Dec 07 08:17:09 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:09 gbvpi-bedroom volumio[9602]: info: ----- System startup ---- Dec 07 08:17:09 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: MYVOLUMIO Environment detected Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Plugin folders cleanup Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning into folder /volumio/app/plugins/ Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category audio_interface Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category miscellanea Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category music_service Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category plugins.json Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category system_controller Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category user_interface Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning into folder /data/plugins/ Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Scanning category music_service Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Plugin folders cleanup completed Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: ----- Core plugins startup ---- Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugins from folder /volumio/app/plugins/ Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Adding plugin upnp to MyMusic Plugins Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugins from folder /data/plugins/ Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "system"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "appearance"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "network"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Refreshing Cached IP Addresses Dec 07 08:17:10 gbvpi-bedroom sudo[9630]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 08:17:10 gbvpi-bedroom sudo[9630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:10 gbvpi-bedroom sudo[9632]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 08:17:10 gbvpi-bedroom sudo[9632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "services"... Dec 07 08:17:10 gbvpi-bedroom sudo[9630]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:10 gbvpi-bedroom sudo[9632]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "alsa_controller"... Dec 07 08:17:10 gbvpi-bedroom sudo[9640]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 07 08:17:10 gbvpi-bedroom sudo[9640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "wizard"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "networkfs"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Starting Udev Watcher for removable devices Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Ignoring mount for partition: boot Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Ignoring mount for partition: volumio Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Ignoring mount for partition: volumio_data Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "volumio_command_line_client"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "upnp"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: [1765113430859] Starting Upmpd Daemon Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "my_music"... Dec 07 08:17:10 gbvpi-bedroom volumio[9602]: info: Loading plugin "mpd"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "upnp_browser"... Dec 07 08:17:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 07 08:17:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:11 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:11 gbvpi-bedroom go-librespot[9664]: go-librespot daemon starting... Dec 07 08:17:11 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:11-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:11 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:11-05:00" level=debug msg="app state loaded" Dec 07 08:17:11 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "alarm-clock"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "airplay_emulation"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Starting Shairport Sync Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "last_100"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "webradio"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "i2s_dacs"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: I2S DAC not set, start Auto-detection Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "volumiodiscovery"... Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: *** WARNING *** For more information see Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: *** WARNING *** For more information see Dec 07 08:17:11 gbvpi-bedroom node[9602]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 08:17:11 gbvpi-bedroom node[9602]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:17:11 gbvpi-bedroom node[9602]: *** WARNING *** For more information see Dec 07 08:17:11 gbvpi-bedroom node[9602]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 08:17:11 gbvpi-bedroom node[9602]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 08:17:11 gbvpi-bedroom node[9602]: *** WARNING *** For more information see Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:17:11 gbvpi-bedroom volumio[9602]: info: Loading plugin "jellyfin"... Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=info msg="zeroconf server listening on port 35943" Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "spop"... Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="obtained new client token: AAAlx1WDCGUM4zl7gouDtTJMuY+Bkrx8Fm5gYSgvqpKIXwd2iOPYNQ1uX6B4UC7zZYWH8lZAT3EbV9KRw0OVSZJoBpHtWwwb4jEZkQbxHpdSuGOd1c+3bvfaNfR4cFgKL8ejXbKWWfLipubuyr2+WZ1RKjjSyu/xSr4UEa9y7fqv8eZmjUx1CQ8QrZySuSxCGZeDw5A2TW1u1T6DWIDVYcFS9huip5S6N0ogRjJief5Djrt0TwyPt42PRg==" Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17:12-05:00" level=debug msg="completed challenge" Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "outputs"... Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "albumart"... Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Plugin example_plugin is not enabled Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "inputs"... Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "updater_comm"... Dec 07 08:17:12 gbvpi-bedroom go-librespot[9665]: time="2025-12-07T08:17: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 07 08:17:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Plugin mpdemulation is not enabled Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "rest_api"... Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Loading plugin "websocket"... Dec 07 08:17:12 gbvpi-bedroom volumio[9602]: info: Starting Socket.io Server version 1.7.4 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Loading i18n strings for locale en Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: Updating browse sources language Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::initPlayerControls Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: Express server listening on port 3000 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: [Metrics] WebUI: 3s 719.72ms Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::resetVolumioState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::getcurrentVolume Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Volumio Network Manager: Network status updated: 2 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: VolumeController:: Volume=91 Mute =false Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::pushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioPushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::updateTrackBlock Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrackBlock Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Reloading queue from file Dec 07 08:17:13 gbvpi-bedroom volumio[9677]: Forking 3 albumart workers Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::setRepeat null single undefined Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::pushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioPushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::setRandom null Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::pushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioPushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Setting Device type: Raspberry PI Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: VolumeController:: Volume=91 Mute =false Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::pushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioPushState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Discovery: Found device NorthPi-Soundstation Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Completed loading Core Plugins Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Preparing to generate the ALSA configuration file Dec 07 08:17:13 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:17:13] [connect] Successful connection Dec 07 08:17:13 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 08:17:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765113433 101 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Asound.conf file written Dec 07 08:17:13 gbvpi-bedroom sudo[9735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 08:17:13 gbvpi-bedroom sudo[9735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:13 gbvpi-bedroom sudo[9735]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Output device has changed, restarting MPD Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Output device has changed, restarting Shairport Sync Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:13 gbvpi-bedroom sudo[9741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:17:13 gbvpi-bedroom sudo[9741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:13 gbvpi-bedroom sudo[9741]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: ___________ START PLUGINS ___________ Dec 07 08:17:13 gbvpi-bedroom sudo[9745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:17:13 gbvpi-bedroom sudo[9745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: ControllerMpd::onStart: Initializing MPD Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Creating MPD Configuration file Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: [1765113433596] CoreMusicLibrary::Adding element Media Servers Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:17:13 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 08:17:13 gbvpi-bedroom sudo[9752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:17:13 gbvpi-bedroom sudo[9752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:13 gbvpi-bedroom sudo[9753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:17:13 gbvpi-bedroom sudo[9753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:13 gbvpi-bedroom sudo[9752]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:13 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 08:17:13 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 08:17:13 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.268s CPU time. Dec 07 08:17:13 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 08:17:13 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 08:17:13 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: [1765113433720] CoreMusicLibrary::Adding element Last_100 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:17:13 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: [1765113433726] CoreMusicLibrary::Adding element Webradio Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:17:13 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Initializing BBC Radios Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Discovery: Getting this device information Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: [1765113433853] CoreMusicLibrary::Adding element Jellyfin Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: Cannot find translation for source Jellyfin Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: 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":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"} Dec 07 08:17:13 gbvpi-bedroom sudo[9765]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 08:17:13 gbvpi-bedroom sudo[9765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: Creating Spotify config file Dec 07 08:17:13 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:13 gbvpi-bedroom sudo[9765]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Volumio Calling Home Dec 07 08:17:14 gbvpi-bedroom volumio[9701]: Starting albumart workers Dec 07 08:17:14 gbvpi-bedroom volumio[9699]: Starting albumart workers Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Discovery: Found device GBVPi-Bedroom Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Discovery: Found device GBVPi-Bedroom Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: MPD Permissions set Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: MPD Permissions set Dec 07 08:17:14 gbvpi-bedroom volumio[9710]: Starting albumart workers Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Spotify config file written Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: Volumio called home Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom sudo[9785]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 08:17:14 gbvpi-bedroom sudo[9785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:14 gbvpi-bedroom volumio[9602]: info: No need to fix Spotify hosts Dec 07 08:17:14 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:14 gbvpi-bedroom go-librespot[9795]: go-librespot daemon starting... Dec 07 08:17:14 gbvpi-bedroom sudo[9785]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:14 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:14-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:14 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:14-05:00" level=debug msg="app state loaded" Dec 07 08:17:14 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:14 gbvpi-bedroom sudo[9640]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17: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 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17: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 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17: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 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:15-05:00" level=info msg="zeroconf server listening on port 35625" Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Starting Shairport Sync Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Starting Shairport Sync Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Starting Shairport Sync Dec 07 08:17:15 gbvpi-bedroom sudo[9824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:17:15 gbvpi-bedroom sudo[9824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:15 gbvpi-bedroom sudo[9826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:17:15 gbvpi-bedroom sudo[9826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:15-05:00" level=debug msg="obtained new client token: AACNmeKzhRJx8wyS+GiUZ4uOqXNm/Dc6jRj2U7djZ4mYpq8BVqg/fxYGwaTbYeyzYN+t2LGDKoPcs/BD5qBtq9Ypv3+1yZNbxVVZRhZhutsuYe2R/2lkBt+AFxQSDgl0a6YFNi0awmboU8RQOIafNM0gQ+ceHyJain3o+Av6mIGNTUsE2L3gOwLQhj80kvX0Rztj/pplPHgg94df24Yv8D38IAzqAogr4H0kvB7UcW9WcIUrHV4yiPE=" Dec 07 08:17:15 gbvpi-bedroom sudo[9828]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:17:15 gbvpi-bedroom sudo[9828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:15 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:17:15 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:17:15 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:17:15 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.630s CPU time. Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:15-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:15-05:00" level=debug msg="completed challenge" Dec 07 08:17:15 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:15 gbvpi-bedroom sudo[9826]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:15 gbvpi-bedroom go-librespot[9804]: time="2025-12-07T08:17:15-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 07 08:17:15 gbvpi-bedroom sudo[9824]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:15 gbvpi-bedroom sudo[9828]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Shairport-Sync Started Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: Error adding Membership: Error: addMembership EINVAL Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Shairport-Sync Started Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Shairport-Sync Started Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:15 gbvpi-bedroom mpd[9780]: 2025-12-07T08:17:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 08:17:15 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 08:17:15 gbvpi-bedroom sudo[9745]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:15 gbvpi-bedroom sudo[9753]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: Completed starting Core Plugins Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: ----- MyVolumio plugins startup ---- Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: ------------------------------------------- Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: error: MPD error: The expression evaluated to a falsy value: Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: assert.ok(self.idling) Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: error: The expression evaluated to a falsy value: Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: assert.ok(self.idling) Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: info: MPD running with PID9780 Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: ,establishing connection Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: error: updateQueue error: null Dec 07 08:17:15 gbvpi-bedroom volumio[9602]: error: updateQueue error: null Dec 07 08:17:18 gbvpi-bedroom volumio[9602]: info: go-librespot daemon successfully initialized Dec 07 08:17:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 07 08:17:18 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:18 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:18 gbvpi-bedroom go-librespot[9852]: go-librespot daemon starting... Dec 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-05:00" level=debug msg="app state loaded" Dec 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-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 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-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 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-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 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-05:00" level=info msg="zeroconf server listening on port 42913" Dec 07 08:17:18 gbvpi-bedroom sudo[9861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:17:18 gbvpi-bedroom sudo[9861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:18 gbvpi-bedroom sudo[9863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:17:18 gbvpi-bedroom sudo[9863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:18 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 08:17:18 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 08:17:18 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-05:00" level=debug msg="obtained new client token: AACIXUAf4d1ZgIsn2xaKWwSPMSTop/kkA9TlsrKEECexZYAcGA+2Bpf79ZnMKtxG8btvTmKNHonsy0mL/G1VVgcNlX+5jLLzkZVnhPcX1OWIfYqiDqyVNKUhiyRzQA0EZ7DJ6umm+fvRwdcgJeMGpzNfcsPwW2/kmWeYhZH1F/uBaFhQDTxivBtL2Vjdl0RTpOWLc5W10Sg5imcm7LVXmp91e7j/puTMrQuBikoQUhRMIp4Js8kvlQ1/4A==" Dec 07 08:17:18 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 08:17:18 gbvpi-bedroom sudo[9861]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:18 gbvpi-bedroom sudo[9863]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:18 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:18 gbvpi-bedroom volumio[9602]: info: Successfully started MPD Monitor Dec 07 08:17:18 gbvpi-bedroom mpd_monitor.sh[9866]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 08:17:18 gbvpi-bedroom volumio[9602]: info: Successfully started MPD Monitor Dec 07 08:17:19 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:19-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:19 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17:19-05:00" level=debug msg="completed challenge" Dec 07 08:17:19 gbvpi-bedroom go-librespot[9853]: time="2025-12-07T08:17: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 07 08:17:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:20 gbvpi-bedroom volumio[9602]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 08:17:20 gbvpi-bedroom sudo[9885]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 08:17:20 gbvpi-bedroom sudo[9885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:20 gbvpi-bedroom sudo[9885]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:20 gbvpi-bedroom sudo[9887]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 08:17:20 gbvpi-bedroom sudo[9887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:20 gbvpi-bedroom sudo[9887]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:20 gbvpi-bedroom sudo[9891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 08:17:20 gbvpi-bedroom sudo[9891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:20 gbvpi-bedroom sudo[9891]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:20 gbvpi-bedroom volumio[9602]: info: Upmpdcli Daemon Started Dec 07 08:17:21 gbvpi-bedroom volumio[9602]: info: Initializing connection to go-librespot Websocket Dec 07 08:17:21 gbvpi-bedroom volumio[9602]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:17:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 07 08:17:22 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:22 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:22 gbvpi-bedroom go-librespot[9893]: go-librespot daemon starting... Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=debug msg="app state loaded" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-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 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-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 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-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 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=info msg="zeroconf server listening on port 34311" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=debug msg="obtained new client token: AAD1u5K8lWa3N9wcVBGl9KDunjAXbYOIkPGEhks+RmJswmN7A2nx2zcHMKn+K7jLa9EWumqolOzcNM03j6GtF7Y3bWHQbEGvvv62YocN/UY1JYC4HXf/CVoO3jgHVPRnum91CzQ3CON8XN1TvFbOwle1BKUtkoWM5JQ4OvACyln3X2OlrETP5vC2UmqYhN6cuJDXUER6Y/F/Dco7XU6+9i2zgK7Te8mtNsPNZGmQE9lChJWK5H4YvhIfOw==" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-05:00" level=debug msg="completed challenge" Dec 07 08:17:22 gbvpi-bedroom go-librespot[9894]: time="2025-12-07T08:17:22-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 07 08:17:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: MyVolumio login type: Token Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 08:17:24 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Streaming services startup Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Starting Streaming Daemon Dec 07 08:17:25 gbvpi-bedroom sudo[9902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 08:17:25 gbvpi-bedroom sudo[9902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 08:17:25 gbvpi-bedroom sudo[9902]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Initializing connection to go-librespot Websocket Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: error: Cannot start Volumio Streaming Daemon Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 08:17:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 07 08:17:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 08:17:25 gbvpi-bedroom go-librespot[9908]: go-librespot daemon starting... Dec 07 08:17:25 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:25-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 08:17:25 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:25-05:00" level=debug msg="app state loaded" Dec 07 08:17:25 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MyVolumio token set successfully Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MYVOLUMIO: Adding device Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MYVOLUMIO: Evaluating Server Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MyVolumio Plan changed: premium Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Removing audio output: Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MYVOLUMIO: Adding device Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: MYVOLUMIO: Evaluating Server Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Remote config written successfully Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Starting Tunnel 1 Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Starting Tunnel Connection Checker Dec 07 08:17:25 gbvpi-bedroom volumio[9602]: info: Completed starting MyVolumio Plugin Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: MYVolumio Device enabled Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: MyVolumio status changed Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: Streaming services startup Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: Starting Streaming Daemon Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 07 08:17:26 gbvpi-bedroom sudo[9955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 08:17:26 gbvpi-bedroom sudo[9955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 07 08:17:26 gbvpi-bedroom sudo[9955]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 07 08:17:26 gbvpi-bedroom sudo[9959]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 07 08:17:26 gbvpi-bedroom sudo[9959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:26 gbvpi-bedroom sudo[9959]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:26 gbvpi-bedroom volumio[9602]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: MultiRoom plugin initialized Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: STOPPING SNAPCLIENT Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: Snap server stop Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: STOPPING volumioStreaming Dec 07 08:17:27 gbvpi-bedroom sudo[9976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 07 08:17:27 gbvpi-bedroom sudo[9976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom sudo[9978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 07 08:17:27 gbvpi-bedroom sudo[9978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 07 08:17:27 gbvpi-bedroom sudo[9980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 07 08:17:27 gbvpi-bedroom sudo[9980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 07 08:17:27 gbvpi-bedroom sudo[9985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 07 08:17:27 gbvpi-bedroom sudo[9985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom sudo[9985]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 07 08:17:27 gbvpi-bedroom sudo[9976]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 07 08:17:27 gbvpi-bedroom sudo[9980]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:27 gbvpi-bedroom sudo[9978]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Preparing to generate the ALSA configuration file Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Reading ALSA contributions from plugins. Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: Removed streaming files Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: volumioStreaming STOPPED Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: SNAPSERVER STOPPED Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: SNAPCLIENT STOPPED Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: error: Cannot start Volumio Streaming Daemon Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Asound.conf file written Dec 07 08:17:27 gbvpi-bedroom sudo[9989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 08:17:27 gbvpi-bedroom sudo[9989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom sudo[9989]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Output device has changed, restarting MPD Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Output device has changed, restarting Shairport Sync Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:27 gbvpi-bedroom sudo[9995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 08:17:27 gbvpi-bedroom sudo[9995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom sudo[9995]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:27 gbvpi-bedroom sudo[9997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 08:17:27 gbvpi-bedroom sudo[9997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 07 08:17:27 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output for this device Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding audio output: Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding audio output: Dec 07 08:17:27 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 08:17:27 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 08:17:27 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.955s CPU time. Dec 07 08:17:27 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 08:17:27 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 08:17:27 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding METAVOLUMIO REST API Endpoints Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:17:27 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.41621 Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Preparing CD Folders Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding CD REST API Endpoints Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Starting UDEV Watcher for CD Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: Detecting CD presence with UDEV Dec 07 08:17:27 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 07 08:17:27 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.41621 disconnected from D-Bus Dec 07 08:17:27 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 08:17:27 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 08:17:27 gbvpi-bedroom sudo[10015]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 08:17:27 gbvpi-bedroom sudo[10015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 08:17:27 gbvpi-bedroom sudo[10015]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:28 gbvpi-bedroom mpd[10017]: 2025-12-07T08:17:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 08:17:28 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 08:17:28 gbvpi-bedroom sudo[9997]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:30 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 08:17:30 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:30-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 07 08:17:30 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:30-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 07 08:17:30 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:30-05:00" level=info msg="zeroconf server listening on port 46599" Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding inputs REST Endpoints Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Scanning Audio Inputs Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Checking against Known Cards name Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding Server instance for streaming Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: error: Hi Res Audio Failed Login: Missing Login Data Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 07 08:17:32 gbvpi-bedroom sudo[10040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 07 08:17:32 gbvpi-bedroom sudo[10040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding TIDAL REST API Endpoints Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Stopping AccessToken refresher cron for QOBUZ Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 07 08:17:32 gbvpi-bedroom sudo[10047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 07 08:17:32 gbvpi-bedroom sudo[10047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:32 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 07 08:17:32 gbvpi-bedroom sudo[10040]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: AccessToken refresher cron started for QOBUZ Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Adding QOBUZ REST API Endpoints Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Initializing connection to go-librespot Websocket Dec 07 08:17:32 gbvpi-bedroom sudo[10047]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: MRS: Getting audio outputs on start Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: MRS: Requesting all other devices output Dec 07 08:17:32 gbvpi-bedroom sudo[10050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 07 08:17:32 gbvpi-bedroom sudo[10050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: MRS: Pushing audio output on request Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 07 08:17:32 gbvpi-bedroom qobuz-connect[9456]: 20251207 08:17:32.597 [9456.9456] INFO SampleApp: Stopping Local configuration server Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Setting Geolocation for MyVolumio to us4 Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Setting Geolocation for MyVolumio to us4 Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: MPD Permissions set Dec 07 08:17:32 gbvpi-bedroom sudo[10054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 07 08:17:32 gbvpi-bedroom sudo[10054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:32 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:32-05:00" level=debug msg="new websocket client" Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:32 gbvpi-bedroom sudo[10054]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: error: updateQueue error: null Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Connection to go-librespot Websocket established Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioStop Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::stop Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Starting Shairport Sync Dec 07 08:17:32 gbvpi-bedroom sudo[10069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 07 08:17:32 gbvpi-bedroom sudo[10069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:32 gbvpi-bedroom sudo[10071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 08:17:32 gbvpi-bedroom sudo[10071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 08:17:32 gbvpi-bedroom autossh[9429]: received signal to exit (15) Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 07 08:17:32 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 07 08:17:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:17:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.635s CPU time. Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 08:17:32 gbvpi-bedroom sudo[10071]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Shairport-Sync Started Dec 07 08:17:32 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 07 08:17:32 gbvpi-bedroom sudo[10069]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:32 gbvpi-bedroom volumio[9602]: info: Remote SSH Started Dec 07 08:17:32 gbvpi-bedroom autossh[10076]: port set to 0, monitoring disabled Dec 07 08:17:32 gbvpi-bedroom autossh[10076]: starting ssh (count 1) Dec 07 08:17:32 gbvpi-bedroom autossh[10076]: ssh child pid is 10079 Dec 07 08:17:33 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 07 08:17:33 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 08:17:33 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 08:17:33 gbvpi-bedroom sudo[10050]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: Executing endpoint qc_getconfig Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.478 [10094.10094] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.483 [10094.10094] INFO VolumeManager: [0xaff588]: Setting new playback volume: 75 Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.483 [10094.10094] INFO VolumeManager: [0xaff588]: Setting new mute state: 0 Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.483 [10094.10094] INFO QobuzConnect: [0xafff58]: Client initialized! Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.483 [10094.10094] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.493 [10094.10094] INFO LocalConfigManager: [0xafee68]: Starting Local Configuration server Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.493 [10094.10094] INFO SampleApp: Starting Local configuration server Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.493 [10094.10094] INFO SampleApp: Connected to UNIX socket client 0xae9818 Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: Updating MyVolumio device info Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:33 gbvpi-bedroom qobuz-connect[10094]: 20251207 08:17:33.628 [10094.10094] INFO SampleApp: Playback volume changed: 75 Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: Updating MyVolumio device info Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:33 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:34 gbvpi-bedroom volumio[9602]: info: MRS: Adding multiroomSync output Dec 07 08:17:34 gbvpi-bedroom volumio[9602]: info: Adding audio output: Dec 07 08:17:34 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output Dec 07 08:17:34 gbvpi-bedroom volumio[9602]: info: MRS: Updating multiroomSync output Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Listing playlists Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: TidalConnect service stoped! Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 07 08:17:35 gbvpi-bedroom sudo[10109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 07 08:17:35 gbvpi-bedroom sudo[10109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:35 gbvpi-bedroom sudo[10113]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 08:17:35 gbvpi-bedroom sudo[10113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 08:17:35 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 07 08:17:35 gbvpi-bedroom sudo[10109]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Getting Spotify volume Dec 07 08:17:35 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 08:17:35 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 08:17:35 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 08:17:35 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 08:17:35 gbvpi-bedroom sudo[10113]: pam_unix(sudo:session): session closed for user root Dec 07 08:17:35 gbvpi-bedroom mpd_monitor.sh[10117]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Successfully started MPD Monitor Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Executing endpoint tc_getconfig Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 07 08:17:35 gbvpi-bedroom vtcs[10115]: STARTING TidalConnect services, version: 1.5.2.56 Dec 07 08:17:35 gbvpi-bedroom vtcs[10115]: STARTED TidalConnect services. Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Executing endpoint tc_connect Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Connecting to TidalConnect Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::servicePushState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::pushState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioPushState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output update for this device Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::servicePushState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreStateMachine::pushState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioPushState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output update for this device Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: MRS: Pushing multiroomSync output Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumioGetState Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: CorePlayQueue::getTrack 0 Dec 07 08:17:35 gbvpi-bedroom volumio[9602]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 07 08:17:35 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:35-05:00" level=debug msg="obtained new client token: AADs+BNTAMUwDn3RzY7NfhAaEZE+Q6L/Ei8VJTFjUmf2uqMxWhn2d+r8hibLcf0qd8l+kpDjf40N4hpSiPMdJd5Jl8G5mG1r9moDasK5Z3wzXqplOUceBYKt135nmEXuZYFOpFgEbtv7bnPzaaqls0Pp7lwN9axoFwY7quufvo2XJ67Ubv7C2Av7iZNBHUMO6JpBxEzDBiW6a+LsoJFWyD0RtT7hlObG2XZ8suG/LVJVgZGwdf2XtzoIZg==" Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: Successfully Added MyVolumio device Dec 07 08:17:38 gbvpi-bedroom volumiossh-tunnel[10079]: Warning: Permanently added '[eu1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: Successfully Added MyVolumio device Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: TidalConnect service started! Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: [Metrics] CommandRouter: 29s 87.02ms Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::volumiosetStartupVolume Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::Close All Modals sent Dec 07 08:17:38 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::Close All Modals sent Dec 07 08:17:39 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 08:17:39 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 07 08:17:39 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 07 08:17:39 gbvpi-bedroom volumio[9602]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 07 08:17:41 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 08:17:41 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:41-05:00" level=debug msg="completed keyexchange" Dec 07 08:17:41 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:41-05:00" level=debug msg="completed challenge" Dec 07 08:17:41 gbvpi-bedroom go-librespot[9909]: time="2025-12-07T08:17:41-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 07 08:17:41 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 08:17:41 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: Error: socket hang up Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: at connResetException (node:internal/errors:720:14) Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: at Socket.emit (node:events:526:35) Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: code: 'ECONNRESET', Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: response: undefined Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: } Dec 07 08:17:41 gbvpi-bedroom volumio[9602]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 08:17:41 gbvpi-bedroom sudo[10166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 08:16' Dec 07 08:17:41 gbvpi-bedroom sudo[10166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"