Dec 06 01:34:00 gbvpi-bedroom go-librespot[21217]: time="2025-12-06T01:34:00-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:00 gbvpi-bedroom go-librespot[21217]: time="2025-12-06T01:34:00-05:00" level=debug msg="completed challenge" Dec 06 01:34:00 gbvpi-bedroom go-librespot[21217]: time="2025-12-06T01:34:00-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 06 01:34:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: Error: socket hang up Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: at connResetException (node:internal/errors:720:14) Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: at Socket.emit (node:events:526:35) Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: code: 'ECONNRESET', Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: response: undefined Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: } Dec 06 01:34:00 gbvpi-bedroom volumio[20239]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 01:34:00 gbvpi-bedroom sudo[21254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 01:33' Dec 06 01:34:00 gbvpi-bedroom sudo[21254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:00 gbvpi-bedroom sudo[21254]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:01 gbvpi-bedroom vtcs[20796]: [2025-12-06 01:34:01.026] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 06 01:34:01 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 06 01:34:01 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 06 01:34:01 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:01 gbvpi-bedroom qobuz-connect[20766]: 20251206 01:34:01.028 [20766.20766] INFO SampleApp: Socket closed Dec 06 01:34:01 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: volumio.service: Consumed 22.055s CPU time. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 942. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: volumio.service: Consumed 22.055s CPU time. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 06 01:34:01 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ----- Volumio3 ---- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ----- System startup ---- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: MYVOLUMIO Environment detected Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Plugin folders cleanup Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning into folder /volumio/app/plugins/ Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category audio_interface Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category miscellanea Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category music_service Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category plugins.json Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category system_controller Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category user_interface Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning into folder /data/plugins/ Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Scanning category music_service Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Plugin folders cleanup completed Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ----- Core plugins startup ---- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Loading plugins from folder /volumio/app/plugins/ Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Adding plugin upnp to MyMusic Plugins Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Loading plugins from folder /data/plugins/ Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Loading plugin "system"... Dec 06 01:34:02 gbvpi-bedroom volumio[21272]: info: Loading plugin "appearance"... Dec 06 01:34:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 179. Dec 06 01:34:03 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:03 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:03 gbvpi-bedroom go-librespot[21300]: go-librespot daemon starting... Dec 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-05:00" level=debug msg="app state loaded" Dec 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "network"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Refreshing Cached IP Addresses Dec 06 01:34:03 gbvpi-bedroom sudo[21309]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 01:34:03 gbvpi-bedroom sudo[21309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:03 gbvpi-bedroom sudo[21311]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 01:34:03 gbvpi-bedroom sudo[21311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:03 gbvpi-bedroom sudo[21309]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "services"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "alsa_controller"... Dec 06 01:34:03 gbvpi-bedroom sudo[21311]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:03 gbvpi-bedroom sudo[21316]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 06 01:34:03 gbvpi-bedroom sudo[21316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "wizard"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "networkfs"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Starting Udev Watcher for removable devices Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Ignoring mount for partition: boot Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Ignoring mount for partition: volumio Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Ignoring mount for partition: volumio_data Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "volumio_command_line_client"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "upnp"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: [1765002843634] Starting Upmpd Daemon Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "my_music"... Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "mpd"... Dec 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-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 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-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 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-05:00" level=info msg="zeroconf server listening on port 42939" Dec 06 01:34:03 gbvpi-bedroom volumio[21272]: info: Loading plugin "upnp_browser"... Dec 06 01:34:03 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:03-05:00" level=debug msg="obtained new client token: AABRDiyTtSGi6L9fQSSKgw2WQSXJThPY7H4/o72Cq5r/SGkSUoVZ5cxiSU5OyYqrbYnN58uZDNhB7hRP2HBcYy6zTQL078NGFJuC50HkkmIpBUw8n/kwIkZ1xdhzlDSOny6vliGJFpic+8uQzzKEcNQCpx/ZH4drkwbQum7Qz2Rzdt6Ywg009iAaxtTcycVL67HQ0SHAGI5BoNeRfcjO2P01HYYzKk8DTaHB8/5ReZNj+IpHHSoc0r18/A==" Dec 06 01:34:04 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:04 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:04-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:04 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34:04-05:00" level=debug msg="completed challenge" Dec 06 01:34:04 gbvpi-bedroom go-librespot[21301]: time="2025-12-06T01:34: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 06 01:34:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "alarm-clock"... Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "airplay_emulation"... Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Starting Shairport Sync Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "last_100"... Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "webradio"... Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "i2s_dacs"... Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: I2S DAC not set, start Auto-detection Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "volumiodiscovery"... Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: *** WARNING *** For more information see Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: *** WARNING *** For more information see Dec 06 01:34:04 gbvpi-bedroom node[21272]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:04 gbvpi-bedroom node[21272]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:04 gbvpi-bedroom node[21272]: *** WARNING *** For more information see Dec 06 01:34:04 gbvpi-bedroom node[21272]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:04 gbvpi-bedroom node[21272]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:04 gbvpi-bedroom node[21272]: *** WARNING *** For more information see Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:04 gbvpi-bedroom volumio[21272]: info: Loading plugin "jellyfin"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "spop"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "outputs"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "albumart"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Plugin example_plugin is not enabled Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "inputs"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "updater_comm"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Plugin mpdemulation is not enabled Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "rest_api"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading plugin "websocket"... Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Starting Socket.io Server version 1.7.4 Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Loading i18n strings for locale en Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: Updating browse sources language Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::initPlayerControls Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: Express server listening on port 3000 Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: [Metrics] WebUI: 3s 698.53ms Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::resetVolumioState Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::getcurrentVolume Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Volumio Network Manager: Network status updated: 2 Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: VolumeController:: Volume=91 Mute =false Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::pushState Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:05 gbvpi-bedroom volumio[21344]: Forking 3 albumart workers Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::updateTrackBlock Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrackBlock Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 01:34:05 gbvpi-bedroom volumio[21272]: info: Reloading queue from file Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::setRepeat null single undefined Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::pushState Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::setRandom null Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::pushState Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:06 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:06] [connect] Successful connection Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Setting Device type: Raspberry PI Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: VolumeController:: Volume=91 Mute =false Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreStateMachine::pushState Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:06 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765002846 101 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: 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 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Completed loading Core Plugins Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Preparing to generate the ALSA configuration file Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Asound.conf file written Dec 06 01:34:06 gbvpi-bedroom sudo[21403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 06 01:34:06 gbvpi-bedroom sudo[21403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:06 gbvpi-bedroom sudo[21403]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Output device has changed, restarting MPD Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Output device has changed, restarting Shairport Sync Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:06 gbvpi-bedroom sudo[21409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 01:34:06 gbvpi-bedroom sudo[21412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 01:34:06 gbvpi-bedroom sudo[21412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:06 gbvpi-bedroom sudo[21409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:06 gbvpi-bedroom sudo[21409]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: ___________ START PLUGINS ___________ Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: ControllerMpd::onStart: Initializing MPD Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Creating MPD Configuration file Dec 06 01:34:06 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: [1765002846334] CoreMusicLibrary::Adding element Media Servers Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:06 gbvpi-bedroom sudo[21421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 01:34:06 gbvpi-bedroom sudo[21421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:06 gbvpi-bedroom sudo[21419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 01:34:06 gbvpi-bedroom sudo[21419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:06 gbvpi-bedroom sudo[21419]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:06 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:06 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 01:34:06 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.314s CPU time. Dec 06 01:34:06 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 06 01:34:06 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 01:34:06 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: [1765002846432] CoreMusicLibrary::Adding element Last_100 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: [1765002846438] CoreMusicLibrary::Adding element Webradio Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Initializing BBC Radios Dec 06 01:34:06 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 01:34:06 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Discovery: Getting this device information Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 06 01:34:06 gbvpi-bedroom sudo[21435]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 01:34:06 gbvpi-bedroom sudo[21435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 01:34:06 gbvpi-bedroom sudo[21435]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: [1765002846620] CoreMusicLibrary::Adding element Jellyfin Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: Cannot find translation for source Jellyfin Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: 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 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Creating Spotify config file Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:06 gbvpi-bedroom volumio[21365]: Starting albumart workers Dec 06 01:34:06 gbvpi-bedroom volumio[21272]: info: Volumio Calling Home Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Discovery: Found device GBVPi-Bedroom Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Discovery: Found device GBVPi-Bedroom Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:07 gbvpi-bedroom volumio[21367]: Starting albumart workers Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: MPD Permissions set Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: MPD Permissions set Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: 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 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Spotify config file written Dec 06 01:34:07 gbvpi-bedroom sudo[21453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 06 01:34:07 gbvpi-bedroom sudo[21453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:07 gbvpi-bedroom go-librespot[21461]: go-librespot daemon starting... Dec 06 01:34:07 gbvpi-bedroom sudo[21453]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21363]: Starting albumart workers Dec 06 01:34:07 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:07-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:07 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:07-05:00" level=debug msg="app state loaded" Dec 06 01:34:07 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: No need to fix Spotify hosts Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Volumio called home Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Starting Shairport Sync Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Starting Shairport Sync Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Starting Shairport Sync Dec 06 01:34:07 gbvpi-bedroom sudo[21480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:07 gbvpi-bedroom sudo[21480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:07 gbvpi-bedroom sudo[21481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:07 gbvpi-bedroom sudo[21481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:07 gbvpi-bedroom sudo[21483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 01:34:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 01:34:07 gbvpi-bedroom sudo[21483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.903s CPU time. Dec 06 01:34:07 gbvpi-bedroom sudo[21316]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 01:34:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:07 gbvpi-bedroom sudo[21481]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:07 gbvpi-bedroom sudo[21480]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 01:34:07 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:07 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:07 gbvpi-bedroom sudo[21483]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Shairport-Sync Started Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: Error adding Membership: Error: addMembership EINVAL Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Shairport-Sync Started Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: Shairport-Sync Started Dec 06 01:34:07 gbvpi-bedroom volumio[21272]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-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 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-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 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-05:00" level=info msg="zeroconf server listening on port 36979" Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-05:00" level=debug msg="obtained new client token: AACrVFdjjbLydQjEsZ/AVTKXdEpfxSOk10aAHeMTzOInBsGdAxBnZl35BvJSDuV53eW2FQ2ORattUB7JbEsGgGJAZbZmGGEqDTi5+mdRE7zziWn4yZp/2wYp3HxbBDlfvh8JorZxwtbEneYiPKfkpGmHgBavtyr5ix8HBcVagWYSB2foheRdt2MYKAJOUnDwHEd7gNGYqF+ON9A+IUx986lpA//BUP93pfcMNjoaFWFq7a4DiXZkQOg=" Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34:08-05:00" level=debug msg="completed challenge" Dec 06 01:34:08 gbvpi-bedroom go-librespot[21464]: time="2025-12-06T01:34: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 06 01:34:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:08 gbvpi-bedroom mpd[21448]: 2025-12-06T01:34:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 06 01:34:08 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 06 01:34:08 gbvpi-bedroom sudo[21412]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:08 gbvpi-bedroom sudo[21421]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: info: Completed starting Core Plugins Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: info: ----- MyVolumio plugins startup ---- Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: info: ------------------------------------------- Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: error: MPD error: The expression evaluated to a falsy value: Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: assert.ok(self.idling) Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: error: The expression evaluated to a falsy value: Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: assert.ok(self.idling) Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: info: MPD running with PID21448 Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: ,establishing connection Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: error: updateQueue error: null Dec 06 01:34:08 gbvpi-bedroom volumio[21272]: error: updateQueue error: null Dec 06 01:34:09 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:09 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:09 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:09 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:09 gbvpi-bedroom volumio[21272]: info: Listing playlists Dec 06 01:34:09 gbvpi-bedroom volumio[21272]: info: Listing playlists Dec 06 01:34:10 gbvpi-bedroom volumio[21272]: info: Listing playlists Dec 06 01:34:10 gbvpi-bedroom volumio[21272]: info: Listing playlists Dec 06 01:34:10 gbvpi-bedroom volumio[21272]: info: go-librespot daemon successfully initialized Dec 06 01:34:10 gbvpi-bedroom volumio[21272]: info: Discovery: Browse raised the following error Error: dns service error: unknown Dec 06 01:34:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 180. Dec 06 01:34:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:11 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:11 gbvpi-bedroom go-librespot[21522]: go-librespot daemon starting... Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=debug msg="app state loaded" Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-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 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-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 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-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 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=info msg="zeroconf server listening on port 41877" Dec 06 01:34:11 gbvpi-bedroom sudo[21532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 01:34:11 gbvpi-bedroom sudo[21532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:11 gbvpi-bedroom sudo[21534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 01:34:11 gbvpi-bedroom sudo[21534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:11 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 06 01:34:11 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 06 01:34:11 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=debug msg="obtained new client token: AAD3yxJ3SMSrNUodY2HEJ27trZl6rBu1+g5bZ+pVuPIGLtPILecpn+20S99caKPqoQBVhC/B0FXbPKSAKKHmIEQ+qVfFvtq53hkvzrL9puI+DBs79tCZzqoTUjQw+pjTK3i50LqOngCypckhRUpP/Zeg1TbnG+VZoP/pPd/mxvxsrOH+ClA4P3LNfeKwEIvgFviljxE7bSA8+3kczynKlHGlLWPbKs5hipGTUfrP1W6bg6a9h1b6/BPxUQ==" Dec 06 01:34:11 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 06 01:34:11 gbvpi-bedroom sudo[21532]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:11 gbvpi-bedroom volumio[21272]: info: Successfully started MPD Monitor Dec 06 01:34:11 gbvpi-bedroom sudo[21534]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:11 gbvpi-bedroom mpd_monitor.sh[21537]: MPD Monitor Service: Starting MPD Monitor Service Dec 06 01:34:11 gbvpi-bedroom volumio[21272]: info: Successfully started MPD Monitor Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-05:00" level=debug msg="completed challenge" Dec 06 01:34:11 gbvpi-bedroom go-librespot[21523]: time="2025-12-06T01:34:11-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 06 01:34:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:13 gbvpi-bedroom volumio[21272]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:13 gbvpi-bedroom volumio[21272]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:13 gbvpi-bedroom volumio[21272]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 06 01:34:13 gbvpi-bedroom sudo[21556]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 01:34:13 gbvpi-bedroom sudo[21556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:13 gbvpi-bedroom sudo[21556]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:13 gbvpi-bedroom sudo[21558]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 01:34:13 gbvpi-bedroom sudo[21558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:13 gbvpi-bedroom sudo[21558]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:13 gbvpi-bedroom sudo[21561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 06 01:34:13 gbvpi-bedroom sudo[21561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:13 gbvpi-bedroom sudo[21561]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:13 gbvpi-bedroom volumio[21272]: info: Upmpdcli Daemon Started Dec 06 01:34:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 181. Dec 06 01:34:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:15 gbvpi-bedroom go-librespot[21564]: go-librespot daemon starting... Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-05:00" level=debug msg="app state loaded" Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34: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-gew1.spotify.com:80]" Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-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 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-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 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-05:00" level=info msg="zeroconf server listening on port 35745" Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-05:00" level=debug msg="obtained new client token: AADRZXl8FDmcJTITNzmKBdYaDZ76Hr6YW/PmSN0hCjKT4M0BDSIP978hNNkd7d+wEwKWWRuiJSabKlcWxC09jBfG/TUmRnbAdXFVVasazy0Ih5YycOHKN0aiEHdZpV6dh8ZNobgs0Y7gSDwdJL5sT9cAquNg3RPdo0sGevX78OVhAH4bGSN8Sfo06h5VmrVjN7ZKL1gGUUX90yrGvYgRx9AI8A5ap3zQDzZ2Y4qY82q0A5RXdz3U/Fdpfw==" Dec 06 01:34:15 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:16 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:16-05:00" level=debug msg="new websocket client" Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Connection to go-librespot Websocket established Dec 06 01:34:16 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:16-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:16 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:16-05:00" level=debug msg="completed challenge" Dec 06 01:34:16 gbvpi-bedroom go-librespot[21565]: time="2025-12-06T01:34:16-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Connection to go-librespot Websocket closed Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin bluetooth to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin multiroom to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin metavolumio to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin cd_controller to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 06 01:34:16 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: Starting MyVolumio Remote Streaming Endpoints Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: MyVolumio login type: Token Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: Streaming services startup Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: Starting Streaming Daemon Dec 06 01:34:17 gbvpi-bedroom sudo[21573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 06 01:34:17 gbvpi-bedroom sudo[21573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 06 01:34:17 gbvpi-bedroom sudo[21573]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: error: Cannot start Volumio Streaming Daemon Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 06 01:34:17 gbvpi-bedroom volumio[21272]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MyVolumio token set successfully Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MYVOLUMIO: Adding device Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MYVOLUMIO: Evaluating Server Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MyVolumio Plan changed: premium Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Removing browser output: myVolumio user plan is not superstar Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Removing audio output: Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MYVOLUMIO: Adding device Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MYVOLUMIO: Evaluating Server Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Remote config written successfully Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Starting Tunnel 1 Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Starting Tunnel Connection Checker Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Completed starting MyVolumio Plugin Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MYVolumio Device enabled Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: MyVolumio status changed Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Streaming services startup Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: Starting Streaming Daemon Dec 06 01:34:18 gbvpi-bedroom sudo[21619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 06 01:34:18 gbvpi-bedroom sudo[21619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 06 01:34:18 gbvpi-bedroom sudo[21619]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 06 01:34:18 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 06 01:34:19 gbvpi-bedroom sudo[21623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 06 01:34:19 gbvpi-bedroom sudo[21623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:19 gbvpi-bedroom sudo[21623]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: MultiRoom plugin initialized Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: STOPPING SNAPCLIENT Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: Snap server stop Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: STOPPING volumioStreaming Dec 06 01:34:19 gbvpi-bedroom sudo[21640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 06 01:34:19 gbvpi-bedroom sudo[21640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:19 gbvpi-bedroom sudo[21642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 06 01:34:19 gbvpi-bedroom sudo[21642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 06 01:34:19 gbvpi-bedroom sudo[21644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 06 01:34:19 gbvpi-bedroom sudo[21644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:19 gbvpi-bedroom sudo[21648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 06 01:34:19 gbvpi-bedroom sudo[21648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 06 01:34:19 gbvpi-bedroom sudo[21648]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 06 01:34:19 gbvpi-bedroom sudo[21640]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 06 01:34:19 gbvpi-bedroom sudo[21642]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:19 gbvpi-bedroom sudo[21644]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 06 01:34:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 182. Dec 06 01:34:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: Preparing to generate the ALSA configuration file Dec 06 01:34:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:19 gbvpi-bedroom go-librespot[21651]: go-librespot daemon starting... Dec 06 01:34:19 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:19 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:19-05:00" level=debug msg="app state loaded" Dec 06 01:34:19 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: Getting Spotify volume Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: Reading ALSA contributions from plugins. Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: Setting Geolocation for MyVolumio to us4 Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: Setting Geolocation for MyVolumio to us4 Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: Removed streaming files Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: volumioStreaming STOPPED Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: SNAPSERVER STOPPED Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: info: MRS: SNAPCLIENT STOPPED Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: error: Cannot start Volumio Streaming Daemon Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 06 01:34:19 gbvpi-bedroom volumio[21272]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 06 01:34:19 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:19-05:00" level=debug msg="new websocket client" Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Connection to go-librespot Websocket established Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: 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 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=info msg="zeroconf server listening on port 34215" Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Asound.conf file written Dec 06 01:34:20 gbvpi-bedroom sudo[21661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 06 01:34:20 gbvpi-bedroom sudo[21661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:20 gbvpi-bedroom sudo[21661]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Output device has changed, restarting MPD Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Output device has changed, restarting Shairport Sync Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:20 gbvpi-bedroom sudo[21667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 01:34:20 gbvpi-bedroom sudo[21667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:20 gbvpi-bedroom sudo[21667]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:20 gbvpi-bedroom sudo[21669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 01:34:20 gbvpi-bedroom sudo[21669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="obtained new client token: AACk+ozt8QtMHGOBfhVqB4zobIjSBsexAqp8QTpzgOGTsFglrbT4HFqRRN5AKJ8RhZs8AxHY1F9uzxKlX20vRLswHK76kc6ULpr84F17qRkjM9uTU4E9qBD+WebsJNtMNl1mB7EJQtmjtsmZtx4IDX1qJfesw0w0i9Myk5FF6DcT7CCcuNfHb2NKx2AhJLW0pDQpNNw6aRW3Pu+wSOz5LbHOH1JftZcObjMkczh7lzSPHtXJ+8l1zwA=" Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 06 01:34:20 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: MRS: Pushing multiroomSync output for this device Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: MRS: Pushing multiroomSync output Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding audio output: Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding audio output: Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:20 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 06 01:34:20 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 01:34:20 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.945s CPU time. Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:20 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 06 01:34:20 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 01:34:20 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 01:34:20 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.15034 Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding METAVOLUMIO REST API Endpoints Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Preparing CD Folders Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding CD REST API Endpoints Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Starting UDEV Watcher for CD Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: Detecting CD presence with UDEV Dec 06 01:34:20 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 06 01:34:20 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.15034 disconnected from D-Bus Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=debug msg="completed challenge" Dec 06 01:34:20 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 01:34:20 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 01:34:20 gbvpi-bedroom go-librespot[21652]: time="2025-12-06T01:34:20-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:20 gbvpi-bedroom sudo[21686]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 01:34:20 gbvpi-bedroom sudo[21686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 01:34:20 gbvpi-bedroom sudo[21686]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:21 gbvpi-bedroom mpd[21689]: 2025-12-06T01:34:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 06 01:34:21 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 06 01:34:21 gbvpi-bedroom sudo[21669]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 183. Dec 06 01:34:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:23 gbvpi-bedroom go-librespot[21692]: go-librespot daemon starting... Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=debug msg="app state loaded" Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-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 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-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 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=info msg="zeroconf server listening on port 44023" Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=debug msg="obtained new client token: AAAR6/OK5aCxIVdMeaAHRgSDWiTcKsz2vSTfXijgmCy1ga4TwVCslU7hmNwuoJICYp+mR87uqwK3tkHsqDJMdpdDk0G3wsFyKplQZLJDkDKHY54BvRvAf40wq2Ha5mrKyLnJO/o3j62RqMp09ajHAf+lptavO/SjQ+lkuN/NBYBZgLrClGFU3hI4kTtKKqh8sa/Q8MTBKo3VKnhw0LHHJmN6C3JCwEMQOSVtVOo9sUvoYmC0KR/gUVNZaQ==" Dec 06 01:34:23 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:24 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:24-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:24 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34:24-05:00" level=debug msg="completed challenge" Dec 06 01:34:24 gbvpi-bedroom go-librespot[21707]: time="2025-12-06T01:34: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 06 01:34:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding inputs REST Endpoints Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Scanning Audio Inputs Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Checking against Known Cards name Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding Server instance for streaming Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: error: Hi Res Audio Failed Login: Missing Login Data Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 06 01:34:25 gbvpi-bedroom sudo[21718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 06 01:34:25 gbvpi-bedroom sudo[21718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:25 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 06 01:34:25 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 20815 (vtcs) with signal SIGKILL. Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding TIDAL REST API Endpoints Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Stopping AccessToken refresher cron for QOBUZ Dec 06 01:34:25 gbvpi-bedroom sudo[21725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 06 01:34:25 gbvpi-bedroom sudo[21725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:25 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 06 01:34:25 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 06 01:34:25 gbvpi-bedroom sudo[21718]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:25 gbvpi-bedroom sudo[21725]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: AccessToken refresher cron started for QOBUZ Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Adding QOBUZ REST API Endpoints Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Updating MyVolumio device info Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:25 gbvpi-bedroom sudo[21728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 06 01:34:25 gbvpi-bedroom sudo[21728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Updating MyVolumio device info Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: MRS: Getting audio outputs on start Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: MRS: Requesting all other devices output Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Getting Spotify volume Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Successfully Added MyVolumio device Dec 06 01:34:25 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 06 01:34:25 gbvpi-bedroom qobuz-connect[20766]: 20251206 01:34:25.485 [20766.20766] INFO SampleApp: Stopping Local configuration server Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: info: Successfully Added MyVolumio device Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: Error: socket hang up Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: at connResetException (node:internal/errors:720:14) Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: at Socket.emit (node:events:526:35) Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: code: 'ECONNRESET', Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: response: undefined Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: } Dec 06 01:34:25 gbvpi-bedroom volumio[21272]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 01:34:25 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 06 01:34:25 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:25 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:25 gbvpi-bedroom sudo[21728]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:25 gbvpi-bedroom sudo[21746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 01:33' Dec 06 01:34:25 gbvpi-bedroom sudo[21746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:26 gbvpi-bedroom sudo[21746]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:26 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 06 01:34:26 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: Error: Application ID was not specified! Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -m|--manufacturer: Manufacturer of the device Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -n|--deviceName: Device name Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -l|--model: Device's model name Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -s|--serialNumber: Device's serial number Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -o|--outputDevice: ALSA PCM device to play audio to Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -p|--port: Port to run the local configuration HTTP server on Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 06 01:34:26 gbvpi-bedroom qobuz-connect[21743]: -h|--help: Print this help Dec 06 01:34:26 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:26 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:26 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: volumio.service: Consumed 18.795s CPU time. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 943. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: volumio.service: Consumed 18.795s CPU time. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 06 01:34:26 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ----- Volumio3 ---- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ----- System startup ---- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 184. Dec 06 01:34:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:27 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:27 gbvpi-bedroom go-librespot[21789]: go-librespot daemon starting... Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=debug msg="app state loaded" Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-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 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-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 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=info msg="zeroconf server listening on port 44287" Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: MYVOLUMIO Environment detected Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=debug msg="obtained new client token: AAAKv1HBGC+erUHKndVX8HW7+UBE76ZPh4rifzh4dotDNNcmwfJYLV8eoIYA7N2/j7WhHa4sewZ7Uj9aWITeZdcmbaKTkTt9zXQ8z0OLDUKC0S16xuu8uZ05Ap2VSt6KWwa+QhqOBDubhZuQzC27GuJskrilVHsAndpwzs0wA0GrL/WjLLp9m3IC7Nw7tJhRFpvloajHjU9h4P/XWLuEGpv9SYvneYLxs89vTTjarMjLVSuicWEmBLElkA==" Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Plugin folders cleanup Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning into folder /volumio/app/plugins/ Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category audio_interface Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category miscellanea Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category music_service Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category plugins.json Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category system_controller Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category user_interface Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning into folder /data/plugins/ Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Scanning category music_service Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Plugin folders cleanup completed Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ----- Core plugins startup ---- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Loading plugins from folder /volumio/app/plugins/ Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Adding plugin upnp to MyMusic Plugins Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 06 01:34:27 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Loading plugins from folder /data/plugins/ Dec 06 01:34:27 gbvpi-bedroom volumio[21768]: info: Loading plugin "system"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "appearance"... Dec 06 01:34:28 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:28-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:28 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:28-05:00" level=debug msg="completed challenge" Dec 06 01:34:28 gbvpi-bedroom go-librespot[21790]: time="2025-12-06T01:34:28-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "network"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Refreshing Cached IP Addresses Dec 06 01:34:28 gbvpi-bedroom sudo[21804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 01:34:28 gbvpi-bedroom sudo[21804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:28 gbvpi-bedroom sudo[21806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 01:34:28 gbvpi-bedroom sudo[21806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:28 gbvpi-bedroom sudo[21804]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "services"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "alsa_controller"... Dec 06 01:34:28 gbvpi-bedroom sudo[21806]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:28 gbvpi-bedroom sudo[21816]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 06 01:34:28 gbvpi-bedroom sudo[21816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "wizard"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "networkfs"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Starting Udev Watcher for removable devices Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Ignoring mount for partition: boot Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Ignoring mount for partition: volumio Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Ignoring mount for partition: volumio_data Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "volumio_command_line_client"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "upnp"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: [1765002868703] Starting Upmpd Daemon Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "my_music"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "mpd"... Dec 06 01:34:28 gbvpi-bedroom volumio[21768]: info: Loading plugin "upnp_browser"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "alarm-clock"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "airplay_emulation"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Starting Shairport Sync Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "last_100"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "webradio"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "i2s_dacs"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: I2S DAC not set, start Auto-detection Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "volumiodiscovery"... Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: *** WARNING *** For more information see Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:29 gbvpi-bedroom node[21768]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: *** WARNING *** For more information see Dec 06 01:34:29 gbvpi-bedroom node[21768]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:29 gbvpi-bedroom node[21768]: *** WARNING *** For more information see Dec 06 01:34:29 gbvpi-bedroom node[21768]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 06 01:34:29 gbvpi-bedroom node[21768]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 06 01:34:29 gbvpi-bedroom node[21768]: *** WARNING *** For more information see Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:29 gbvpi-bedroom volumio[21768]: info: Loading plugin "jellyfin"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "spop"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "outputs"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "albumart"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Plugin example_plugin is not enabled Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "inputs"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "updater_comm"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Plugin mpdemulation is not enabled Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "rest_api"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading plugin "websocket"... Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Starting Socket.io Server version 1.7.4 Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Loading i18n strings for locale en Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: Updating browse sources language Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::initPlayerControls Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: Express server listening on port 3000 Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: [Metrics] WebUI: 3s 706.05ms Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::resetVolumioState Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::getcurrentVolume Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:30 gbvpi-bedroom volumio[21768]: info: Volumio Network Manager: Network status updated: 2 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom volumio[21839]: Forking 3 albumart workers Dec 06 01:34:31 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:31] [connect] Successful connection Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: VolumeController:: Volume=91 Mute =false Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::pushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::updateTrackBlock Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrackBlock Dec 06 01:34:31 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 1. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioRetrievevolume Dec 06 01:34:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 185. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Reloading queue from file Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::setRepeat null single undefined Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::pushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::setRandom null Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::pushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Setting Device type: Raspberry PI Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 06 01:34:31 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 01:34:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765002871 101 Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:31 gbvpi-bedroom go-librespot[21884]: go-librespot daemon starting... Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: 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 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=debug msg="app state loaded" Dec 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: VolumeController:: Volume=91 Mute =false Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::pushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: No valid Plugin REST Endpoint Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: 20251206 01:34:31.328 [21893.21893] ERROR SampleApp: api request was not successful Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: Error: Application ID was not specified! Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -m|--manufacturer: Manufacturer of the device Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -n|--deviceName: Device name Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -l|--model: Device's model name Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -s|--serialNumber: Device's serial number Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -o|--outputDevice: ALSA PCM device to play audio to Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -p|--port: Port to run the local configuration HTTP server on Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 06 01:34:31 gbvpi-bedroom qobuz-connect[21893]: -h|--help: Print this help Dec 06 01:34:31 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:31 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Completed loading Core Plugins Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Preparing to generate the ALSA configuration file Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Asound.conf file written Dec 06 01:34:31 gbvpi-bedroom sudo[21906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 06 01:34:31 gbvpi-bedroom sudo[21906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:31 gbvpi-bedroom sudo[21906]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Output device has changed, restarting MPD Dec 06 01:34:31 gbvpi-bedroom sudo[21912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 01:34:31 gbvpi-bedroom sudo[21912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:31 gbvpi-bedroom sudo[21912]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Output device has changed, restarting Shairport Sync Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:31 gbvpi-bedroom sudo[21917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 01:34:31 gbvpi-bedroom sudo[21917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: ___________ START PLUGINS ___________ Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: ControllerMpd::onStart: Initializing MPD Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Creating MPD Configuration file Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 06 01:34:31 gbvpi-bedroom sudo[21925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 01:34:31 gbvpi-bedroom sudo[21925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 06 01:34:31 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:31-05:00" level=info msg="zeroconf server listening on port 39039" Dec 06 01:34:31 gbvpi-bedroom sudo[21925]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: [1765002871682] CoreMusicLibrary::Adding element Media Servers Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.276s CPU time. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 01:34:31 gbvpi-bedroom sudo[21928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 01:34:31 gbvpi-bedroom sudo[21928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: [1765002871781] CoreMusicLibrary::Adding element Last_100 Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: [1765002871786] CoreMusicLibrary::Adding element Webradio Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Initializing BBC Radios Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 01:34:31 gbvpi-bedroom mpd_monitor.sh[21936]: MPD error: Connection reset by peer Dec 06 01:34:31 gbvpi-bedroom mpd_monitor.sh[21537]: MPD Monitor Service: MPD Appears to be inactive, restarting Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 01:34:31 gbvpi-bedroom mpd_monitor.sh[21945]: mpd: no process found Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Discovery: Getting this device information Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:31 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: [1765002871928] CoreMusicLibrary::Adding element Jellyfin Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: Cannot find translation for source Jellyfin Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: 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 06 01:34:31 gbvpi-bedroom volumio[21768]: info: Creating Spotify config file Dec 06 01:34:31 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21858]: Starting albumart workers Dec 06 01:34:32 gbvpi-bedroom sudo[21960]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 01:34:32 gbvpi-bedroom sudo[21960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 01:34:32 gbvpi-bedroom sudo[21960]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:32 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:32-05:00" level=debug msg="obtained new client token: AADHxHfC15K8SU1JpCvjdR2LORpERAE6rJ4CIYn0rRPScDLAtnPDvhbLPta54FFwZPfKdMeBC5YuuZ+tSKLadQVuW4VT1VYy81eZiTWVYIxul3mHx3VyJ6nuLZ6jD/P7fB7Ywe6cHvMCTLcn2sF0JgT2eliS4ZVqWh222TdiGNfL6tjUuFvS7v6bFXOc0iFb79DjVyDKeF7ypnbK925v8ACzka1gPDYwyyfv/fGf4whlPupkhawX4LTQkw==" Dec 06 01:34:32 gbvpi-bedroom volumio[21857]: Starting albumart workers Dec 06 01:34:32 gbvpi-bedroom volumio[21855]: Starting albumart workers Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Volumio Calling Home Dec 06 01:34:32 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:32 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:32-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:32 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34:32-05:00" level=debug msg="completed challenge" Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Discovery: Found device GBVPi-Bedroom Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Discovery: Found device GBVPi-Bedroom Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: MPD Permissions set Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: MPD Permissions set Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Spotify config file written Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: 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 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom sudo[21973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 06 01:34:32 gbvpi-bedroom sudo[21973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:32 gbvpi-bedroom go-librespot[21892]: time="2025-12-06T01:34: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 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom sudo[21816]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: No need to fix Spotify hosts Dec 06 01:34:32 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:32 gbvpi-bedroom sudo[21973]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:32 gbvpi-bedroom go-librespot[21981]: go-librespot daemon starting... Dec 06 01:34:32 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:32-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:32 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:32-05:00" level=debug msg="app state loaded" Dec 06 01:34:32 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Volumio called home Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Starting Shairport Sync Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Starting Shairport Sync Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: Starting Shairport Sync Dec 06 01:34:32 gbvpi-bedroom sudo[22000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:32 gbvpi-bedroom sudo[22000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:32 gbvpi-bedroom volumio[21768]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 06 01:34:32 gbvpi-bedroom sudo[22003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:32 gbvpi-bedroom sudo[22003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:32 gbvpi-bedroom sudo[22001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:32 gbvpi-bedroom sudo[22001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:33 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 01:34:33 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 01:34:33 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:33 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.644s CPU time. Dec 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-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 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-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 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-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 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-05:00" level=info msg="zeroconf server listening on port 37207" Dec 06 01:34:33 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:33 gbvpi-bedroom sudo[22003]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:33 gbvpi-bedroom sudo[22000]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:33 gbvpi-bedroom sudo[22001]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-05:00" level=debug msg="obtained new client token: AADOFt+MohmUMvTjavgeBhj7BPfnf9XFaOxB2xbdsRZY2qNtWZ0VrPmRRpoJrCkfmLrUmFUqhG1dRm/AI3/e6IV3U0k2w/sq+eYnWu1VOgoEaaiJQdoP1IW7Zg9omHVyRj1pHmSYJIlkGgm+OSBfossK0u4cRbpYn57HpkLleNZk3Jry4mXwrhjw/hyzwJPSum8dRjI+b5L9gQuWzmlW/vvliabAwN0TknIKZcgzIZz3dioDRhtMEFU=" Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: Shairport-Sync Started Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: Error adding Membership: Error: addMembership EINVAL Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: Shairport-Sync Started Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: Shairport-Sync Started Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-05:00" level=debug msg="completed challenge" Dec 06 01:34:33 gbvpi-bedroom go-librespot[21992]: time="2025-12-06T01:34:33-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:33 gbvpi-bedroom mpd[21962]: 2025-12-06T01:34:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 06 01:34:33 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 06 01:34:33 gbvpi-bedroom sudo[21917]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:33 gbvpi-bedroom sudo[21928]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:33 gbvpi-bedroom mpd_monitor.sh[21537]: MPD Monitor Service: MPD restarted due to no mpc output. Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: Completed starting Core Plugins Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: ----- MyVolumio plugins startup ---- Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: ------------------------------------------- Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: error: MPD error: The expression evaluated to a falsy value: Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: assert.ok(self.idling) Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: error: The expression evaluated to a falsy value: Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: assert.ok(self.idling) Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: error: updateQueue error: null Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: info: MPD running with PID21962 Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: ,establishing connection Dec 06 01:34:33 gbvpi-bedroom volumio[21768]: error: updateQueue error: null Dec 06 01:34:35 gbvpi-bedroom volumio[21768]: info: go-librespot daemon successfully initialized Dec 06 01:34:36 gbvpi-bedroom volumio[21768]: info: Discovery: Browse raised the following error Error: dns service error: unknown Dec 06 01:34:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 186. Dec 06 01:34:36 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:36 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:36 gbvpi-bedroom go-librespot[22037]: go-librespot daemon starting... Dec 06 01:34:36 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 2. Dec 06 01:34:36 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:36 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="app state loaded" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:36 gbvpi-bedroom volumio[21768]: info: No valid Plugin REST Endpoint Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: 20251206 01:34:36.430 [22039.22039] ERROR SampleApp: api request was not successful Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: Error: Application ID was not specified! Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -m|--manufacturer: Manufacturer of the device Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -n|--deviceName: Device name Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -l|--model: Device's model name Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -s|--serialNumber: Device's serial number Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -o|--outputDevice: ALSA PCM device to play audio to Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -p|--port: Port to run the local configuration HTTP server on Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 06 01:34:36 gbvpi-bedroom qobuz-connect[22039]: -h|--help: Print this help Dec 06 01:34:36 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:36 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=info msg="zeroconf server listening on port 39929" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="obtained new client token: AACsTjL+1agLYZ7LCLdZuma6iXgRnBJfNmIs0meOHS8LPd5rP9TI9dLd/UmH3qqSGJlIdrH4ySRU3W6IplrYjghXjs9eHPGXgl8itvzeMUoFyi5XCBthF7bzxTrsDNJK97st1VrOCzDkpWsHzhxgDo4PLE5vFiAS4/lqUmiwq0fkGaRae0QrWkFtjtNkxScljR2fKHTcl6/3i84iEGiBPYGVvZXfyfpFVu8YBcjOOJmmFGjC4Nqz/b2/8w==" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34:36-05:00" level=debug msg="completed challenge" Dec 06 01:34:36 gbvpi-bedroom sudo[22047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 01:34:36 gbvpi-bedroom sudo[22047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:36 gbvpi-bedroom sudo[22049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 01:34:36 gbvpi-bedroom sudo[22049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:36 gbvpi-bedroom go-librespot[22038]: time="2025-12-06T01:34: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 06 01:34:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:36 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:36 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 06 01:34:36 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 06 01:34:36 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 06 01:34:37 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 06 01:34:37 gbvpi-bedroom sudo[22047]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:37 gbvpi-bedroom sudo[22049]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:37 gbvpi-bedroom mpd_monitor.sh[22052]: MPD Monitor Service: Starting MPD Monitor Service Dec 06 01:34:37 gbvpi-bedroom volumio[21768]: info: Successfully started MPD Monitor Dec 06 01:34:37 gbvpi-bedroom volumio[21768]: info: Successfully started MPD Monitor Dec 06 01:34:38 gbvpi-bedroom sudo[22071]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 06 01:34:38 gbvpi-bedroom sudo[22071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:38 gbvpi-bedroom sudo[22071]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:38 gbvpi-bedroom sudo[22073]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 06 01:34:38 gbvpi-bedroom sudo[22073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:38 gbvpi-bedroom sudo[22073]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:38 gbvpi-bedroom sudo[22076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 06 01:34:38 gbvpi-bedroom sudo[22076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:38 gbvpi-bedroom sudo[22076]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:38 gbvpi-bedroom volumio[21768]: info: Upmpdcli Daemon Started Dec 06 01:34:38 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:38 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:38 gbvpi-bedroom volumio[21768]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 06 01:34:39 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:39 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:39 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:39 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 187. Dec 06 01:34:40 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:40 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:40 gbvpi-bedroom go-librespot[22079]: go-librespot daemon starting... Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=debug msg="app state loaded" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-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 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-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 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=info msg="zeroconf server listening on port 42499" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=debug msg="obtained new client token: AAByRjrdJeM+n/4bmd53MeQz/yQegsX6U8SjwYqqYCF7+0OgjGuIV42fnLW28bHBRUeXR3erBqsxkstAMHt9X/pRQXyXl/lGus9ugy6WiJH6Ei9NE5GOO0Ydsc+S2ucBAx2WuUiKko30Gqpq5wsbuHCNwsbnTN5CR9ARMD5sJSItHGHmmgm/+22loZfx/x7xmRfpd869BTF9qDAQRItTvWOcD07M6b0h1Rv2xj9W/UZhOH6zEz4I+rYYsA==" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=debug msg="completed challenge" Dec 06 01:34:40 gbvpi-bedroom go-librespot[22080]: time="2025-12-06T01:34:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:41 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 3. Dec 06 01:34:41 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:41 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:41 gbvpi-bedroom volumio[21768]: info: No valid Plugin REST Endpoint Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: 20251206 01:34:41.655 [22087.22087] ERROR SampleApp: api request was not successful Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: Error: Application ID was not specified! Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -m|--manufacturer: Manufacturer of the device Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -n|--deviceName: Device name Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -l|--model: Device's model name Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -s|--serialNumber: Device's serial number Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -o|--outputDevice: ALSA PCM device to play audio to Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -p|--port: Port to run the local configuration HTTP server on Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 06 01:34:41 gbvpi-bedroom qobuz-connect[22087]: -h|--help: Print this help Dec 06 01:34:41 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:41 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 06 01:34:41 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:41 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin bluetooth to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin multiroom to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin metavolumio to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin cd_controller to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: Starting MyVolumio Remote Streaming Endpoints Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: MyVolumio login type: Token Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 06 01:34:42 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: Streaming services startup Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: Starting Streaming Daemon Dec 06 01:34:43 gbvpi-bedroom sudo[22089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 06 01:34:43 gbvpi-bedroom sudo[22089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 06 01:34:43 gbvpi-bedroom sudo[22089]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: error: Cannot start Volumio Streaming Daemon Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 06 01:34:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 188. Dec 06 01:34:43 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:43 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:43 gbvpi-bedroom go-librespot[22095]: go-librespot daemon starting... Dec 06 01:34:43 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:43-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:43 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:43-05:00" level=debug msg="app state loaded" Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: MyVolumio token set successfully Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: MYVOLUMIO: Adding device Dec 06 01:34:43 gbvpi-bedroom volumio[21768]: info: MYVOLUMIO: Evaluating Server Dec 06 01:34:43 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: MyVolumio Plan changed: premium Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Removing browser output: myVolumio user plan is not superstar Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Removing audio output: Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: MYVOLUMIO: Adding device Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: MYVOLUMIO: Evaluating Server Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Remote config written successfully Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Starting Tunnel 1 Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Starting Tunnel Connection Checker Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Completed starting MyVolumio Plugin Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-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 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-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 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=info msg="zeroconf server listening on port 40289" Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=debug msg="obtained new client token: AAB0l+93q39IBNeg88Q5yKh5x5KI0Z1k76OkJYLW+I2AHOJm+g80x7SiYpiHODnD1um6t+7aIbrIcZxZMgw47Ybs/zF1eUO9pEtSwrQDvg23xqjgqS1DfmVuzoW64m7yzK+z/hNhBbqjQpmiMNAm3d6XVhzbOU8c5XoC6L7+0Yg9Dchl2mfYeJayLp+TYZAYILpR8KNhZ5TLi6RRJ7amNUSiWUPM0EtA1d7nO86fYFv98QIxlirDOKwi6g==" Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: MYVolumio Device enabled Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: MyVolumio status changed Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Streaming services startup Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Starting Streaming Daemon Dec 06 01:34:44 gbvpi-bedroom sudo[22142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 06 01:34:44 gbvpi-bedroom sudo[22142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: Setting Geolocation for MyVolumio to us1 Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:44 gbvpi-bedroom sudo[22142]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=debug msg="completed challenge" Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 06 01:34:44 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 06 01:34:44 gbvpi-bedroom go-librespot[22098]: time="2025-12-06T01:34:44-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 06 01:34:45 gbvpi-bedroom sudo[22146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 06 01:34:45 gbvpi-bedroom sudo[22146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom sudo[22146]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: MultiRoom plugin initialized Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: STOPPING SNAPCLIENT Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: Snap server stop Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: STOPPING volumioStreaming Dec 06 01:34:45 gbvpi-bedroom sudo[22163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 06 01:34:45 gbvpi-bedroom sudo[22163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom sudo[22165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 06 01:34:45 gbvpi-bedroom sudo[22165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 06 01:34:45 gbvpi-bedroom sudo[22168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 06 01:34:45 gbvpi-bedroom sudo[22168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 06 01:34:45 gbvpi-bedroom sudo[22171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 06 01:34:45 gbvpi-bedroom sudo[22171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 06 01:34:45 gbvpi-bedroom sudo[22171]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 06 01:34:45 gbvpi-bedroom sudo[22163]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 06 01:34:45 gbvpi-bedroom sudo[22165]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 06 01:34:45 gbvpi-bedroom sudo[22168]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Preparing to generate the ALSA configuration file Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Updating MyVolumio device info Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Setting Geolocation for MyVolumio to us4 Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Successfully Added MyVolumio device Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: Removed streaming files Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: volumioStreaming STOPPED Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: SNAPSERVER STOPPED Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: SNAPCLIENT STOPPED Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: error: Cannot start Volumio Streaming Daemon Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Asound.conf file unchanged, so no further update is needed Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Output device has changed, restarting MPD Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Output device has changed, restarting Shairport Sync Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:45 gbvpi-bedroom sudo[22176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 06 01:34:45 gbvpi-bedroom sudo[22176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom sudo[22176]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:45 gbvpi-bedroom sudo[22178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 06 01:34:45 gbvpi-bedroom sudo[22178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: Pushing multiroomSync output for this device Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: Pushing multiroomSync output Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding audio output: Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding audio output: Dec 06 01:34:45 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.768s CPU time. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:45 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.15044 Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding METAVOLUMIO REST API Endpoints Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Preparing CD Folders Dec 06 01:34:45 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.15044 disconnected from D-Bus Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding CD REST API Endpoints Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Starting UDEV Watcher for CD Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: Detecting CD presence with UDEV Dec 06 01:34:45 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 06 01:34:45 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 06 01:34:45 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 06 01:34:45 gbvpi-bedroom sudo[22196]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 06 01:34:45 gbvpi-bedroom sudo[22196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 06 01:34:45 gbvpi-bedroom sudo[22196]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:46 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 4. Dec 06 01:34:46 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:46 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:46 gbvpi-bedroom mpd[22198]: 2025-12-06T01:34:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 06 01:34:46 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 06 01:34:46 gbvpi-bedroom sudo[22178]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189. Dec 06 01:34:47 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:47 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:47 gbvpi-bedroom go-librespot[22204]: go-librespot daemon starting... Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=debug msg="app state loaded" Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 06 01:34:47 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:47-05:00" level=info msg="zeroconf server listening on port 33905" Dec 06 01:34:48 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:48-05:00" level=debug msg="obtained new client token: AACuLch1d/BDeeojGiQlVaHJR3UBRcfY6ekbhf8mS02mq96AhLyIwdhtBmldLwVB5cuIIXaqWVZBCb1mPDu9fIhqnlKexPSsYC6/sgu4H/X+1a+rza6OOqpXpIq15oeU7JDFO6Ez9kE3Re119ioeiEbFTonn9l7koyD77uEH13rbMf7rp3XuXNAB/XgUdu0vc5duue/eaPwZmnL/uLnOv0L8KFDUzquCWFDSf3MdhOXn+h79p7QKNx0=" Dec 06 01:34:48 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:48 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:48-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:48 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:48-05:00" level=debug msg="completed challenge" Dec 06 01:34:48 gbvpi-bedroom go-librespot[22205]: time="2025-12-06T01:34:48-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding inputs REST Endpoints Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Scanning Audio Inputs Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Checking against Known Cards name Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding Server instance for streaming Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: error: Hi Res Audio Failed Login: Missing Login Data Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 06 01:34:50 gbvpi-bedroom sudo[22230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 06 01:34:50 gbvpi-bedroom sudo[22230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding TIDAL REST API Endpoints Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Stopping AccessToken refresher cron for QOBUZ Dec 06 01:34:50 gbvpi-bedroom sudo[22237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 06 01:34:50 gbvpi-bedroom sudo[22237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:50 gbvpi-bedroom sudo[22230]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: AccessToken refresher cron started for QOBUZ Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Adding QOBUZ REST API Endpoints Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Updating MyVolumio device info Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:50 gbvpi-bedroom sudo[22237]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: MRS: Getting audio outputs on start Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: MRS: Requesting all other devices output Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:50 gbvpi-bedroom sudo[22240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 06 01:34:50 gbvpi-bedroom sudo[22240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Successfully Updated MyVolumio device Dec 06 01:34:50 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 06 01:34:50 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 06 01:34:50 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: MPD Permissions set Dec 06 01:34:50 gbvpi-bedroom sudo[22244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 06 01:34:50 gbvpi-bedroom sudo[22244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Executing endpoint qc_getconfig Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 06 01:34:50 gbvpi-bedroom sudo[22240]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:50 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:50 gbvpi-bedroom sudo[22244]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: error: updateQueue error: null Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:50 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioStop Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::stop Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Successfully Updated MyVolumio device Dec 06 01:34:51 gbvpi-bedroom sudo[22263]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 06 01:34:51 gbvpi-bedroom sudo[22263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Executing endpoint qc_getconfig Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.050 [22242.22242] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.054 [22242.22242] INFO VolumeManager: [0x1633588]: Setting new playback volume: 75 Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.054 [22242.22242] INFO VolumeManager: [0x1633588]: Setting new mute state: 0 Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.054 [22242.22242] INFO QobuzConnect: [0x1633f58]: Client initialized! Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.054 [22242.22242] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Starting Shairport Sync Dec 06 01:34:51 gbvpi-bedroom autossh[20746]: received signal to exit (15) Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 06 01:34:51 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Listing playlists Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.077 [22242.22242] INFO LocalConfigManager: [0x1632e68]: Starting Local Configuration server Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.077 [22242.22242] INFO SampleApp: Starting Local configuration server Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.078 [22242.22242] INFO SampleApp: Connected to UNIX socket client 0x161d818 Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Adding audio output: Dec 06 01:34:51 gbvpi-bedroom sudo[22270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 06 01:34:51 gbvpi-bedroom sudo[22270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Adding audio output: Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 06 01:34:51 gbvpi-bedroom sudo[22263]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:51 gbvpi-bedroom autossh[22274]: port set to 0, monitoring disabled Dec 06 01:34:51 gbvpi-bedroom autossh[22274]: starting ssh (count 1) Dec 06 01:34:51 gbvpi-bedroom autossh[22274]: ssh child pid is 22277 Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Successfully Added MyVolumio device Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Remote SSH Started Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 06 01:34:51 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:51 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.629s CPU time. Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 06 01:34:51 gbvpi-bedroom qobuz-connect[22242]: 20251206 01:34:51.200 [22242.22242] INFO SampleApp: Playback volume changed: 75 Dec 06 01:34:51 gbvpi-bedroom sudo[22270]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: info: Shairport-Sync Started Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: 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 06 01:34:51 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:51 gbvpi-bedroom volumio[21768]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 06 01:34:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 190. Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:51 gbvpi-bedroom volumiossh-tunnel[22277]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts. Dec 06 01:34:51 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:51 gbvpi-bedroom go-librespot[22293]: go-librespot daemon starting... Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=debug msg="app state loaded" Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-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 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-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 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=info msg="zeroconf server listening on port 46555" Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=debug msg="obtained new client token: AAAIj7d21+9c8vfN0WvnyiBrU0bZopJmiInhY3hytA4IsncLJOljhj9lT2TuVs7IEe5aGX1IOhUQs6Vp3gAcBaLHzivP+yhdi0Z6h+eVOafrbGDi77eW7NYnCGz7w0nuadV8LK+c8i0SP3fAtx7Sgox+Ok1WKTt6aLnwT98n3k7LWwmdlcYwDGDqA1Am7EaCGEayYDVsGQb03VPgO6AX8ImE4i6UB3VDBYFlhAk2l0pQPFUjXoLLDDqQxw==" Dec 06 01:34:51 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:52 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:52-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:52 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:52-05:00" level=debug msg="completed challenge" Dec 06 01:34:52 gbvpi-bedroom go-librespot[22294]: time="2025-12-06T01:34:52-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:53 gbvpi-bedroom volumio[21768]: info: TidalConnect service stoped! Dec 06 01:34:53 gbvpi-bedroom volumio[21768]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 06 01:34:53 gbvpi-bedroom volumio[21768]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 06 01:34:53 gbvpi-bedroom sudo[22311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 06 01:34:53 gbvpi-bedroom sudo[22311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:53 gbvpi-bedroom sudo[22314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 06 01:34:53 gbvpi-bedroom sudo[22314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 06 01:34:53 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:53 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:53 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 06 01:34:53 gbvpi-bedroom sudo[22311]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:53 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 06 01:34:53 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 06 01:34:53 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 06 01:34:53 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 06 01:34:53 gbvpi-bedroom sudo[22314]: pam_unix(sudo:session): session closed for user root Dec 06 01:34:53 gbvpi-bedroom mpd_monitor.sh[22319]: MPD Monitor Service: Starting MPD Monitor Service Dec 06 01:34:53 gbvpi-bedroom volumio[21768]: info: Successfully started MPD Monitor Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: Executing endpoint tc_getconfig Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 06 01:34:54 gbvpi-bedroom vtcs[22317]: STARTING TidalConnect services, version: 1.5.2.56 Dec 06 01:34:54 gbvpi-bedroom vtcs[22317]: STARTED TidalConnect services. Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: Executing endpoint tc_connect Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: Connecting to TidalConnect Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::servicePushState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::pushState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: MRS: Pushing multiroomSync output update for this device Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: MRS: Pushing multiroomSync output Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::servicePushState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreStateMachine::pushState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioPushState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: MRS: Pushing multiroomSync output update for this device Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: MRS: Pushing multiroomSync output Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: CorePlayQueue::getTrack 0 Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 06 01:34:54 gbvpi-bedroom volumio[21768]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 06 01:34:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 191. Dec 06 01:34:55 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:55 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:55 gbvpi-bedroom go-librespot[22337]: go-librespot daemon starting... Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=debug msg="app state loaded" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-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 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-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 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-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 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=info msg="zeroconf server listening on port 37763" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=debug msg="obtained new client token: AABJJ3JD23l9gz53TEeJWatXVnrKKbc8pQyPd0QRVdxnUf3IVCnOr7mT+V1OsVPRX06cbWq+SLZ3JfM2RMK1Xk/STxZ3mrx4Lx1U2PLa/CLGH9vGk7GanlwzD1aHNUWNnjcdTB/r2YsGjP8A56MvBsg4RXiJC5Xl023w5+y+bZkkqlU5lzp95tD1M+UgTukgSVJSDfmrmPfc0/fTPDq6gm6iJwxZKBAMAOURvDywN3nBAx8qjYakpDjIig==" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=debug msg="completed challenge" Dec 06 01:34:55 gbvpi-bedroom go-librespot[22338]: time="2025-12-06T01:34:55-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:34:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: TidalConnect service started! Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: [Metrics] CommandRouter: 29s 488.93ms Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumiosetStartupVolume Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::Close All Modals sent Dec 06 01:34:56 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::Close All Modals sent Dec 06 01:34:57 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 06 01:34:57 gbvpi-bedroom volumio[21768]: 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 06 01:34:57 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:57 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 06 01:34:57 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 06 01:34:57 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 06 01:34:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 192. Dec 06 01:34:59 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:59 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:34:59 gbvpi-bedroom go-librespot[22363]: go-librespot daemon starting... Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=debug msg="app state loaded" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-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 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-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 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-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 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=info msg="zeroconf server listening on port 38259" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=debug msg="obtained new client token: AADUsmouJmkF9V6ck6rCeVkWH+j2tQgGwA6n8oHCNsULAlcJ9SqP2qsnD/PRAcf5aW2IKSN4zgTno9JXp2+9esXWUH9IRi72P/k+AtQ24MIqXRzbgGWkKq6pdClH+j/MgeBlVM9Kr0hrgqWZeuIZ7EyvAasb5t9M49gMemWzkhDBAsDLN3UcarYcYMn78Hap2WLL6c3S/oMXAsPU6/8R3FPihNQN7DL3yYDJSiD4EYkjE05lqn3+e0CNhw==" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=debug msg="completed keyexchange" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-05:00" level=debug msg="completed challenge" Dec 06 01:34:59 gbvpi-bedroom go-librespot[22364]: time="2025-12-06T01:34:59-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 06 01:34:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:34:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:34:59 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:34:59 gbvpi-bedroom volumio[21768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:34:59 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:34:59 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetState Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 06 01:35:02 gbvpi-bedroom volumio-remote-updater[11354]: Test mode enabled Dec 06 01:35:02 gbvpi-bedroom volumio-remote-updater[11354]: Alpha mode disabled Dec 06 01:35:02 gbvpi-bedroom volumio-remote-updater[11354]: Alpha legacy test mode disabled Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: 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 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::volumioGetBrowseSources Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 06 01:35:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 193. Dec 06 01:35:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:35:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 06 01:35:02 gbvpi-bedroom go-librespot[22375]: go-librespot daemon starting... Dec 06 01:35:02 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 06 01:35:02 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:02-05:00" level=debug msg="app state loaded" Dec 06 01:35:02 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: Initializing connection to go-librespot Websocket Dec 06 01:35:02 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:02-05:00" level=debug msg="new websocket client" Dec 06 01:35:02 gbvpi-bedroom volumio[21768]: info: Connection to go-librespot Websocket established Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=info msg="zeroconf server listening on port 41615" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="obtained new client token: AAAVuFnxzGtddnAASSdCT/6tFUhvsqA6v+aidLfov9n8F2dP6VKaLd5R/L6RUjyOTzcQ7QD2I7b7qJE4A6jG+BOfF260X4zboo8uvLkZZFFIFYG33ElqSE6Vpm6pWTs9qjFJ2KkoqXd8L4FXErQ5zoKA87k6H3lXkaAlZ4GWhe71vKZmATwBZi90CCsu8TND4+4/fMtSmvG+0PelfXeP8+0oPfKgqAxi068r7NBGWPgLHJ9f3TRAsxWyvA==" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="completed keyexchange" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=debug msg="completed challenge" Dec 06 01:35:03 gbvpi-bedroom go-librespot[22376]: time="2025-12-06T01:35:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 06 01:35:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 06 01:35:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 06 01:35:03 gbvpi-bedroom volumio[21768]: info: Connection to go-librespot Websocket closed Dec 06 01:35:03 gbvpi-bedroom volumio[21768]: info: BOOT COMPLETED Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: info: Getting Spotify volume Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: errno: -111, Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: code: 'ECONNREFUSED', Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: syscall: 'connect', Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: address: '127.0.0.1', Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: port: 9879, Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: response: undefined Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: } Dec 06 01:35:05 gbvpi-bedroom volumio[21768]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 06 01:35:06 gbvpi-bedroom sudo[22397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 01:34' Dec 06 01:35:06 gbvpi-bedroom sudo[22397]: 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"