Dec 10 20:48:00 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Dec 10 20:48:00 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:01 gbvpi-bedroom go-librespot[18924]: go-librespot daemon starting... Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="app state loaded" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=info msg="zeroconf server listening on port 38987" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="obtained new client token: AAAj3s51skMhSBumQjCjqwvfpU+u2j5W1VWd7sfYjBVZeU1zhvv305L3X1KAaJawFVBX9OWCFtFOiRd+SfNM35ivKaTkW9n7Z0tFDcCSuMRpZD7Ncf1RrWXgoAxL3O/KehHnEOGsD5Aytuf9rop9qya0iN+i4M0SBHqwAO255gXouGS6sdldy8bC2LHWjO7B3QE+DCY4Owyf4kzwTnmvPQxij/lxoOGPzhPN1pxigkCMOzbvzxf4XqKw3Q==" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=debug msg="completed challenge" Dec 10 20:48:01 gbvpi-bedroom go-librespot[18925]: time="2025-12-10T20:48:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:02 gbvpi-bedroom volumio[18296]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:02 gbvpi-bedroom volumio[18296]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 114. Dec 10 20:48:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:04 gbvpi-bedroom go-librespot[18936]: go-librespot daemon starting... Dec 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-05:00" level=debug msg="app state loaded" Dec 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-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 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-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 10 20:48:04 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:04-05:00" level=info msg="zeroconf server listening on port 36859" Dec 10 20:48:05 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:05-05:00" level=debug msg="obtained new client token: AABumrZh1TPL2n4FAPOycztwSSAVdVCn0sO4YTOu3v0ZJTj5VqxR6KJ1I7tobNvm/rfjExy9W+VlZVqZeECteVYvkLcX+iInB+qU986i0pGCm2mXO76i9G7sedf+yhjVsmu/qzYQo+SfOYXVQuvqlitoabHiiT20056ZLw/0UhMXdM7Wc19ZuMUODGiPk81it3o/OX8IsUKACTJWgHS28i1yKXT+ZIGCz35znVzZvhVuIQS2gXsHt6I=" Dec 10 20:48:05 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:05 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:05-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:05 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:05-05:00" level=debug msg="completed challenge" Dec 10 20:48:05 gbvpi-bedroom volumio[18296]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:05 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:05-05:00" level=debug msg="new websocket client" Dec 10 20:48:05 gbvpi-bedroom volumio[18296]: info: Connection to go-librespot Websocket established Dec 10 20:48:05 gbvpi-bedroom go-librespot[18937]: time="2025-12-10T20:48:05-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:05 gbvpi-bedroom volumio[18296]: info: Connection to go-librespot Websocket closed Dec 10 20:48:06 gbvpi-bedroom volumio[18296]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:06 gbvpi-bedroom volumio[18296]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:06 gbvpi-bedroom volumio[18296]: info: Listing playlists Dec 10 20:48:06 gbvpi-bedroom volumio[18296]: info: Listing playlists Dec 10 20:48:06 gbvpi-bedroom volumio[18296]: info: Listing playlists Dec 10 20:48:06 gbvpi-bedroom volumio[18296]: info: Listing playlists Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: info: Getting Spotify volume Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: errno: -111, Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: code: 'ECONNREFUSED', Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: syscall: 'connect', Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: address: '127.0.0.1', Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: port: 9879, Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: response: undefined Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: } Dec 10 20:48:08 gbvpi-bedroom volumio[18296]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 20:48:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:08 gbvpi-bedroom go-librespot[18961]: go-librespot daemon starting... Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="app state loaded" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=info msg="zeroconf server listening on port 45869" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="obtained new client token: AABxKUDV+KFJyWb3xCFZSC3RZ2Vvq7fr0toMsfx8VemiMUPaZTd85I246CHdZH/tbuS8vjHcVYmDOq8hGSs6SVAqtthwiY1/+X9MX+iVX6b+zsSDe7gLh1jTV4RjcKtJ1MqKCVmJRYST5QJvGQ8F4V7HqTfrlWmGtwydNQ2b4KV0uUEM2zoXO2E8xak4CA93GkJOEz+gYxQV78FnZ962vqPkdqq24RBITDjh5dQ8p+xDax0Rs8CtpUviVw==" Dec 10 20:48:08 gbvpi-bedroom sudo[18980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-10 20:47' Dec 10 20:48:08 gbvpi-bedroom sudo[18980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:08 gbvpi-bedroom sudo[18980]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48:08-05:00" level=debug msg="completed challenge" Dec 10 20:48:08 gbvpi-bedroom vtcs[18828]: [2025-12-10 20:48:08.739] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 10 20:48:08 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:08] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Dec 10 20:48:08 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:08] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Dec 10 20:48:08 gbvpi-bedroom qobuz-connect[18801]: 20251210 20:48:08.740 [18801.18801] INFO SampleApp: Socket closed Dec 10 20:48:08 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:08 gbvpi-bedroom go-librespot[18971]: time="2025-12-10T20:48: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 10 20:48:08 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.336s CPU time. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 10 20:48:08 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 693. Dec 10 20:48:09 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 10 20:48:09 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 10 20:48:09 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.336s CPU time. Dec 10 20:48:09 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 10 20:48:09 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ----- Volumio3 ---- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ----- System startup ---- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: MYVOLUMIO Environment detected Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Plugin folders cleanup Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning into folder /volumio/app/plugins/ Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category audio_interface Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category miscellanea Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category music_service Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category plugins.json Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category system_controller Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category user_interface Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning into folder /data/plugins/ Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Scanning category music_service Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Plugin folders cleanup completed Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ----- Core plugins startup ---- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Loading plugins from folder /volumio/app/plugins/ Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Adding plugin upnp to MyMusic Plugins Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Loading plugins from folder /data/plugins/ Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Loading plugin "system"... Dec 10 20:48:10 gbvpi-bedroom volumio[18992]: info: Loading plugin "appearance"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "network"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Refreshing Cached IP Addresses Dec 10 20:48:11 gbvpi-bedroom sudo[19020]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 20:48:11 gbvpi-bedroom sudo[19020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:11 gbvpi-bedroom sudo[19020]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:11 gbvpi-bedroom sudo[19022]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 20:48:11 gbvpi-bedroom sudo[19022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "services"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "alsa_controller"... Dec 10 20:48:11 gbvpi-bedroom sudo[19022]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:11 gbvpi-bedroom sudo[19031]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 10 20:48:11 gbvpi-bedroom sudo[19031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "wizard"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "networkfs"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Starting Udev Watcher for removable devices Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Ignoring mount for partition: boot Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Ignoring mount for partition: volumio Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Ignoring mount for partition: volumio_data Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "volumio_command_line_client"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "upnp"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: [1765417691276] Starting Upmpd Daemon Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "my_music"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "mpd"... Dec 10 20:48:11 gbvpi-bedroom volumio[18992]: info: Loading plugin "upnp_browser"... Dec 10 20:48:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116. Dec 10 20:48:11 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:12 gbvpi-bedroom go-librespot[19053]: go-librespot daemon starting... Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=debug msg="app state loaded" Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Starting UPNP Browser Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "alarm-clock"... Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-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 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-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 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=info msg="zeroconf server listening on port 36103" Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "airplay_emulation"... Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Starting Shairport Sync Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "last_100"... Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "webradio"... Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "i2s_dacs"... Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: I2S DAC not set, start Auto-detection Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "volumiodiscovery"... Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: *** WARNING *** For more information see Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: *** WARNING *** For more information see Dec 10 20:48:12 gbvpi-bedroom node[18992]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:12 gbvpi-bedroom node[18992]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:12 gbvpi-bedroom node[18992]: *** WARNING *** For more information see Dec 10 20:48:12 gbvpi-bedroom node[18992]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:12 gbvpi-bedroom node[18992]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:12 gbvpi-bedroom node[18992]: *** WARNING *** For more information see Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "jellyfin"... Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=debug msg="obtained new client token: AADPpM4F/JbzctGBoAkvlsg/IPh7RiWJsbAxA7CB9YhBrqo1EyIxxC+NN+kUtAfOYjEIJ44uPikA0zkHSy3UNfAx8Q3q2cew+OVnm3/1tVquvdysPPcegPVDezqF9gOMkkQi3WTQhm3S4mt/xZueaJJ2zDM8ZYJK0VXlugNu2xr8y8NiXO4E3/48o5SdnUE4Eljw+HVNjAG7qN3tPD1zEI2amwp5kO2rqi0UeERZiYPP3MjwzB+nFFL6Qg==" Dec 10 20:48:12 gbvpi-bedroom volumio[18992]: info: Loading plugin "spop"... Dec 10 20:48:12 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:13 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:13-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:13 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:13-05:00" level=debug msg="completed challenge" Dec 10 20:48:13 gbvpi-bedroom go-librespot[19054]: time="2025-12-10T20:48:13-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading plugin "outputs"... Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading plugin "albumart"... Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Plugin example_plugin is not enabled Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading plugin "inputs"... Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading plugin "updater_comm"... Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Plugin mpdemulation is not enabled Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading plugin "rest_api"... Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading plugin "websocket"... Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Starting Socket.io Server version 1.7.4 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Loading i18n strings for locale en Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: Updating browse sources language Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::initPlayerControls Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: Express server listening on port 3000 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: [Metrics] WebUI: 3s 783.00ms Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::resetVolumioState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::getcurrentVolume Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Volumio Network Manager: Network status updated: 2 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: VolumeController:: Volume=91 Mute =false Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::pushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::updateTrackBlock Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrackBlock Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 20:48:13 gbvpi-bedroom volumio[19063]: Forking 3 albumart workers Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Reloading queue from file Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::setRepeat true single undefined Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::pushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::setRandom null Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::pushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Setting Device type: Raspberry PI Dec 10 20:48:13 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:13] [connect] Successful connection Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: VolumeController:: Volume=91 Mute =false Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::pushState Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:13 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765417693 101 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: 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 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Completed loading Core Plugins Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Preparing to generate the ALSA configuration file Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Asound.conf file written Dec 10 20:48:13 gbvpi-bedroom sudo[19120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 10 20:48:13 gbvpi-bedroom sudo[19120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:13 gbvpi-bedroom sudo[19120]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Output device has changed, restarting MPD Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Output device has changed, restarting Shairport Sync Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:13 gbvpi-bedroom sudo[19127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 20:48:13 gbvpi-bedroom sudo[19127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:13 gbvpi-bedroom sudo[19127]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:13 gbvpi-bedroom sudo[19128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 20:48:13 gbvpi-bedroom sudo[19128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: ___________ START PLUGINS ___________ Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: ControllerMpd::onStart: Initializing MPD Dec 10 20:48:13 gbvpi-bedroom volumio[18992]: info: Creating MPD Configuration file Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: [1765417694007] CoreMusicLibrary::Adding element Media Servers Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: UPNP Browser: Client initialized successfully Dec 10 20:48:14 gbvpi-bedroom sudo[19137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 20:48:14 gbvpi-bedroom sudo[19137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:14 gbvpi-bedroom sudo[19138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 20:48:14 gbvpi-bedroom sudo[19138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:14 gbvpi-bedroom sudo[19137]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:14 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.262s CPU time. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: [1765417694117] CoreMusicLibrary::Adding element Last_100 Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: [1765417694119] CoreMusicLibrary::Adding element Webradio Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: Initializing BBC Radios Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 20:48:14 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 20:48:14 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: Discovery: Getting this device information Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: [1765417694295] CoreMusicLibrary::Adding element Jellyfin Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: Cannot find translation for source Jellyfin Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: 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/6483a073f2c9b346a09e98bd65fe1753/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"The Mountain Goats & John Vanderslice","mute":false,"status":"stop","track":"Surrounded","volume":91},"type":"device"} Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: Creating Spotify config file Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:14 gbvpi-bedroom sudo[19157]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 20:48:14 gbvpi-bedroom sudo[19157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 20:48:14 gbvpi-bedroom sudo[19157]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:14 gbvpi-bedroom volumio[19083]: Starting albumart workers Dec 10 20:48:14 gbvpi-bedroom volumio[19084]: Starting albumart workers Dec 10 20:48:14 gbvpi-bedroom volumio[18992]: info: Volumio Calling Home Dec 10 20:48:14 gbvpi-bedroom volumio[19086]: Starting albumart workers Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Discovery: Found device GBVPi-Bedroom Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Discovery: Found device GBVPi-Bedroom Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: MPD Permissions set Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: MPD Permissions set Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Spotify config file written Dec 10 20:48:15 gbvpi-bedroom sudo[19031]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:15 gbvpi-bedroom sudo[19178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 10 20:48:15 gbvpi-bedroom sudo[19178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: 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 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:15 gbvpi-bedroom go-librespot[19191]: go-librespot daemon starting... Dec 10 20:48:15 gbvpi-bedroom sudo[19178]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="app state loaded" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: No need to fix Spotify hosts Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Volumio called home Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Starting Shairport Sync Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Starting Shairport Sync Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Starting Shairport Sync Dec 10 20:48:15 gbvpi-bedroom sudo[19211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:15 gbvpi-bedroom sudo[19211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:15 gbvpi-bedroom sudo[19213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:15 gbvpi-bedroom sudo[19213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=info msg="zeroconf server listening on port 37237" Dec 10 20:48:15 gbvpi-bedroom sudo[19215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:15 gbvpi-bedroom sudo[19215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:15 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 20:48:15 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 20:48:15 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:48:15 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.706s CPU time. Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="obtained new client token: AADWOA2hFfcV69Aj7GLwZnswlv+3ZKaGTVRgYK4ufPxamf72w+0Tu8LDnQuaREMoEqi15rnTHtOsWx3PRUC//6X+F5Wm/Q6DN59QK80bu3uyJIg/hC2dbEkOFQF+112ALL8K0fCxm/8ZZDH5zmfMT4lnS0TilZxsnwbUk/rHVCYAulLEjH6mn+8cJ4KqomlAtOHsMJov/fqVnya7gd25kVcYFhdYZNOPxzPSIMNF4TtuOVPBuYrHjAhhIg==" Dec 10 20:48:15 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:48:15 gbvpi-bedroom sudo[19213]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:15 gbvpi-bedroom sudo[19211]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:15 gbvpi-bedroom sudo[19215]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Shairport-Sync Started Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: Error adding Membership: Error: addMembership EINVAL Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Shairport-Sync Started Dec 10 20:48:15 gbvpi-bedroom volumio[18992]: info: Shairport-Sync Started Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=debug msg="completed challenge" Dec 10 20:48:15 gbvpi-bedroom go-librespot[19199]: time="2025-12-10T20:48:15-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:16 gbvpi-bedroom mpd[19167]: 2025-12-10T20:48:16 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 20:48:16 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 20:48:16 gbvpi-bedroom sudo[19128]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:16 gbvpi-bedroom sudo[19138]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: Completed starting Core Plugins Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: ----- MyVolumio plugins startup ---- Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: ------------------------------------------- Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: error: MPD error: The expression evaluated to a falsy value: Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: assert.ok(self.idling) Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: error: The expression evaluated to a falsy value: Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: assert.ok(self.idling) Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: MPD running with PID19167 Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: ,establishing connection Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: error: updateQueue error: null Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: error: updateQueue error: null Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:16 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:18 gbvpi-bedroom volumio[18992]: info: go-librespot daemon successfully initialized Dec 10 20:48:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117. Dec 10 20:48:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:19 gbvpi-bedroom go-librespot[19239]: go-librespot daemon starting... Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=debug msg="app state loaded" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:19 gbvpi-bedroom sudo[19247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 20:48:19 gbvpi-bedroom sudo[19247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:19 gbvpi-bedroom sudo[19249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 20:48:19 gbvpi-bedroom sudo[19249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:19 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 20:48:19 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 20:48:19 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 20:48:19 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 20:48:19 gbvpi-bedroom sudo[19247]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:19 gbvpi-bedroom sudo[19249]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:19 gbvpi-bedroom mpd_monitor.sh[19252]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 20:48:19 gbvpi-bedroom volumio[18992]: info: Successfully started MPD Monitor Dec 10 20:48:19 gbvpi-bedroom volumio[18992]: info: Successfully started MPD Monitor Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-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 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-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 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=info msg="zeroconf server listening on port 40647" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=debug msg="obtained new client token: AAD2hj+s2K0SNdytC3FEBOSLDLmeT3neAV3s4Tmc28vyqECnqVBnbQbWEwiszzl/hDMrVEggy5jAZx4lkU3TZ8BpizAH/kCH015qGwHyTxp4pKw9KJwNtoRAcY4Yj8DN9B9cid/2djLxWnONrcW52bc4mKjyoDSn/es3/XMpShyDIEIDeD0m5p8c7iDP6p7XYzkKeS1/ElC3TXZexRE0IjFaZFFmdl5Liy3yvLUUlWFTQKimS+s8Ea3BXA==" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=debug msg="completed challenge" Dec 10 20:48:19 gbvpi-bedroom go-librespot[19240]: time="2025-12-10T20:48:19-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:21 gbvpi-bedroom sudo[19272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 20:48:21 gbvpi-bedroom sudo[19272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:21 gbvpi-bedroom sudo[19274]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 20:48:21 gbvpi-bedroom sudo[19274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:21 gbvpi-bedroom sudo[19272]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:21 gbvpi-bedroom sudo[19274]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:21 gbvpi-bedroom sudo[19277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 10 20:48:21 gbvpi-bedroom sudo[19277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:21 gbvpi-bedroom volumio[18992]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 10 20:48:21 gbvpi-bedroom sudo[19277]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:21 gbvpi-bedroom volumio[18992]: info: Upmpdcli Daemon Started Dec 10 20:48:21 gbvpi-bedroom volumio[18992]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:21 gbvpi-bedroom volumio[18992]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:22 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Dec 10 20:48:22 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:22 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:22 gbvpi-bedroom go-librespot[19281]: go-librespot daemon starting... Dec 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-05:00" level=debug msg="app state loaded" Dec 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-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 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-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 10 20:48:22 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:22-05:00" level=info msg="zeroconf server listening on port 38121" Dec 10 20:48:23 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:23-05:00" level=debug msg="obtained new client token: AADj+9cyPjGTL8d0GCKt19a6LN9vWlbSrADEi09Arob0bHJ56Gm1R0wZVXZU0qCMBiJDH6qM24KOosgqViSA7ftcr3UlO8g+Nv4HdP/OmG8V25uSyPz2axXxMKGUVO6uhiBZax+exmj6vijpglApHUu7Mdc4qe+Z0t7LnG+ZAkV65RgpzXLxu89ySSiS5y+43pSU7Sg1WoLTTgvg6tYtfP382TtKhQP7tPn9ML0GWSQrPyw8DKvktYw=" Dec 10 20:48:23 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:23 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:23-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:23 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:23-05:00" level=debug msg="completed challenge" Dec 10 20:48:23 gbvpi-bedroom go-librespot[19282]: time="2025-12-10T20:48:23-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin bluetooth to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin multiroom to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin metavolumio to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin cd_controller to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 10 20:48:24 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: Starting MyVolumio Remote Streaming Endpoints Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: MyVolumio login type: Token Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: Streaming services startup Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: Starting Streaming Daemon Dec 10 20:48:25 gbvpi-bedroom sudo[19290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 10 20:48:25 gbvpi-bedroom sudo[19290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 10 20:48:25 gbvpi-bedroom sudo[19290]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: error: Cannot start Volumio Streaming Daemon Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 10 20:48:25 gbvpi-bedroom volumio[18992]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: Listing playlists Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: Listing playlists Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: Listing playlists Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: Listing playlists Dec 10 20:48:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Dec 10 20:48:26 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:26 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:26 gbvpi-bedroom go-librespot[19296]: go-librespot daemon starting... Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="app state loaded" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=info msg="zeroconf server listening on port 32777" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="obtained new client token: AADrf4044Q8VHW7qLaWCsn/oHd2gCT2Jinzx1AhUHPcZ1/S/eB0HoNa0HEBJryLDy15kQXEhUujWqW5JWRQLqbUif66G5NLlgJ2B+Bp2cRi9BkXVyHcHRoZLMun0Lk/pTGfHth4BHbwrsnPLKXnJ/hdxelVJbQpmdgSxHO4Zee7k5Cq2uaiBlITKVOa5dwyBQG4RLASSOwjAE011USIc1op2lYD54lzf+BrQWA+2/a+60nXqG9mXn68x7A==" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: MyVolumio token set successfully Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: MYVOLUMIO: Adding device Dec 10 20:48:26 gbvpi-bedroom volumio[18992]: info: MYVOLUMIO: Evaluating Server Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=debug msg="completed challenge" Dec 10 20:48:26 gbvpi-bedroom go-librespot[19297]: time="2025-12-10T20:48:26-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:26 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: MyVolumio Plan changed: premium Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Removing browser output: myVolumio user plan is not superstar Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Removing audio output: Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: MYVOLUMIO: Adding device Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: MYVOLUMIO: Evaluating Server Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Remote config written successfully Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Starting Tunnel 1 Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Starting Tunnel Connection Checker Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Completed starting MyVolumio Plugin Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: MYVolumio Device enabled Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: MyVolumio status changed Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Streaming services startup Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: Starting Streaming Daemon Dec 10 20:48:27 gbvpi-bedroom sudo[19343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 10 20:48:27 gbvpi-bedroom sudo[19343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 10 20:48:27 gbvpi-bedroom sudo[19343]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 10 20:48:27 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 10 20:48:28 gbvpi-bedroom sudo[19347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 10 20:48:28 gbvpi-bedroom sudo[19347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom sudo[19347]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: MultiRoom plugin initialized Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: STOPPING SNAPCLIENT Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: Snap server stop Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: STOPPING volumioStreaming Dec 10 20:48:28 gbvpi-bedroom sudo[19364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 10 20:48:28 gbvpi-bedroom sudo[19364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 10 20:48:28 gbvpi-bedroom sudo[19366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 10 20:48:28 gbvpi-bedroom sudo[19366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 10 20:48:28 gbvpi-bedroom sudo[19368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 10 20:48:28 gbvpi-bedroom sudo[19368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 10 20:48:28 gbvpi-bedroom sudo[19372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 10 20:48:28 gbvpi-bedroom sudo[19372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom sudo[19372]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 10 20:48:28 gbvpi-bedroom sudo[19364]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom sudo[19366]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 10 20:48:28 gbvpi-bedroom sudo[19368]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Preparing to generate the ALSA configuration file Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Setting Geolocation for MyVolumio to us1 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Reading ALSA contributions from plugins. Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Setting Geolocation for MyVolumio to us1 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: Removed streaming files Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: volumioStreaming STOPPED Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: SNAPSERVER STOPPED Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: SNAPCLIENT STOPPED Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: error: Cannot start Volumio Streaming Daemon Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Asound.conf file written Dec 10 20:48:28 gbvpi-bedroom sudo[19378]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 10 20:48:28 gbvpi-bedroom sudo[19378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom sudo[19378]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Output device has changed, restarting MPD Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Output device has changed, restarting Shairport Sync Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:28 gbvpi-bedroom sudo[19384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 20:48:28 gbvpi-bedroom sudo[19384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom sudo[19386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 20:48:28 gbvpi-bedroom sudo[19384]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:28 gbvpi-bedroom sudo[19386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: Pushing multiroomSync output for this device Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: Pushing multiroomSync output Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding audio output: Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding audio output: Dec 10 20:48:28 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.869s CPU time. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 10 20:48:28 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.10142 Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding METAVOLUMIO REST API Endpoints Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Preparing CD Folders Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding CD REST API Endpoints Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Starting UDEV Watcher for CD Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: Detecting CD presence with UDEV Dec 10 20:48:28 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 10 20:48:28 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.10142 disconnected from D-Bus Dec 10 20:48:28 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 20:48:28 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 20:48:28 gbvpi-bedroom sudo[19404]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 20:48:28 gbvpi-bedroom sudo[19404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 20:48:28 gbvpi-bedroom sudo[19404]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:29 gbvpi-bedroom mpd[19406]: 2025-12-10T20:48:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 20:48:29 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 20:48:29 gbvpi-bedroom sudo[19386]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Dec 10 20:48:29 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:30 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:30 gbvpi-bedroom go-librespot[19409]: go-librespot daemon starting... Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=debug msg="app state loaded" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-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 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-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 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=info msg="zeroconf server listening on port 39751" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=debug msg="obtained new client token: AAB596WwkOQKi/BPJ/EJC0twXWsW4t7HAAcnKZUDUnzyoMHYPE8PpDSJLRhVMIRWozJqKx0QYgYnDntJDQh34qyTStQaoKjeYAc3yKo+f2GHsuRY6njv/MIv10CwoqOOHKQczBYrwaAjrVF8v+h3eZWH8Fh4Zaxj+BX1dS3PVzgwhMTprhb1COpnOEctPk3iEMTlSLlzdt1Ibz8xDYWs1oqvnLUiV1Iutd6h69sfEpzR9dn1HMfU5AkgOw==" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-05:00" level=debug msg="completed challenge" Dec 10 20:48:30 gbvpi-bedroom go-librespot[19410]: time="2025-12-10T20:48:30-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 10 20:48:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding inputs REST Endpoints Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Scanning Audio Inputs Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Checking against Known Cards name Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding Server instance for streaming Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 10 20:48:33 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121. Dec 10 20:48:33 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: error: Hi Res Audio Failed Login: Missing Login Data Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 10 20:48:33 gbvpi-bedroom sudo[19436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 10 20:48:33 gbvpi-bedroom sudo[19436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding TIDAL REST API Endpoints Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Stopping AccessToken refresher cron for QOBUZ Dec 10 20:48:33 gbvpi-bedroom sudo[19443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 10 20:48:33 gbvpi-bedroom sudo[19443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:33 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:33 gbvpi-bedroom go-librespot[19434]: go-librespot daemon starting... Dec 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-05:00" level=debug msg="app state loaded" Dec 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:33 gbvpi-bedroom sudo[19443]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:33 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 10 20:48:33 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 18846 (vtcs) with signal SIGKILL. Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: AccessToken refresher cron started for QOBUZ Dec 10 20:48:33 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 10 20:48:33 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Adding QOBUZ REST API Endpoints Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: MRS: Getting audio outputs on start Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: MRS: Requesting all other devices output Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Updating MyVolumio device info Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:33 gbvpi-bedroom sudo[19451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 10 20:48:33 gbvpi-bedroom sudo[19451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Updating MyVolumio device info Dec 10 20:48:33 gbvpi-bedroom sudo[19436]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:33 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 10 20:48:33 gbvpi-bedroom qobuz-connect[18801]: 20251210 20:48:33.864 [18801.18801] INFO SampleApp: Stopping Local configuration server Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Successfully Added MyVolumio device Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: Successfully Added MyVolumio device Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: MPD Permissions set Dec 10 20:48:33 gbvpi-bedroom sudo[19456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 10 20:48:33 gbvpi-bedroom sudo[19456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:33 gbvpi-bedroom sudo[19456]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48: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-gew4.spotify.com:80]" Dec 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-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 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-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 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-05:00" level=info msg="zeroconf server listening on port 46043" Dec 10 20:48:33 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:33-05:00" level=debug msg="new websocket client" Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioStop Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::stop Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 10 20:48:33 gbvpi-bedroom volumio[18992]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: error: updateQueue error: null Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Connection to go-librespot Websocket established Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Starting Shairport Sync Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Adding audio output: Dec 10 20:48:34 gbvpi-bedroom sudo[19472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 10 20:48:34 gbvpi-bedroom sudo[19472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Adding audio output: Dec 10 20:48:34 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:34-05:00" level=debug msg="obtained new client token: AACLEb6GdtLjTJgSxoZU80i8Vi4SUg87rt7cQNap7wdfM0MZbAa1wdCPBi/9RKevMuHuj9361zCjvFhOBcUNde0M4/CmVR36OUM+kWDSCmlqwcRw0YEeQdxRzaUPqNa/HRD3D+gfwMuSlWntfaNFJQfOrkuceU+fUBO5xPl6TeEzoNCZsQeUjhNY/xE8NX7/Xgw6SrbUR0E+6IIjmSKu19WbGZCGbdEFcE8ueDVFj5EJ6Zblht4+GyU=" Dec 10 20:48:34 gbvpi-bedroom sudo[19474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:34 gbvpi-bedroom sudo[19474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Successfully Updated MyVolumio device Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 20:48:34 gbvpi-bedroom autossh[18780]: received signal to exit (15) Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 10 20:48:34 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 10 20:48:34 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:48:34 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.619s CPU time. Dec 10 20:48:34 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:34 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:34-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:34 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:34-05:00" level=debug msg="completed challenge" Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:48:34 gbvpi-bedroom sudo[19474]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 10 20:48:34 gbvpi-bedroom sudo[19472]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:34 gbvpi-bedroom autossh[19479]: port set to 0, monitoring disabled Dec 10 20:48:34 gbvpi-bedroom autossh[19479]: starting ssh (count 1) Dec 10 20:48:34 gbvpi-bedroom autossh[19479]: ssh child pid is 19482 Dec 10 20:48:34 gbvpi-bedroom go-librespot[19445]: time="2025-12-10T20:48:34-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Successfully Updated MyVolumio device Dec 10 20:48:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Remote SSH Started Dec 10 20:48:34 gbvpi-bedroom volumiossh-tunnel[19482]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Shairport-Sync Started Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: info: Connection to go-librespot Websocket closed Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: 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 10 20:48:34 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:34 gbvpi-bedroom volumio[18992]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 10 20:48:34 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 10 20:48:34 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 10 20:48:34 gbvpi-bedroom sudo[19451]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:35 gbvpi-bedroom volumio[18992]: info: Executing endpoint qc_getconfig Dec 10 20:48:35 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.026 [19497.19497] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.029 [19497.19497] INFO VolumeManager: [0x1cbf588]: Setting new playback volume: 75 Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.029 [19497.19497] INFO VolumeManager: [0x1cbf588]: Setting new mute state: 0 Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.029 [19497.19497] INFO QobuzConnect: [0x1cbff58]: Client initialized! Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.029 [19497.19497] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 10 20:48:35 gbvpi-bedroom volumio[18992]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 10 20:48:35 gbvpi-bedroom volumio[18992]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.045 [19497.19497] INFO LocalConfigManager: [0x1cbee68]: Starting Local Configuration server Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.045 [19497.19497] INFO SampleApp: Starting Local configuration server Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.046 [19497.19497] INFO SampleApp: Connected to UNIX socket client 0x1ca9818 Dec 10 20:48:35 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:35.175 [19497.19497] INFO SampleApp: Playback volume changed: 75 Dec 10 20:48:35 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:36 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:36 gbvpi-bedroom volumio[18992]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:36 gbvpi-bedroom volumio[18992]: info: TidalConnect service stoped! Dec 10 20:48:36 gbvpi-bedroom volumio[18992]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 10 20:48:36 gbvpi-bedroom volumio[18992]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 10 20:48:36 gbvpi-bedroom sudo[19512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 10 20:48:36 gbvpi-bedroom sudo[19512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:36 gbvpi-bedroom sudo[19516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 20:48:36 gbvpi-bedroom sudo[19516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:36 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:36 gbvpi-bedroom sudo[19512]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:36 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 20:48:36 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 20:48:36 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 20:48:37 gbvpi-bedroom sudo[19516]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: info: Successfully started MPD Monitor Dec 10 20:48:37 gbvpi-bedroom mpd_monitor.sh[19520]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: info: Getting Spotify volume Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: errno: -111, Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: code: 'ECONNREFUSED', Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: syscall: 'connect', Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: address: '127.0.0.1', Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: port: 9879, Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: response: undefined Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: } Dec 10 20:48:37 gbvpi-bedroom volumio[18992]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 20:48:37 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:37 gbvpi-bedroom sudo[19539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-10 20:47' Dec 10 20:48:37 gbvpi-bedroom sudo[19539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:37 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:37 gbvpi-bedroom go-librespot[19536]: go-librespot daemon starting... Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=debug msg="app state loaded" Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:37 gbvpi-bedroom sudo[19539]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:37 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:48:37.668 [19497.19497] INFO SampleApp: Socket closed Dec 10 20:48:37 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:37] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 10 20:48:37 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:37] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 10 20:48:37 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:37 gbvpi-bedroom vtcs[19518]: BYE TidalConnect Dec 10 20:48:37 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: volumio.service: Consumed 19.937s CPU time. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-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 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-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 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-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 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=info msg="zeroconf server listening on port 37581" Dec 10 20:48:37 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=debug msg="obtained new client token: AAATkwvyeZa9vmXovx7tdXSQiIqdJDAnTNZx9fwGTLCqZfpyCkvgObksHopZ6yLw+N5zijOGR9n30jU/s90F+sdqZHMwPTkulu/7xvy9MHOtTu6wUuuVphwnXWfbYCsccS5yiBm6z3kaFUlHtMwhZ/FqMTasBCdqsLZMlCSavg/KbcLPaRKUXtC5ZrRAnrcH4cTiFhREbB1WHkDjG3NExMRjYPuN5iMyqqeqkOtqumlAAIS8dE8eH3pLRg==" Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-05:00" level=debug msg="completed challenge" Dec 10 20:48:37 gbvpi-bedroom go-librespot[19541]: time="2025-12-10T20:48:37-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 10 20:48:37 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:37 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: vtcs.service: Scheduled restart job, restart counter is at 1. Dec 10 20:48:37 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 694. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: volumio.service: Consumed 19.937s CPU time. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 10 20:48:38 gbvpi-bedroom vtcs[19565]: BYE TidalConnect Dec 10 20:48:38 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: vtcs.service: Scheduled restart job, restart counter is at 2. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:38 gbvpi-bedroom vtcs[19576]: BYE TidalConnect Dec 10 20:48:38 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: vtcs.service: Scheduled restart job, restart counter is at 3. Dec 10 20:48:38 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:39 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ----- Volumio3 ---- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ----- System startup ---- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: MYVOLUMIO Environment detected Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Plugin folders cleanup Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning into folder /volumio/app/plugins/ Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category audio_interface Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category miscellanea Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category music_service Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category plugins.json Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category system_controller Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category user_interface Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning into folder /data/plugins/ Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Scanning category music_service Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Plugin folders cleanup completed Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ----- Core plugins startup ---- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Loading plugins from folder /volumio/app/plugins/ Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Adding plugin upnp to MyMusic Plugins Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Loading plugins from folder /data/plugins/ Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Loading plugin "system"... Dec 10 20:48:39 gbvpi-bedroom volumio[19558]: info: Loading plugin "appearance"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "network"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Refreshing Cached IP Addresses Dec 10 20:48:40 gbvpi-bedroom sudo[19592]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 20:48:40 gbvpi-bedroom sudo[19592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:40 gbvpi-bedroom sudo[19594]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 20:48:40 gbvpi-bedroom sudo[19594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:40 gbvpi-bedroom sudo[19592]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "services"... Dec 10 20:48:40 gbvpi-bedroom sudo[19594]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "alsa_controller"... Dec 10 20:48:40 gbvpi-bedroom sudo[19601]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 10 20:48:40 gbvpi-bedroom sudo[19601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "wizard"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "networkfs"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Starting Udev Watcher for removable devices Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Ignoring mount for partition: boot Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Ignoring mount for partition: volumio Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Ignoring mount for partition: volumio_data Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "volumio_command_line_client"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "upnp"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: [1765417720339] Starting Upmpd Daemon Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "my_music"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "mpd"... Dec 10 20:48:40 gbvpi-bedroom volumio[19558]: info: Loading plugin "upnp_browser"... Dec 10 20:48:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123. Dec 10 20:48:40 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:41 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:41 gbvpi-bedroom go-librespot[19625]: go-librespot daemon starting... Dec 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-05:00" level=debug msg="app state loaded" Dec 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Starting UPNP Browser Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "alarm-clock"... Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "airplay_emulation"... Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Starting Shairport Sync Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "last_100"... Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "webradio"... Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "i2s_dacs"... Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: I2S DAC not set, start Auto-detection Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "volumiodiscovery"... Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: *** WARNING *** For more information see Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: *** WARNING *** For more information see Dec 10 20:48:41 gbvpi-bedroom node[19558]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:41 gbvpi-bedroom node[19558]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:41 gbvpi-bedroom node[19558]: *** WARNING *** For more information see Dec 10 20:48:41 gbvpi-bedroom node[19558]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 10 20:48:41 gbvpi-bedroom node[19558]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 10 20:48:41 gbvpi-bedroom node[19558]: *** WARNING *** For more information see Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-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 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-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 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-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 10 20:48:41 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "jellyfin"... Dec 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-05:00" level=info msg="zeroconf server listening on port 44759" Dec 10 20:48:41 gbvpi-bedroom volumio[19558]: info: Loading plugin "spop"... Dec 10 20:48:41 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:41-05:00" level=debug msg="obtained new client token: AADtY8MN3ZY8wfTYWCJ34kI2q/0dPF6MEYhDpBFHtRsqWVE9Lj4CExNRvB4mQmyUYgLGbMRr1H3RKu5DzAMOK85Ui73v6vdpbzX9ukzsBFaZvBVRKQL3ILVeoO8eexyHCKNWXpZjWFbQ+jC3G641GEU56QDfu8f73GN7bUbfM+XvAbykLGnkPpGJbEdvbORYzYq1zQc1yiomJrxHjdegTK2O7IsYucl7t9aYq+AGFlmTVgO4uZxsj3PpPg==" Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading plugin "outputs"... Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading plugin "albumart"... Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Plugin example_plugin is not enabled Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading plugin "inputs"... Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading plugin "updater_comm"... Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Plugin mpdemulation is not enabled Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading plugin "rest_api"... Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading plugin "websocket"... Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Starting Socket.io Server version 1.7.4 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Loading i18n strings for locale en Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: Updating browse sources language Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::initPlayerControls Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: Express server listening on port 3000 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: [Metrics] WebUI: 3s 819.36ms Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::resetVolumioState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::getcurrentVolume Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 20:48:42 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:42] [connect] Successful connection Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Volumio Network Manager: Network status updated: 2 Dec 10 20:48:42 gbvpi-bedroom volumio[19636]: Forking 3 albumart workers Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: No valid Plugin REST Endpoint Dec 10 20:48:42 gbvpi-bedroom vtcs[19578]: BYE TidalConnect Dec 10 20:48:42 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 10 20:48:42 gbvpi-bedroom volumio-remote-updater[775]: [2025-12-10 20:48:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765417722 101 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: 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 10 20:48:42 gbvpi-bedroom volumio[19558]: info: VolumeController:: Volume=91 Mute =false Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::pushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::updateTrackBlock Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrackBlock Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Reloading queue from file Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::setRepeat true single undefined Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::pushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::setRandom null Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::pushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: Setting Device type: Raspberry PI Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 10 20:48:42 gbvpi-bedroom systemd[1]: vtcs.service: Scheduled restart job, restart counter is at 4. Dec 10 20:48:42 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: VolumeController:: Volume=91 Mute =false Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::pushState Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:42 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioPushState Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Completed loading Core Plugins Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Preparing to generate the ALSA configuration file Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Asound.conf file written Dec 10 20:48:43 gbvpi-bedroom sudo[19695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 10 20:48:43 gbvpi-bedroom sudo[19695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:43 gbvpi-bedroom sudo[19695]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Output device has changed, restarting MPD Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Output device has changed, restarting Shairport Sync Dec 10 20:48:43 gbvpi-bedroom sudo[19702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 20:48:43 gbvpi-bedroom sudo[19702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:43 gbvpi-bedroom sudo[19702]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:43 gbvpi-bedroom sudo[19703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 20:48:43 gbvpi-bedroom sudo[19703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: ___________ START PLUGINS ___________ Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: ControllerMpd::onStart: Initializing MPD Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Creating MPD Configuration file Dec 10 20:48:43 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: [1765417723272] CoreMusicLibrary::Adding element Media Servers Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: UPNP Browser: Client initialized successfully Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 20:48:43 gbvpi-bedroom sudo[19711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 20:48:43 gbvpi-bedroom sudo[19711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:43 gbvpi-bedroom sudo[19711]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:43 gbvpi-bedroom sudo[19713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 20:48:43 gbvpi-bedroom sudo[19713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:43 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.266s CPU time. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: [1765417723381] CoreMusicLibrary::Adding element Last_100 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: [1765417723384] CoreMusicLibrary::Adding element Webradio Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Initializing BBC Radios Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 20:48:43 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:43-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:43 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:43-05:00" level=debug msg="completed challenge" Dec 10 20:48:43 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 20:48:43 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Discovery: Getting this device information Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: [1765417723527] CoreMusicLibrary::Adding element Jellyfin Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: Cannot find translation for source Jellyfin Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: 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/6483a073f2c9b346a09e98bd65fe1753/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"The Mountain Goats & John Vanderslice","mute":false,"status":"stop","track":"Surrounded","volume":91},"type":"device"} Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Creating Spotify config file Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:43 gbvpi-bedroom go-librespot[19626]: time="2025-12-10T20:48:43-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:48:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:43 gbvpi-bedroom sudo[19737]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 20:48:43 gbvpi-bedroom sudo[19737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 20:48:43 gbvpi-bedroom sudo[19737]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:43 gbvpi-bedroom volumio[19558]: info: Volumio Calling Home Dec 10 20:48:43 gbvpi-bedroom volumio[19653]: Starting albumart workers Dec 10 20:48:43 gbvpi-bedroom volumio[19651]: Starting albumart workers Dec 10 20:48:43 gbvpi-bedroom volumio[19652]: Starting albumart workers Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Discovery: Found device GBVPi-Bedroom Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Discovery: Found device GBVPi-Bedroom Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: MPD Permissions set Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: MPD Permissions set Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: No valid Plugin REST Endpoint Dec 10 20:48:44 gbvpi-bedroom vtcs[19692]: BYE TidalConnect Dec 10 20:48:44 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Spotify config file written Dec 10 20:48:44 gbvpi-bedroom sudo[19747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 10 20:48:44 gbvpi-bedroom sudo[19747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: 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 10 20:48:44 gbvpi-bedroom sudo[19601]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:44 gbvpi-bedroom go-librespot[19749]: go-librespot daemon starting... Dec 10 20:48:44 gbvpi-bedroom systemd[1]: vtcs.service: Scheduled restart job, restart counter is at 5. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: vtcs.service: Start request repeated too quickly. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: vtcs.service: Failed with result 'start-limit-hit'. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Failed to start vtcs.service - Volumio Tidal Connect Service. Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom sudo[19747]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=debug msg="app state loaded" Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: No need to fix Spotify hosts Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48: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 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48: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 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48: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 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=info msg="zeroconf server listening on port 43119" Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Volumio called home Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=debug msg="obtained new client token: AACV4Lm6KzR99KDfyUAQk9q7t/rjr+Oo0eH8V5C2rJ25gjBFwW6hx4lR9lpr/SO3dInn8tqTsCEDUinSLe2SQtqRyb4m0taHj/otGmiKJqeO0ZRXgq8/zW1oreV7doFr3F7b7Ts6lYkLGWHYS9rvdu8De226BeDtpAgwatzH90z3qLmCMMHVTJhWX/0DoRgRyoLOp9ovmwBfIQkljvlGFs161uBG8DwHp95qMT50TW2gR6kw4E3ZOqPLUQ==" Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Starting Shairport Sync Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Starting Shairport Sync Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: Starting Shairport Sync Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48:44-05:00" level=debug msg="completed challenge" Dec 10 20:48:44 gbvpi-bedroom sudo[19787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:44 gbvpi-bedroom sudo[19787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 10 20:48:44 gbvpi-bedroom sudo[19792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:44 gbvpi-bedroom sudo[19792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:44 gbvpi-bedroom sudo[19789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:48:44 gbvpi-bedroom go-librespot[19755]: time="2025-12-10T20:48: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 10 20:48:44 gbvpi-bedroom sudo[19789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:44 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 20:48:44 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:48:44 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.588s CPU time. Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:44 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:44 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:48:44 gbvpi-bedroom sudo[19789]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:45 gbvpi-bedroom sudo[19787]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:45 gbvpi-bedroom sudo[19792]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: Shairport-Sync Started Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: Error adding Membership: Error: addMembership EINVAL Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: Shairport-Sync Started Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: Shairport-Sync Started Dec 10 20:48:45 gbvpi-bedroom mpd[19742]: 2025-12-10T20:48:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 20:48:45 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 20:48:45 gbvpi-bedroom sudo[19703]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:45 gbvpi-bedroom sudo[19713]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: error: updateQueue error: null Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: Completed starting Core Plugins Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: ----- MyVolumio plugins startup ---- Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: ------------------------------------------- Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: error: updateQueue error: null Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: info: MPD running with PID19742 Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: ,establishing connection Dec 10 20:48:45 gbvpi-bedroom volumio[19558]: error: updateQueue error: null Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:48:46 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:48:47 gbvpi-bedroom volumio[19558]: info: go-librespot daemon successfully initialized Dec 10 20:48:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Dec 10 20:48:47 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:48 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:48 gbvpi-bedroom go-librespot[19815]: go-librespot daemon starting... Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=debug msg="app state loaded" Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-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 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-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 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-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 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=info msg="zeroconf server listening on port 44327" Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=debug msg="obtained new client token: AAD0Aw6Is/hf9xFgQqs1CwaNpyHr9CM/sZmSUeSaWGEQkKDZCTe6QnXQm9tpij0EilAXVdkx6fd5oNPDyWGPX0mXfZLXc0AwRrrQ5k4kjm36BJ4MTQCBxORBhZ/MhVCXp3NTw9RGsMI5WJqCYdYL1PPpKzRFe7PsWV1k7/9Esfu83pu9WBlaAGkLug7ViWy2pPS1i5FS3MesD1V/729oI9629qGLhX5/0G+CPbFJTb7KgwSs1zeDk22lyg==" Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:48 gbvpi-bedroom sudo[19824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 20:48:48 gbvpi-bedroom sudo[19824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48:48-05:00" level=debug msg="completed challenge" Dec 10 20:48:48 gbvpi-bedroom sudo[19826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 20:48:48 gbvpi-bedroom sudo[19826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:48 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 20:48:48 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 20:48:48 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 20:48:48 gbvpi-bedroom go-librespot[19816]: time="2025-12-10T20:48: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 10 20:48:48 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 20:48:48 gbvpi-bedroom sudo[19824]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:48 gbvpi-bedroom sudo[19826]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:48 gbvpi-bedroom mpd_monitor.sh[19829]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 20:48:48 gbvpi-bedroom volumio[19558]: info: Successfully started MPD Monitor Dec 10 20:48:48 gbvpi-bedroom volumio[19558]: info: Successfully started MPD Monitor Dec 10 20:48:50 gbvpi-bedroom sudo[19848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 20:48:50 gbvpi-bedroom sudo[19848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:50 gbvpi-bedroom sudo[19850]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 20:48:50 gbvpi-bedroom sudo[19850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:50 gbvpi-bedroom sudo[19848]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:50 gbvpi-bedroom sudo[19850]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:50 gbvpi-bedroom sudo[19852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 10 20:48:50 gbvpi-bedroom sudo[19852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:50 gbvpi-bedroom sudo[19852]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:50 gbvpi-bedroom volumio[19558]: info: Upmpdcli Daemon Started Dec 10 20:48:50 gbvpi-bedroom volumio[19558]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 10 20:48:50 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:50 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Dec 10 20:48:51 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:51 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:51 gbvpi-bedroom go-librespot[19856]: go-librespot daemon starting... Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=debug msg="app state loaded" Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 10 20:48:51 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:51-05:00" level=info msg="zeroconf server listening on port 41455" Dec 10 20:48:52 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:52-05:00" level=debug msg="obtained new client token: AABsRhH3gfsFBJnX8EFsbTILuMqaw8hqRfNg9SUucDU3kl5lZvXf0hHrSSk5sd3PnryWQShSW2+JqM6Wz9qf/7ApRyNhrHGGeKxuYWFxWbY4W9/W80HskuTIlQONC1iS2VoqgkM8eVhuFX8A0MbznE2nT1aNuBw8SP2ZYOUS+SVs0aLKP9JYYAUUOAifiQ9FTeu3mw+bW+fuSnkiisIAEtfr3dwG3xNhVL4s8nzrm3TxF/6WqNg1McA=" Dec 10 20:48:52 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:52 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:52-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:52 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48:52-05:00" level=debug msg="completed challenge" Dec 10 20:48:52 gbvpi-bedroom go-librespot[19857]: time="2025-12-10T20:48: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 10 20:48:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin bluetooth to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin multiroom to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin metavolumio to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin cd_controller to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 10 20:48:53 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: Starting MyVolumio Remote Streaming Endpoints Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: MyVolumio login type: Token Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: Streaming services startup Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: Starting Streaming Daemon Dec 10 20:48:54 gbvpi-bedroom sudo[19866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 10 20:48:54 gbvpi-bedroom sudo[19866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 10 20:48:54 gbvpi-bedroom sudo[19866]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: error: Cannot start Volumio Streaming Daemon Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 10 20:48:54 gbvpi-bedroom volumio[19558]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 10 20:48:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Dec 10 20:48:55 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:55 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:55 gbvpi-bedroom go-librespot[19872]: go-librespot daemon starting... Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=debug msg="app state loaded" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MyVolumio token set successfully Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MYVOLUMIO: Adding device Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MYVOLUMIO: Evaluating Server Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-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 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-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 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=info msg="zeroconf server listening on port 35647" Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MyVolumio Plan changed: premium Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Removing browser output: myVolumio user plan is not superstar Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Removing audio output: Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MYVOLUMIO: Adding device Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MYVOLUMIO: Evaluating Server Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Remote config written successfully Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Starting Tunnel 1 Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Starting Tunnel Connection Checker Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Completed starting MyVolumio Plugin Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=debug msg="obtained new client token: AACeBsr+Ik1exj+rKQrr6vE4pjjm4UBaxBuxMgoupm32PhWahrmJcdU1bkwMoeb1cR3QCWUV3bt/r3x7yGQuvfBSvBfkL//JoNiio6ExJ+CSUBOkwvlPsPMxBwrqICACPXDLvFh8zcQNijGDme3Tuu1kVVnfBQvJqiy5bjO3oRWHdMZNbnTs1bc6OU+vQhen1QksZb8dQkCP085iCraZuPIXHcSj7LyELmHSU6ofd4N0bSHJnOAqyvwF2A==" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48:55-05:00" level=debug msg="completed challenge" Dec 10 20:48:55 gbvpi-bedroom go-librespot[19873]: time="2025-12-10T20:48: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 10 20:48:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MYVolumio Device enabled Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: MyVolumio status changed Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Streaming services startup Dec 10 20:48:55 gbvpi-bedroom volumio[19558]: info: Starting Streaming Daemon Dec 10 20:48:56 gbvpi-bedroom sudo[19920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 10 20:48:56 gbvpi-bedroom sudo[19920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 10 20:48:56 gbvpi-bedroom sudo[19920]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 10 20:48:56 gbvpi-bedroom sudo[19924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 10 20:48:56 gbvpi-bedroom sudo[19924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:56 gbvpi-bedroom sudo[19924]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: MRS: MultiRoom plugin initialized Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: MRS: STOPPING SNAPCLIENT Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: MRS: Snap server stop Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: MRS: STOPPING volumioStreaming Dec 10 20:48:56 gbvpi-bedroom sudo[19941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 10 20:48:56 gbvpi-bedroom sudo[19941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 10 20:48:56 gbvpi-bedroom sudo[19943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 10 20:48:56 gbvpi-bedroom sudo[19943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:56 gbvpi-bedroom sudo[19946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 10 20:48:56 gbvpi-bedroom sudo[19946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 10 20:48:56 gbvpi-bedroom sudo[19949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 10 20:48:56 gbvpi-bedroom sudo[19949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:56 gbvpi-bedroom sudo[19949]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 10 20:48:56 gbvpi-bedroom sudo[19941]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:56 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 10 20:48:57 gbvpi-bedroom sudo[19943]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:57 gbvpi-bedroom sudo[19946]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Preparing to generate the ALSA configuration file Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Setting Geolocation for MyVolumio to us1 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Setting Geolocation for MyVolumio to us1 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Reading ALSA contributions from plugins. Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: Removed streaming files Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: volumioStreaming STOPPED Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: SNAPSERVER STOPPED Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: SNAPCLIENT STOPPED Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: error: Cannot start Volumio Streaming Daemon Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Asound.conf file written Dec 10 20:48:57 gbvpi-bedroom sudo[19954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 10 20:48:57 gbvpi-bedroom sudo[19954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:57 gbvpi-bedroom sudo[19954]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Output device has changed, restarting MPD Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Output device has changed, restarting Shairport Sync Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:48:57 gbvpi-bedroom sudo[19960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 20:48:57 gbvpi-bedroom sudo[19960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:57 gbvpi-bedroom sudo[19960]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:57 gbvpi-bedroom sudo[19962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 20:48:57 gbvpi-bedroom sudo[19962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 10 20:48:57 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: Pushing multiroomSync output for this device Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: Pushing multiroomSync output Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding audio output: Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding audio output: Dec 10 20:48:57 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 10 20:48:57 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 20:48:57 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.826s CPU time. Dec 10 20:48:57 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 10 20:48:57 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 20:48:57 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 20:48:57 gbvpi-bedroom bluetoothd[763]: Path / reserved for Adv Monitor app :1.10156 Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:48:57 gbvpi-bedroom bluetoothd[763]: Adv Monitor app :1.10156 disconnected from D-Bus Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding METAVOLUMIO REST API Endpoints Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Preparing CD Folders Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding CD REST API Endpoints Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Starting UDEV Watcher for CD Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: Detecting CD presence with UDEV Dec 10 20:48:57 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 10 20:48:57 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 20:48:57 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 20:48:57 gbvpi-bedroom sudo[19980]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 20:48:57 gbvpi-bedroom sudo[19980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 20:48:57 gbvpi-bedroom sudo[19980]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:58 gbvpi-bedroom mpd[19983]: 2025-12-10T20:48:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 20:48:58 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 20:48:58 gbvpi-bedroom sudo[19962]: pam_unix(sudo:session): session closed for user root Dec 10 20:48:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Dec 10 20:48:59 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:59 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:48:59 gbvpi-bedroom go-librespot[19986]: go-librespot daemon starting... Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=debug msg="app state loaded" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48: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-gew4.spotify.com:80]" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-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 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-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 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=info msg="zeroconf server listening on port 44377" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=debug msg="obtained new client token: AAAY8mn84+CDmWduIrOdCqHnEJOWmAOZMj2Y/bL48hP3A7xWI9IfepVS0JJlI2fEUTe4Pr3S0KdMj9Coizyw+CwniLQNM5d14o3/W9x4F7zfhdXPeZnS3UQc/9APXWkeQOtaasRKCam/+M2efmdtW0saBk59Pj4grTSZDDPm+udpD8JTAwBLOXz7ac4fRoWR1q2DSSrM/7YpqPJnkxMcqvtuSBm3nUDRC7vC9z6kTUBLukuctBmgsKR1yA==" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=debug msg="completed keyexchange" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48:59-05:00" level=debug msg="completed challenge" Dec 10 20:48:59 gbvpi-bedroom go-librespot[19987]: time="2025-12-10T20:48: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 10 20:48:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:48:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding inputs REST Endpoints Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Scanning Audio Inputs Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Checking against Known Cards name Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding Server instance for streaming Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: error: Hi Res Audio Failed Login: Missing Login Data Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 10 20:49:02 gbvpi-bedroom sudo[20012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 10 20:49:02 gbvpi-bedroom sudo[20012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 10 20:49:02 gbvpi-bedroom sudo[20019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 10 20:49:02 gbvpi-bedroom sudo[20019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding TIDAL REST API Endpoints Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Stopping AccessToken refresher cron for QOBUZ Dec 10 20:49:02 gbvpi-bedroom sudo[20012]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:02 gbvpi-bedroom sudo[20019]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: AccessToken refresher cron started for QOBUZ Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding QOBUZ REST API Endpoints Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Updating MyVolumio device info Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom sudo[20022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom sudo[20022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Updating MyVolumio device info Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: MRS: Getting audio outputs on start Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: MRS: Requesting all other devices output Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Successfully Added MyVolumio device Dec 10 20:49:02 gbvpi-bedroom qobuz-connect[19497]: 20251210 20:49:02.591 [19497.19497] INFO SampleApp: Stopping Local configuration server Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Successfully Added MyVolumio device Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: MPD Permissions set Dec 10 20:49:02 gbvpi-bedroom sudo[20025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 10 20:49:02 gbvpi-bedroom sudo[20025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:02 gbvpi-bedroom sudo[20025]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioStop Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::stop Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: error: updateQueue error: null Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding audio output: Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Starting Shairport Sync Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:02 gbvpi-bedroom go-librespot[20036]: go-librespot daemon starting... Dec 10 20:49:02 gbvpi-bedroom sudo[20041]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 10 20:49:02 gbvpi-bedroom sudo[20041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9 Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Adding audio output: Dec 10 20:49:02 gbvpi-bedroom sudo[20043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 20:49:02 gbvpi-bedroom sudo[20043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:02 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:49:02 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:02-05:00" level=debug msg="app state loaded" Dec 10 20:49:02 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Successfully Updated MyVolumio device Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 20:49:02 gbvpi-bedroom autossh[19479]: received signal to exit (15) Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 10 20:49:02 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.622s CPU time. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 20:49:02 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 10 20:49:02 gbvpi-bedroom sudo[20041]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Remote SSH Started Dec 10 20:49:02 gbvpi-bedroom sudo[20043]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:02 gbvpi-bedroom autossh[20054]: port set to 0, monitoring disabled Dec 10 20:49:02 gbvpi-bedroom autossh[20054]: starting ssh (count 1) Dec 10 20:49:02 gbvpi-bedroom autossh[20054]: ssh child pid is 20057 Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: info: Shairport-Sync Started Dec 10 20:49:02 gbvpi-bedroom volumio[19558]: 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 10 20:49:03 gbvpi-bedroom volumiossh-tunnel[20057]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-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 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-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 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-05:00" level=info msg="zeroconf server listening on port 38675" Dec 10 20:49:03 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 10 20:49:03 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 10 20:49:03 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 10 20:49:03 gbvpi-bedroom sudo[20022]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: Executing endpoint qc_getconfig Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.178 [20074.20074] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.181 [20074.20074] INFO VolumeManager: [0x16ff588]: Setting new playback volume: 75 Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.182 [20074.20074] INFO VolumeManager: [0x16ff588]: Setting new mute state: 0 Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.182 [20074.20074] INFO QobuzConnect: [0x16fff58]: Client initialized! Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.182 [20074.20074] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-05:00" level=debug msg="obtained new client token: AACOSi6ZNocJSsdqDMrN+hiIMTEC8hUSaYeWGhBD9scSJNixe0+BveCakKRFvr1MW1Mold47plUhX1yJCwKN+0WrpHJk+9MyKBeB/JCuhr5F6ibwuakTbYrK8X1WUYFomV/5QyyRNVjiFaJ2m8ltuQUM8QkeyRnTXq68NOxNe1KKQbPlDgqRBwYagFXSkExmwSRTEp2YkWIdGzARAE6VePoWB1+AHojBIO21cpp7pNm4ZT6NkpJNSEw=" Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.194 [20074.20074] INFO LocalConfigManager: [0x16fee68]: Starting Local Configuration server Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.194 [20074.20074] INFO SampleApp: Starting Local configuration server Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.195 [20074.20074] INFO SampleApp: Connected to UNIX socket client 0x16e9818 Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: Successfully Updated MyVolumio device Dec 10 20:49:03 gbvpi-bedroom qobuz-connect[20074]: 20251210 20:49:03.327 [20074.20074] INFO SampleApp: Playback volume changed: 75 Dec 10 20:49:03 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-05:00" level=debug msg="completed keyexchange" Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49:03-05:00" level=debug msg="completed challenge" Dec 10 20:49:03 gbvpi-bedroom go-librespot[20044]: time="2025-12-10T20:49: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 10 20:49:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:49:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: TidalConnect service stoped! Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 10 20:49:05 gbvpi-bedroom sudo[20089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 10 20:49:05 gbvpi-bedroom sudo[20089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:05 gbvpi-bedroom sudo[20093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 20:49:05 gbvpi-bedroom sudo[20093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 20:49:05 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:49:05 gbvpi-bedroom sudo[20089]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:05 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 20:49:05 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 20:49:05 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 20:49:05 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 20:49:05 gbvpi-bedroom sudo[20093]: pam_unix(sudo:session): session closed for user root Dec 10 20:49:05 gbvpi-bedroom mpd_monitor.sh[20097]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Successfully started MPD Monitor Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Executing endpoint tc_getconfig Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 10 20:49:05 gbvpi-bedroom vtcs[20095]: STARTING TidalConnect services, version: 1.5.2.56 Dec 10 20:49:05 gbvpi-bedroom vtcs[20095]: STARTED TidalConnect services. Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Executing endpoint tc_connect Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Connecting to TidalConnect Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::servicePushState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::pushState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioPushState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: MRS: Pushing multiroomSync output update for this device Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: MRS: Pushing multiroomSync output Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::servicePushState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreStateMachine::pushState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioPushState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: MRS: Pushing multiroomSync output update for this device Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: MRS: Pushing multiroomSync output Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: CorePlayQueue::getTrack 0 Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 10 20:49:05 gbvpi-bedroom volumio[19558]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status' Dec 10 20:49:06 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:06 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:06 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:06 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:06 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:06 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129. Dec 10 20:49:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:06 gbvpi-bedroom go-librespot[20115]: go-librespot daemon starting... Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=debug msg="app state loaded" Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 10 20:49:06 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:06-05:00" level=info msg="zeroconf server listening on port 42215" Dec 10 20:49:07 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:07-05:00" level=debug msg="obtained new client token: AAA0AQvt9PkA9etGEyKdUow4LsbAkVZOAElsnRHJWcQ0LWaUMeh5XIv2uxRqap9/uRvfMKew+Y0FgpwT8yKu93gLOwrvSQUEsBz1oqKW8OLe8I2hggdW59FoGI6oHXNdvm4U7VQR+M+ODmxWgptnmBohWVe5SQrPodNlhDyLx4l8OE/kZia+eAyYdLS7waYZRs94RTKEuuyuDxZ333lLzCI+V7lfksjSUsUMy2dbw8FLWCoEthohIQc=" Dec 10 20:49:07 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:49:07 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:07-05:00" level=debug msg="completed keyexchange" Dec 10 20:49:07 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:07-05:00" level=debug msg="completed challenge" Dec 10 20:49:07 gbvpi-bedroom go-librespot[20116]: time="2025-12-10T20:49:07-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 10 20:49:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:49:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: TidalConnect service started! Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: [Metrics] CommandRouter: 29s 567.50ms Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumiosetStartupVolume Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::Close All Modals sent Dec 10 20:49:08 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::Close All Modals sent Dec 10 20:49:09 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 10 20:49:09 gbvpi-bedroom volumio[19558]: 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 10 20:49:09 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:09 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 10 20:49:09 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 10 20:49:09 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 10 20:49:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130. Dec 10 20:49:10 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:10 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:10 gbvpi-bedroom go-librespot[20126]: go-librespot daemon starting... Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=debug msg="app state loaded" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-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 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-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 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-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 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=info msg="zeroconf server listening on port 39227" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=debug msg="obtained new client token: AAC3EHzQD5DmD2831IWdhrgp5Z+PIL0yx5fVwn6fT+K5XrUSe5AsiDKYzFm/s5p14RaIOE8hqx0HR+NgJMZU2Mg+zRvp/Kah9ycDTzMni0CK0GpU6cC/pxpWy+fWEAxcDQQ+GxIX6FUHdhAXYjRVDpb87PQgObemg2tZ5eBXUkzHSxlwHMGd6iIGLPRsSkTok/Mkm96TVmYmIB+o6r9DLLgFMTpNyGjNSvGa59DztSk8K5WQiB0gpFS2Fw==" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=debug msg="completed keyexchange" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=debug msg="completed challenge" Dec 10 20:49:10 gbvpi-bedroom go-librespot[20127]: time="2025-12-10T20:49:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 10 20:49:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:49:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:49:11 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:11 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:49:13 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:49:13 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 20:49:13 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 10 20:49:13 gbvpi-bedroom volumio-remote-updater[775]: Test mode enabled Dec 10 20:49:13 gbvpi-bedroom volumio-remote-updater[775]: Alpha mode disabled Dec 10 20:49:13 gbvpi-bedroom volumio-remote-updater[775]: Alpha legacy test mode disabled Dec 10 20:49:13 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 10 20:49:13 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 131. Dec 10 20:49:13 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:13 gbvpi-bedroom volumio[19558]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

CAUTION

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

FIX

\n
    \n
  • Wireless and network handling
    • \n
\n","title":"Update v4.078","updateavailable":true} Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 10 20:49:14 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:14 gbvpi-bedroom go-librespot[20152]: go-librespot daemon starting... Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=debug msg="app state loaded" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-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 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-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 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-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 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=info msg="zeroconf server listening on port 37583" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=debug msg="obtained new client token: AAA75V1fUPKAyQFzSIV43OaYPWa5zSmQ/foMQ1U5/Z25hPx4iJ1qWcmSRTQlaWH3ZXFDYzS8GdXXeZHWvM5g2VvCXY9OVf6Tu+9YBYetKQ0kkpRmrZ6S+WkQ7Y+LHxQje4OqThXh/ArjcNOsoO/9TmnlhJrAwkPjgG5tizjuW629IeP3A+lG0wOuPlDoaJhu0rNdYCTZ3St0cmy2tkzvsFjISjX7QFxtw1mHq55vySTp3wik50Kj5Zzoqw==" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetBrowseSources Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=debug msg="completed keyexchange" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-05:00" level=debug msg="completed challenge" Dec 10 20:49:14 gbvpi-bedroom go-librespot[20154]: time="2025-12-10T20:49:14-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 10 20:49:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:49:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:14 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:49:15 gbvpi-bedroom volumio[19558]: info: BOOT COMPLETED Dec 10 20:49:16 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:16 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:17 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:17 gbvpi-bedroom volumio[19558]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 20:49:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132. Dec 10 20:49:17 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:17 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 20:49:17 gbvpi-bedroom go-librespot[20161]: go-librespot daemon starting... Dec 10 20:49:17 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:17-05:00" level=info msg="running go-librespot 0.4.0" Dec 10 20:49:17 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:17-05:00" level=debug msg="app state loaded" Dec 10 20:49:17 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:17-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 20:49:17 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 10 20:49:17 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:17-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 10 20:49:17 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:17-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 10 20:49:18 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:18-05:00" level=info msg="zeroconf server listening on port 40945" Dec 10 20:49:18 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:18-05:00" level=debug msg="obtained new client token: AABovLE1tRqLrOM+3LUDkHXbbC2/xJ410PU20GCIn1uFUjsoeLWD+nUjYPOE/IDTmlEXLrLKEudvqPHyo3IlzdZVket993+aMIAjAFrtJPUoP8zsfll7CFvQCOqnXAY0JLkEZxVVZJnf92wapP4kuKJewW/vcnaL4jIr4M97EsqRino/PgRMJ9MdXQ1QXVym37DxMKtyHnf5xrFUrMRz1z4sgvlklnzr6ivMIKwyZOgxfAT/eSB9XOk=" Dec 10 20:49:18 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 10 20:49:20 gbvpi-bedroom volumio[19558]: info: Initializing connection to go-librespot Websocket Dec 10 20:49:20 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:20-05:00" level=debug msg="new websocket client" Dec 10 20:49:20 gbvpi-bedroom volumio[19558]: info: Connection to go-librespot Websocket established Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: info: Getting Spotify volume Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: SPOTIFY: SPOTIFY VOLUME undefined Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: SPOTIFY: VOLUMIO VOLUME 91 Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: info: Aligning Spotify Volume to Volumio Volume Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:23 gbvpi-bedroom volumio[19558]: info: Setting Spotify Volume from Volumio: 91 Dec 10 20:49:25 gbvpi-bedroom volumio[19558]: SPOTIFY: SETTING SPOTIFY VOLUME 91 Dec 10 20:49:25 gbvpi-bedroom volumio[19558]: info: Sending Spotify command with payload to local API: /player/volume Dec 10 20:49:26 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:26 gbvpi-bedroom volumio[19558]: info: CoreCommandRouter::volumioGetState Dec 10 20:49:26 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:26 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:26 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:26 gbvpi-bedroom volumio[19558]: info: Listing playlists Dec 10 20:49:32 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:32-05:00" level=debug msg="completed keyexchange" Dec 10 20:49:32 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49:32-05:00" level=debug msg="completed challenge" Dec 10 20:49:32 gbvpi-bedroom go-librespot[20162]: time="2025-12-10T20:49: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 10 20:49:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 20:49:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: Error: socket hang up Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: at connResetException (node:internal/errors:720:14) Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: at Socket.emit (node:events:526:35) Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: code: 'ECONNRESET', Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: response: undefined Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: } Dec 10 20:49:32 gbvpi-bedroom volumio[19558]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 20:49:32 gbvpi-bedroom sudo[20218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-10 20:48' Dec 10 20:49:32 gbvpi-bedroom sudo[20218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="6a0bffa825dc2af90b21170949f5219ba5ab5701" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Dec 10 09:27:23 UTC 2025" VOLUMIO_VERSION="4.075" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4bd01f93a654c7068f4553fbd69478e2"