Dec 07 02:14:00 gbvpi-bedroom volumio[477]: info: MRS: Pushing audio output on request Dec 07 02:14:00 gbvpi-bedroom volumio[477]: info: MRS: Pushing multiroomSync output Dec 07 02:14:00 gbvpi-bedroom volumio[477]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 02:14:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Dec 07 02:14:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:01 gbvpi-bedroom go-librespot[1083]: go-librespot daemon starting... Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="app state loaded" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=info msg="zeroconf server listening on port 45693" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="obtained new client token: AACae32e+ND9ssdNgsyWb7bBlRX+545mMHAFTpPJ7nzxQX+gotOhpCmNbtHnyUXlWhKL1j2QVqPLEfiywryFwXWe1SQf+wwkBr0WMWfy02IWoiWaJJbwP2XBVs0lW0q9DGqIa0e2TfT97fyonVikrncExC50yVcpBkmJauDBYIVAh+ONolJii0m7xE9P1FtWDhhNpNGRc1hOchQAdKiE+FtIrFt3ohMpHyKOXtV0/k8FmCR/+JHyWS+yuA==" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:01 gbvpi-bedroom volumio[477]: info: Initializing connection to go-librespot Websocket Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="new websocket client" Dec 07 02:14:01 gbvpi-bedroom volumio[477]: info: Connection to go-librespot Websocket established Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:01 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:01-05:00" level=debug msg="completed challenge" Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: TidalConnect service started! Dec 07 02:14:02 gbvpi-bedroom volumio[477]: [Metrics] CommandRouter: 29s 123.57ms Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::volumiosetStartupVolume Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::Close All Modals sent Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::Close All Modals sent Dec 07 02:14:02 gbvpi-bedroom go-librespot[1084]: time="2025-12-07T02:14:02-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: Connection to go-librespot Websocket closed Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 02:14:02 gbvpi-bedroom volumio[477]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 07 02:14:02 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:03 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 07 02:14:03 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 07 02:14:03 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 07 02:14:03 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:03 gbvpi-bedroom volumio[477]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:04 gbvpi-bedroom volumio[477]: info: Getting Spotify volume Dec 07 02:14:05 gbvpi-bedroom volumio[477]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:14:05 gbvpi-bedroom volumio[477]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 02:14:05 gbvpi-bedroom volumio[477]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 07 02:14:05 gbvpi-bedroom volumio[477]: errno: -111, Dec 07 02:14:05 gbvpi-bedroom volumio[477]: code: 'ECONNREFUSED', Dec 07 02:14:05 gbvpi-bedroom volumio[477]: syscall: 'connect', Dec 07 02:14:05 gbvpi-bedroom volumio[477]: address: '127.0.0.1', Dec 07 02:14:05 gbvpi-bedroom volumio[477]: port: 9879, Dec 07 02:14:05 gbvpi-bedroom volumio[477]: response: undefined Dec 07 02:14:05 gbvpi-bedroom volumio[477]: } Dec 07 02:14:05 gbvpi-bedroom volumio[477]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:14:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:05 gbvpi-bedroom go-librespot[1120]: go-librespot daemon starting... Dec 07 02:14:05 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:05-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:05 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:05-05:00" level=debug msg="app state loaded" Dec 07 02:14:05 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:05 gbvpi-bedroom sudo[1130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 02:13' Dec 07 02:14:05 gbvpi-bedroom sudo[1130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:05 gbvpi-bedroom sudo[1130]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:05 gbvpi-bedroom vtcs[1061]: [2025-12-07 02:14:05.554] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 07 02:14:05 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:05 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 07 02:14:05 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 07 02:14:05 gbvpi-bedroom qobuz-connect[1018]: 20251207 02:14:05.557 [1018.1018] INFO SampleApp: Socket closed Dec 07 02:14:05 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: volumio.service: Consumed 20.597s CPU time. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2241. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: volumio.service: Consumed 20.597s CPU time. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 07 02:14:05 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 02:14:06 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:06 gbvpi-bedroom volumio[1149]: info: ----- Volumio3 ---- Dec 07 02:14:06 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:06 gbvpi-bedroom volumio[1149]: info: ----- System startup ---- Dec 07 02:14:06 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: MYVOLUMIO Environment detected Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Plugin folders cleanup Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning into folder /volumio/app/plugins/ Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category audio_interface Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category miscellanea Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category music_service Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category plugins.json Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category system_controller Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category user_interface Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning into folder /data/plugins/ Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Scanning category music_service Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Plugin folders cleanup completed Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: ----- Core plugins startup ---- Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugins from folder /volumio/app/plugins/ Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Adding plugin upnp to MyMusic Plugins Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugins from folder /data/plugins/ Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugin "system"... Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugin "appearance"... Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugin "network"... Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Refreshing Cached IP Addresses Dec 07 02:14:07 gbvpi-bedroom sudo[1178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 02:14:07 gbvpi-bedroom sudo[1178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:07 gbvpi-bedroom sudo[1178]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:07 gbvpi-bedroom sudo[1180]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 02:14:07 gbvpi-bedroom sudo[1180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugin "services"... Dec 07 02:14:07 gbvpi-bedroom volumio[1149]: info: Loading plugin "alsa_controller"... Dec 07 02:14:07 gbvpi-bedroom sudo[1180]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:07 gbvpi-bedroom sudo[1188]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 07 02:14:08 gbvpi-bedroom sudo[1188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "wizard"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "networkfs"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Starting Udev Watcher for removable devices Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Ignoring mount for partition: boot Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Ignoring mount for partition: volumio Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Ignoring mount for partition: volumio_data Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "volumio_command_line_client"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "upnp"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: [1765091648081] Starting Upmpd Daemon Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "my_music"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "mpd"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "upnp_browser"... Dec 07 02:14:08 gbvpi-bedroom volumio[1149]: info: Loading plugin "alarm-clock"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "airplay_emulation"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Starting Shairport Sync Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "last_100"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "webradio"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "i2s_dacs"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: I2S DAC not set, start Auto-detection Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "volumiodiscovery"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: *** WARNING *** For more information see Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:09 gbvpi-bedroom node[1149]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: *** WARNING *** For more information see Dec 07 02:14:09 gbvpi-bedroom node[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:09 gbvpi-bedroom node[1149]: *** WARNING *** For more information see Dec 07 02:14:09 gbvpi-bedroom node[1149]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:09 gbvpi-bedroom node[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:09 gbvpi-bedroom node[1149]: *** WARNING *** For more information see Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "jellyfin"... Dec 07 02:14:09 gbvpi-bedroom volumio[1149]: info: Loading plugin "spop"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading plugin "outputs"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading plugin "albumart"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Plugin example_plugin is not enabled Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading plugin "inputs"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading plugin "updater_comm"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Plugin mpdemulation is not enabled Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading plugin "rest_api"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading plugin "websocket"... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Starting Socket.io Server version 1.7.4 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Loading i18n strings for locale en Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: Updating browse sources language Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::initPlayerControls Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: Express server listening on port 3000 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: [Metrics] WebUI: 3s 675.29ms Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::resetVolumioState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::getcurrentVolume Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Volumio Network Manager: Network status updated: 2 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: VolumeController:: Volume=91 Mute =false Dec 07 02:14:10 gbvpi-bedroom volumio[1214]: Forking 3 albumart workers Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::pushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::updateTrackBlock Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrackBlock Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Reloading queue from file Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: VolumeController:: Volume=91 Mute =false Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::pushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:10 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:10 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:10 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:10 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:10-05:00" level=info msg="zeroconf server listening on port 41651" Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::setRepeat null single undefined Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::pushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::setRandom null Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::pushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Setting Device type: Raspberry PI Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 07 02:14:10 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:10] [connect] Successful connection Dec 07 02:14:10 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765091650 101 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Completed loading Core Plugins Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Preparing to generate the ALSA configuration file Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Asound.conf file written Dec 07 02:14:10 gbvpi-bedroom sudo[1276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 02:14:10 gbvpi-bedroom sudo[1276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:10 gbvpi-bedroom sudo[1276]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Output device has changed, restarting MPD Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Output device has changed, restarting Shairport Sync Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:10 gbvpi-bedroom sudo[1282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:14:10 gbvpi-bedroom sudo[1282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:10 gbvpi-bedroom sudo[1284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:14:10 gbvpi-bedroom sudo[1284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:10 gbvpi-bedroom sudo[1282]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: ___________ START PLUGINS ___________ Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: ControllerMpd::onStart: Initializing MPD Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Creating MPD Configuration file Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:14:10 gbvpi-bedroom sudo[1293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:14:10 gbvpi-bedroom sudo[1293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: [1765091650855] CoreMusicLibrary::Adding element Media Servers Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:10 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.273s CPU time. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:14:10 gbvpi-bedroom sudo[1293]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:10 gbvpi-bedroom sudo[1295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:14:10 gbvpi-bedroom sudo[1295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:10 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:10 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:14:10 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:14:11 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: [1765091651002] CoreMusicLibrary::Adding element Last_100 Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:11 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:14:11 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:11-05:00" level=debug msg="obtained new client token: AACAq84bCkbhzdZMkivLcdsjdwk1qpFVqdZqnNlprTpQYBzAD/2Ndjx8UyMUiVhmcKJI3XpCZmkeYW3pP36Nb0VqqrRjdrXUQxujb3b3fhf57xj2mPLPkaX4RsKyuzBg/CI4+J8yz/ZSx0IjjT9fLs23aeHSGH0PIJYnux/Z4tJsozUx05Q6Eji2Uck35/26oTlYGv4XkHCo1Ri8TyJDrh1atWNK8vF8e0cZfR1/BcTYZfM8DJG0DhNQCA==" Dec 07 02:14:11 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: [1765091651020] CoreMusicLibrary::Adding element Webradio Dec 07 02:14:11 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:14:11 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: Initializing BBC Radios Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: Discovery: Getting this device information Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: [1765091651170] CoreMusicLibrary::Adding element Jellyfin Dec 07 02:14:11 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:11 gbvpi-bedroom sudo[1310]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: Cannot find translation for source Jellyfin Dec 07 02:14:11 gbvpi-bedroom sudo[1310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"} Dec 07 02:14:11 gbvpi-bedroom sudo[1310]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: Creating Spotify config file Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:11 gbvpi-bedroom volumio[1232]: Starting albumart workers Dec 07 02:14:11 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:11-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:11 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:11-05:00" level=debug msg="completed challenge" Dec 07 02:14:11 gbvpi-bedroom volumio[1235]: Starting albumart workers Dec 07 02:14:11 gbvpi-bedroom go-librespot[1121]: time="2025-12-07T02:14:11-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:11 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:11 gbvpi-bedroom volumio[1149]: info: Volumio Calling Home Dec 07 02:14:11 gbvpi-bedroom volumio[1234]: Starting albumart workers Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: Found device GBVPi-Bedroom Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: Found device NorthPi-Soundstation Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: Found device GBVPi-Bedroom Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: MPD Permissions set Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: MPD Permissions set Dec 07 02:14:12 gbvpi-bedroom sudo[1188]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Spotify config file written Dec 07 02:14:12 gbvpi-bedroom sudo[1345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 07 02:14:12 gbvpi-bedroom sudo[1345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:12 gbvpi-bedroom go-librespot[1353]: go-librespot daemon starting... Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: No need to fix Spotify hosts Dec 07 02:14:12 gbvpi-bedroom sudo[1345]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="app state loaded" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Volumio called home Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Starting Shairport Sync Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Starting Shairport Sync Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Starting Shairport Sync Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=info msg="zeroconf server listening on port 38105" Dec 07 02:14:12 gbvpi-bedroom sudo[1373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:12 gbvpi-bedroom sudo[1373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:14:12 gbvpi-bedroom sudo[1377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:12 gbvpi-bedroom sudo[1377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:12 gbvpi-bedroom sudo[1375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:12 gbvpi-bedroom sudo[1375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:12 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:12 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.625s CPU time. Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: A device disappeared from network Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Discovery: Device northpi-soundstation disappeared from network Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="obtained new client token: AAClMuGqRU/3yj6iE0DIyvE0n6kt3X1+wf43hBS/sqqJu0LMYLIxz+6r835nj90xVrmTlqS0NMmRHldf5EHCoiYi7uzj0cvRKDf92MPsnxl7JOpfaUlMD6o/fLXHeqbDmY53ExCLrt9DjxWRDlanaiLNYpn58Id6HDpRSMzF4b7PJoffz6zyQp6dqQL98geqDr2E04plb4bGJZbRVcGGL1xzAQXsASSePwCbMZNiCil9wdC3BaxTIHJABg==" Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:12 gbvpi-bedroom sudo[1373]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Shairport-Sync Started Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: Error adding Membership: Error: addMembership EINVAL Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:14:12 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:12 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:12 gbvpi-bedroom sudo[1375]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:12 gbvpi-bedroom sudo[1377]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Shairport-Sync Started Dec 07 02:14:12 gbvpi-bedroom volumio[1149]: info: Shairport-Sync Started Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=debug msg="completed challenge" Dec 07 02:14:12 gbvpi-bedroom go-librespot[1364]: time="2025-12-07T02:14:12-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:13 gbvpi-bedroom mpd[1328]: 2025-12-07T02:14:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 02:14:13 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 02:14:13 gbvpi-bedroom sudo[1284]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:13 gbvpi-bedroom sudo[1295]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: Completed starting Core Plugins Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: ----- MyVolumio plugins startup ---- Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: ------------------------------------------- Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: error: MPD error: The expression evaluated to a falsy value: Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: assert.ok(self.idling) Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: error: The expression evaluated to a falsy value: Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: assert.ok(self.idling) Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: MPD running with PID1328 Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: ,establishing connection Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: error: updateQueue error: null Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: error: updateQueue error: null Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:13 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:15 gbvpi-bedroom volumio[1149]: info: go-librespot daemon successfully initialized Dec 07 02:14:15 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Dec 07 02:14:15 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:15 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:15 gbvpi-bedroom go-librespot[1402]: go-librespot daemon starting... Dec 07 02:14:15 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:15-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:15 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:15-05:00" level=debug msg="app state loaded" Dec 07 02:14:15 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:15 gbvpi-bedroom volumio[1149]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 02:14:15 gbvpi-bedroom volumio[1149]: info: Discovery: Found device NorthPi-Soundstation Dec 07 02:14:15 gbvpi-bedroom volumio[1149]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 02:14:16 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:16-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:16 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:16-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:16 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:16-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:16 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:16-05:00" level=info msg="zeroconf server listening on port 35927" Dec 07 02:14:16 gbvpi-bedroom sudo[1412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:14:16 gbvpi-bedroom sudo[1412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:16 gbvpi-bedroom sudo[1414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:14:16 gbvpi-bedroom sudo[1414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:16 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 02:14:16 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 02:14:16 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 02:14:16 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 02:14:16 gbvpi-bedroom sudo[1412]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:16 gbvpi-bedroom sudo[1414]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:16 gbvpi-bedroom mpd_monitor.sh[1417]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 02:14:16 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:16-05:00" level=debug msg="obtained new client token: AADoZHqHIr25WYmpM7I5iPLFgiwh2++UzFR6wHVBUubzfcbtii/0H4I4l6o9QJHfGYZimOtBI+R78uGziM8PkiKqkgNYNu5yfwzUnS6AI0Jo7q5A7cNIyuyUBsyrVIptZtnnmZ3py6FZsrs84WiL6v0KoQ5iNVOo/Zef5j7LcPw420+W0oBi+2L5tFeBXghleo0DnP42mrLgBx7DA/aUScAj3fyofjECDtJtcO2wAcZyrGD7F5fRyR4=" Dec 07 02:14:16 gbvpi-bedroom volumio[1149]: info: Successfully started MPD Monitor Dec 07 02:14:16 gbvpi-bedroom volumio[1149]: info: Successfully started MPD Monitor Dec 07 02:14:16 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:17 gbvpi-bedroom volumio[1149]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 02:14:18 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:18-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:18 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:18-05:00" level=debug msg="completed challenge" Dec 07 02:14:18 gbvpi-bedroom volumio[1149]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 02:14:18 gbvpi-bedroom sudo[1436]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 02:14:18 gbvpi-bedroom sudo[1436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:18 gbvpi-bedroom sudo[1438]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 02:14:18 gbvpi-bedroom sudo[1438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:18 gbvpi-bedroom go-librespot[1403]: time="2025-12-07T02:14:18-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:18 gbvpi-bedroom sudo[1436]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:18 gbvpi-bedroom sudo[1438]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:18 gbvpi-bedroom sudo[1441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 02:14:18 gbvpi-bedroom sudo[1441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:18 gbvpi-bedroom sudo[1441]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:18 gbvpi-bedroom volumio[1149]: info: Upmpdcli Daemon Started Dec 07 02:14:18 gbvpi-bedroom volumio[1149]: info: Initializing connection to go-librespot Websocket Dec 07 02:14:18 gbvpi-bedroom volumio[1149]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 02:14:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Dec 07 02:14:21 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:21 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:21 gbvpi-bedroom go-librespot[1444]: go-librespot daemon starting... Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="app state loaded" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=info msg="zeroconf server listening on port 34529" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="obtained new client token: AACA2jXkfq8HsOaLMyb8Y3FGaOKIgV1LiwXiYdiWjD26k6VeqywxOVfOZZDB8M7VzHDEtI7sF+ZSGQwaztosCHvQz4uK6BL8OLnReJU3zA+bgX3WFY73RtSFzq9Nr+wnLJgRLCK021xCtndKOMlEeUTExswHF7poVe++B+bJMvMBmsRDhxh/XZwQK73jBTKNRo+/+chXfzUN1WjwmXnnp5ycLiJ8emKX2+w/5h3AzrQ67gd5udclWfpT7g==" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=debug msg="completed challenge" Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: MyVolumio login type: Token Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 02:14:21 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 02:14:21 gbvpi-bedroom go-librespot[1445]: time="2025-12-07T02:14:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: Streaming services startup Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: Starting Streaming Daemon Dec 07 02:14:22 gbvpi-bedroom sudo[1454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 02:14:22 gbvpi-bedroom sudo[1454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 02:14:22 gbvpi-bedroom sudo[1454]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: Initializing connection to go-librespot Websocket Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: error: Cannot start Volumio Streaming Daemon Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: MyVolumio token set successfully Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: MYVOLUMIO: Adding device Dec 07 02:14:22 gbvpi-bedroom volumio[1149]: info: MYVOLUMIO: Evaluating Server Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: MyVolumio Plan changed: premium Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Removing audio output: Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: MYVOLUMIO: Adding device Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: MYVOLUMIO: Evaluating Server Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Remote config written successfully Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Starting Tunnel 1 Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Starting Tunnel Connection Checker Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Completed starting MyVolumio Plugin Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: MYVolumio Device enabled Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: MyVolumio status changed Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Streaming services startup Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: Starting Streaming Daemon Dec 07 02:14:23 gbvpi-bedroom sudo[1499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 02:14:23 gbvpi-bedroom sudo[1499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 07 02:14:23 gbvpi-bedroom sudo[1499]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 07 02:14:23 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 07 02:14:24 gbvpi-bedroom sudo[1503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 07 02:14:24 gbvpi-bedroom sudo[1503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom sudo[1503]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: MultiRoom plugin initialized Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: STOPPING SNAPCLIENT Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: Snap server stop Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: STOPPING volumioStreaming Dec 07 02:14:24 gbvpi-bedroom sudo[1521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 07 02:14:24 gbvpi-bedroom sudo[1521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom sudo[1523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 07 02:14:24 gbvpi-bedroom sudo[1523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 07 02:14:24 gbvpi-bedroom sudo[1529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 07 02:14:24 gbvpi-bedroom sudo[1526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 07 02:14:24 gbvpi-bedroom sudo[1529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom sudo[1526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom sudo[1529]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 07 02:14:24 gbvpi-bedroom sudo[1521]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom sudo[1523]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 07 02:14:24 gbvpi-bedroom sudo[1526]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Preparing to generate the ALSA configuration file Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Setting Geolocation for MyVolumio to us4 Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Reading ALSA contributions from plugins. Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: Removed streaming files Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: volumioStreaming STOPPED Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: SNAPSERVER STOPPED Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: SNAPCLIENT STOPPED Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: error: Cannot start Volumio Streaming Daemon Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Asound.conf file written Dec 07 02:14:24 gbvpi-bedroom sudo[1535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 02:14:24 gbvpi-bedroom sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom sudo[1535]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Output device has changed, restarting MPD Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Output device has changed, restarting Shairport Sync Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:24 gbvpi-bedroom sudo[1541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:14:24 gbvpi-bedroom sudo[1541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom sudo[1543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:14:24 gbvpi-bedroom sudo[1543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:24 gbvpi-bedroom sudo[1541]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 07 02:14:24 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: Pushing multiroomSync output for this device Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: Pushing multiroomSync output Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding audio output: Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding audio output: Dec 07 02:14:24 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:14:24 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:14:24 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.863s CPU time. Dec 07 02:14:24 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:14:24 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:14:24 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:24 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.36024 Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding METAVOLUMIO REST API Endpoints Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Preparing CD Folders Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding CD REST API Endpoints Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Starting UDEV Watcher for CD Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: Detecting CD presence with UDEV Dec 07 02:14:24 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 07 02:14:24 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.36024 disconnected from D-Bus Dec 07 02:14:24 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:14:24 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:14:24 gbvpi-bedroom sudo[1558]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 02:14:24 gbvpi-bedroom sudo[1558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 02:14:24 gbvpi-bedroom sudo[1558]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Dec 07 02:14:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:25 gbvpi-bedroom go-librespot[1564]: go-librespot daemon starting... Dec 07 02:14:25 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:25-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:25 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:25-05:00" level=debug msg="app state loaded" Dec 07 02:14:25 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:25 gbvpi-bedroom mpd[1563]: 2025-12-07T02:14:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 02:14:25 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 02:14:25 gbvpi-bedroom sudo[1543]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding inputs REST Endpoints Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Scanning Audio Inputs Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Checking against Known Cards name Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding Server instance for streaming Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: error: Hi Res Audio Failed Login: Missing Login Data Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 07 02:14:29 gbvpi-bedroom sudo[1598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 07 02:14:29 gbvpi-bedroom sudo[1598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding TIDAL REST API Endpoints Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Stopping AccessToken refresher cron for QOBUZ Dec 07 02:14:29 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 07 02:14:29 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 1081 (vtcs) with signal SIGKILL. Dec 07 02:14:29 gbvpi-bedroom sudo[1605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 07 02:14:29 gbvpi-bedroom sudo[1605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:29 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 07 02:14:29 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 07 02:14:29 gbvpi-bedroom sudo[1598]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: AccessToken refresher cron started for QOBUZ Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Adding QOBUZ REST API Endpoints Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Initializing connection to go-librespot Websocket Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Updating MyVolumio device info Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom sudo[1605]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: MRS: Getting audio outputs on start Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: MRS: Requesting all other devices output Dec 07 02:14:29 gbvpi-bedroom sudo[1608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 07 02:14:29 gbvpi-bedroom sudo[1608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Successfully Added MyVolumio device Dec 07 02:14:29 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Setting Geolocation for MyVolumio to us4 Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom qobuz-connect[1018]: 20251207 02:14:29.814 [1018.1018] INFO SampleApp: Stopping Local configuration server Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: MPD Permissions set Dec 07 02:14:29 gbvpi-bedroom sudo[1611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 07 02:14:29 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:29-05:00" level=debug msg="new websocket client" Dec 07 02:14:29 gbvpi-bedroom sudo[1611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:29 gbvpi-bedroom sudo[1611]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Connection to go-librespot Websocket established Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: error: updateQueue error: null Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioStop Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::stop Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 02:14:29 gbvpi-bedroom volumio[1149]: info: Starting Shairport Sync Dec 07 02:14:29 gbvpi-bedroom sudo[1627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 07 02:14:29 gbvpi-bedroom sudo[1627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:29 gbvpi-bedroom sudo[1629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:29 gbvpi-bedroom sudo[1629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:29 gbvpi-bedroom autossh[996]: received signal to exit (15) Dec 07 02:14:29 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 07 02:14:29 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully. Dec 07 02:14:30 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 07 02:14:30 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:14:30 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 07 02:14:30 gbvpi-bedroom sudo[1627]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: Remote SSH Started Dec 07 02:14:30 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:14:30 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:30 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.615s CPU time. Dec 07 02:14:30 gbvpi-bedroom autossh[1633]: port set to 0, monitoring disabled Dec 07 02:14:30 gbvpi-bedroom autossh[1633]: starting ssh (count 1) Dec 07 02:14:30 gbvpi-bedroom autossh[1633]: ssh child pid is 1636 Dec 07 02:14:30 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:30 gbvpi-bedroom sudo[1629]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: Shairport-Sync Started Dec 07 02:14:30 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14: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-gew1.spotify.com:80]" Dec 07 02:14:30 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:30-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 02:14:30 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:30-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 02:14:30 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:30-05:00" level=info msg="zeroconf server listening on port 41899" Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: Updating MyVolumio device info Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:30 gbvpi-bedroom volumio[1149]: info: Successfully Updated MyVolumio device Dec 07 02:14:31 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 07 02:14:31 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:14:31 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:14:31 gbvpi-bedroom sudo[1608]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:31 gbvpi-bedroom volumio[1149]: info: Executing endpoint qc_getconfig Dec 07 02:14:31 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.762 [1654.1654] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 07 02:14:31 gbvpi-bedroom volumio[1149]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 07 02:14:31 gbvpi-bedroom volumio[1149]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.766 [1654.1654] INFO VolumeManager: [0x1d71588]: Setting new playback volume: 75 Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.766 [1654.1654] INFO VolumeManager: [0x1d71588]: Setting new mute state: 0 Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.766 [1654.1654] INFO QobuzConnect: [0x1d71f58]: Client initialized! Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.766 [1654.1654] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.775 [1654.1654] INFO LocalConfigManager: [0x1d70e68]: Starting Local Configuration server Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.775 [1654.1654] INFO SampleApp: Starting Local configuration server Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.775 [1654.1654] INFO SampleApp: Connected to UNIX socket client 0x1d5b818 Dec 07 02:14:31 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:31.912 [1654.1654] INFO SampleApp: Playback volume changed: 75 Dec 07 02:14:31 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:32 gbvpi-bedroom volumio[1149]: info: TidalConnect service stoped! Dec 07 02:14:32 gbvpi-bedroom volumio[1149]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 07 02:14:32 gbvpi-bedroom volumio[1149]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 07 02:14:32 gbvpi-bedroom sudo[1669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 07 02:14:32 gbvpi-bedroom sudo[1669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:32 gbvpi-bedroom sudo[1673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:14:32 gbvpi-bedroom sudo[1673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:32 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 07 02:14:32 gbvpi-bedroom sudo[1669]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:32 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 02:14:32 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 02:14:32 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 02:14:32 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 02:14:32 gbvpi-bedroom sudo[1673]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:32 gbvpi-bedroom mpd_monitor.sh[1677]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 02:14:32 gbvpi-bedroom volumio[1149]: info: Getting Spotify volume Dec 07 02:14:32 gbvpi-bedroom volumio[1149]: info: Successfully started MPD Monitor Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Executing endpoint tc_getconfig Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 07 02:14:33 gbvpi-bedroom vtcs[1675]: STARTING TidalConnect services, version: 1.5.2.56 Dec 07 02:14:33 gbvpi-bedroom vtcs[1675]: STARTED TidalConnect services. Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Executing endpoint tc_connect Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Connecting to TidalConnect Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::servicePushState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::pushState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: MRS: Pushing multiroomSync output Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::servicePushState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreStateMachine::pushState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: MRS: Pushing multiroomSync output Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:33 gbvpi-bedroom volumio[1149]: info: Listing playlists Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: Successfully Added MyVolumio device Dec 07 02:14:35 gbvpi-bedroom volumiossh-tunnel[1636]: Warning: Permanently added '[us4.myvolumio.org]:2222' (ED25519) to the list of known hosts. Dec 07 02:14:35 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:35-05:00" level=debug msg="obtained new client token: AADOHyoRp1WLGNxTFT9ZANXynGOMMLIbGe3d/IOa6OCRwsxZrdDG88467demoF9msKYClSjCFjkxGy3IQEBwih/ATlxYP3kmqn9StD8nE3ErHrvo3vgsgh9nbYjTxRcgVC4bukzatiNVfVBbMwyMng4WAI4ZdtsQfLEwweKfxhvVa+76+KvUXKC51AUzNcInQdMYpK+8i7+PRJ15/U7/Eg7kgvtxCKetYax7CD2Mp1ngmC96eXropiyuOg==" Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: TidalConnect service started! Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: [Metrics] CommandRouter: 29s 20.89ms Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::volumiosetStartupVolume Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::Close All Modals sent Dec 07 02:14:35 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::Close All Modals sent Dec 07 02:14:36 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 02:14:36 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 07 02:14:36 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 07 02:14:36 gbvpi-bedroom volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: info: Adding audio output: Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 07 02:14:40 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:40 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:40-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:40 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:40-05:00" level=debug msg="completed challenge" Dec 07 02:14:40 gbvpi-bedroom go-librespot[1565]: time="2025-12-07T02:14:40-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:14:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:40 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: Error: socket hang up Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: at connResetException (node:internal/errors:720:14) Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: at Socket.emit (node:events:526:35) Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: code: 'ECONNRESET', Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: response: undefined Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: } Dec 07 02:14:40 gbvpi-bedroom volumio[1149]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:14:41 gbvpi-bedroom sudo[1726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 02:13' Dec 07 02:14:41 gbvpi-bedroom sudo[1726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:41 gbvpi-bedroom sudo[1726]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129. Dec 07 02:14:43 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:43 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:43 gbvpi-bedroom go-librespot[1734]: go-librespot daemon starting... Dec 07 02:14:43 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:43-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:43 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:43-05:00" level=debug msg="app state loaded" Dec 07 02:14:43 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=info msg="zeroconf server listening on port 41765" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="obtained new client token: AAC6jmaIoPf6UbmIjJgCzHzMCzTq7KgTyqz8H4LWLR45lF52knfqILDJyYLMM1r7Y8zW9tu05VDVJIjNSiFWy3NY8N5xrtx6pa6Icbg0CeusnfFlUJP11gSsh3MJZ4RtKvMYJG6RU1ltJIFNmZRCCwiasOgfRUy5gyvQqZiDN1ab9QBxtZCfTbYN+ei4kGSbtgWV+FJUhidtxR7Yq5whdsoYdRCz/Z9ta5Z/DXwZJkGtDV7yir7+GlKxxQ==" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=debug msg="completed challenge" Dec 07 02:14:45 gbvpi-bedroom go-librespot[1735]: time="2025-12-07T02:14:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:45 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:45] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 07 02:14:45 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:14:45.976 [1654.1654] INFO SampleApp: Socket closed Dec 07 02:14:45 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:45 gbvpi-bedroom vtcs[1675]: [2025-12-07 02:14:45.976] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 07 02:14:45 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:45] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 07 02:14:45 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 07 02:14:45 gbvpi-bedroom systemd[1]: volumio.service: Consumed 19.862s CPU time. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2242. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: volumio.service: Consumed 19.862s CPU time. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 07 02:14:46 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ----- Volumio3 ---- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ----- System startup ---- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: MYVOLUMIO Environment detected Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Plugin folders cleanup Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning into folder /volumio/app/plugins/ Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category audio_interface Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category miscellanea Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category music_service Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category plugins.json Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category system_controller Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category user_interface Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning into folder /data/plugins/ Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Scanning category music_service Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Plugin folders cleanup completed Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ----- Core plugins startup ---- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Loading plugins from folder /volumio/app/plugins/ Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Adding plugin upnp to MyMusic Plugins Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Loading plugins from folder /data/plugins/ Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Loading plugin "system"... Dec 07 02:14:47 gbvpi-bedroom volumio[1749]: info: Loading plugin "appearance"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "network"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Refreshing Cached IP Addresses Dec 07 02:14:48 gbvpi-bedroom sudo[1777]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 02:14:48 gbvpi-bedroom sudo[1777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:48 gbvpi-bedroom sudo[1777]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:48 gbvpi-bedroom sudo[1779]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 02:14:48 gbvpi-bedroom sudo[1779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "services"... Dec 07 02:14:48 gbvpi-bedroom sudo[1779]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "alsa_controller"... Dec 07 02:14:48 gbvpi-bedroom sudo[1792]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 07 02:14:48 gbvpi-bedroom sudo[1792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "wizard"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "networkfs"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Starting Udev Watcher for removable devices Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Ignoring mount for partition: boot Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Ignoring mount for partition: volumio Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Ignoring mount for partition: volumio_data Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "volumio_command_line_client"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "upnp"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: [1765091688587] Starting Upmpd Daemon Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "my_music"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "mpd"... Dec 07 02:14:48 gbvpi-bedroom volumio[1749]: info: Loading plugin "upnp_browser"... Dec 07 02:14:48 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130. Dec 07 02:14:48 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:48 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:48 gbvpi-bedroom go-librespot[1811]: go-librespot daemon starting... Dec 07 02:14:48 gbvpi-bedroom go-librespot[1812]: time="2025-12-07T02:14:48-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:48 gbvpi-bedroom go-librespot[1812]: time="2025-12-07T02:14:48-05:00" level=debug msg="app state loaded" Dec 07 02:14:48 gbvpi-bedroom go-librespot[1812]: time="2025-12-07T02:14:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "alarm-clock"... Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "airplay_emulation"... Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Starting Shairport Sync Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "last_100"... Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "webradio"... Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "i2s_dacs"... Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: I2S DAC not set, start Auto-detection Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "volumiodiscovery"... Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: *** WARNING *** For more information see Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:49 gbvpi-bedroom node[1749]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: *** WARNING *** For more information see Dec 07 02:14:49 gbvpi-bedroom node[1749]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:49 gbvpi-bedroom node[1749]: *** WARNING *** For more information see Dec 07 02:14:49 gbvpi-bedroom node[1749]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 02:14:49 gbvpi-bedroom node[1749]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:14:49 gbvpi-bedroom node[1749]: *** WARNING *** For more information see Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:49 gbvpi-bedroom volumio[1749]: info: Loading plugin "jellyfin"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "spop"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "outputs"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "albumart"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Plugin example_plugin is not enabled Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "inputs"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "updater_comm"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Plugin mpdemulation is not enabled Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "rest_api"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading plugin "websocket"... Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Starting Socket.io Server version 1.7.4 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Loading i18n strings for locale en Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: Updating browse sources language Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::initPlayerControls Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: Express server listening on port 3000 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: [Metrics] WebUI: 3s 687.94ms Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::resetVolumioState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::getcurrentVolume Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Volumio Network Manager: Network status updated: 2 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: VolumeController:: Volume=91 Mute =false Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::pushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::updateTrackBlock Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrackBlock Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 02:14:50 gbvpi-bedroom volumio[1821]: Forking 3 albumart workers Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Reloading queue from file Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::setRepeat null single undefined Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::pushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::setRandom null Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::pushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: Setting Device type: Raspberry PI Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 07 02:14:50 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:50] [connect] Successful connection Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: VolumeController:: Volume=91 Mute =false Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreStateMachine::pushState Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:50 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioPushState Dec 07 02:14:51 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:14:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765091690 101 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Completed loading Core Plugins Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Preparing to generate the ALSA configuration file Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Asound.conf file written Dec 07 02:14:51 gbvpi-bedroom sudo[1877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 02:14:51 gbvpi-bedroom sudo[1877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:51 gbvpi-bedroom sudo[1877]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Output device has changed, restarting MPD Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Output device has changed, restarting Shairport Sync Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:51 gbvpi-bedroom sudo[1883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:14:51 gbvpi-bedroom sudo[1883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: ___________ START PLUGINS ___________ Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: ControllerMpd::onStart: Initializing MPD Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Creating MPD Configuration file Dec 07 02:14:51 gbvpi-bedroom sudo[1885]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:14:51 gbvpi-bedroom sudo[1885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:51 gbvpi-bedroom sudo[1883]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: [1765091691285] CoreMusicLibrary::Adding element Media Servers Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:51 gbvpi-bedroom sudo[1893]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:14:51 gbvpi-bedroom sudo[1893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:51 gbvpi-bedroom sudo[1893]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:51 gbvpi-bedroom sudo[1895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:14:51 gbvpi-bedroom sudo[1895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:51 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.284s CPU time. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: [1765091691415] CoreMusicLibrary::Adding element Last_100 Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: [1765091691419] CoreMusicLibrary::Adding element Webradio Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Initializing BBC Radios Dec 07 02:14:51 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:14:51 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Discovery: Getting this device information Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: [1765091691528] CoreMusicLibrary::Adding element Jellyfin Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: Cannot find translation for source Jellyfin Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"} Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Creating Spotify config file Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:51 gbvpi-bedroom sudo[1914]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 02:14:51 gbvpi-bedroom sudo[1914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 02:14:51 gbvpi-bedroom sudo[1914]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: Volumio Calling Home Dec 07 02:14:51 gbvpi-bedroom volumio[1842]: Starting albumart workers Dec 07 02:14:51 gbvpi-bedroom volumio[1840]: Starting albumart workers Dec 07 02:14:51 gbvpi-bedroom volumio[1749]: info: MPD Permissions set Dec 07 02:14:52 gbvpi-bedroom volumio[1844]: Starting albumart workers Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: MPD Permissions set Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Spotify config file written Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom sudo[1929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 02:14:52 gbvpi-bedroom sudo[1929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: No need to fix Spotify hosts Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Starting Shairport Sync Dec 07 02:14:52 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Starting Shairport Sync Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Starting Shairport Sync Dec 07 02:14:52 gbvpi-bedroom sudo[1945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:52 gbvpi-bedroom sudo[1945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:52 gbvpi-bedroom go-librespot[1943]: go-librespot daemon starting... Dec 07 02:14:52 gbvpi-bedroom sudo[1929]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:52 gbvpi-bedroom sudo[1947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:52 gbvpi-bedroom sudo[1947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:52 gbvpi-bedroom sudo[1948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:14:52 gbvpi-bedroom sudo[1948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:52 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:52-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:52 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:52-05:00" level=debug msg="app state loaded" Dec 07 02:14:52 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:52-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:14:52 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:52 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.648s CPU time. Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:52 gbvpi-bedroom sudo[1948]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:52 gbvpi-bedroom sudo[1945]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:14:52 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Shairport-Sync Started Dec 07 02:14:52 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:14:52 gbvpi-bedroom sudo[1947]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: Error adding Membership: Error: addMembership EINVAL Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Shairport-Sync Started Dec 07 02:14:52 gbvpi-bedroom volumio[1749]: info: Shairport-Sync Started Dec 07 02:14:52 gbvpi-bedroom sudo[1792]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:14:53 gbvpi-bedroom mpd[1924]: 2025-12-07T02:14:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 02:14:53 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 02:14:53 gbvpi-bedroom sudo[1895]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:53 gbvpi-bedroom sudo[1885]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: Completed starting Core Plugins Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: ----- MyVolumio plugins startup ---- Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: ------------------------------------------- Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: error: MPD error: The expression evaluated to a falsy value: Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: assert.ok(self.idling) Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: error: The expression evaluated to a falsy value: Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: assert.ok(self.idling) Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: info: MPD running with PID1924 Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: ,establishing connection Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: error: updateQueue error: null Dec 07 02:14:53 gbvpi-bedroom volumio[1749]: error: updateQueue error: null Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: go-librespot daemon successfully initialized Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: Found device NorthPi-Soundstation Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: Found device GBVPi-Bedroom Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: Found device GBVPi-Bedroom Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 02:14:55 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:55-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 07 02:14:55 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:55-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 07 02:14:55 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:55-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 07 02:14:55 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:55-05:00" level=info msg="zeroconf server listening on port 45573" Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: Volumio called home Dec 07 02:14:55 gbvpi-bedroom volumio[1749]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 07 02:14:55 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:55-05:00" level=debug msg="obtained new client token: AAAk2PpSkaaWGMF4HRT3aIZwYK5n4NXqW4eM99bfU9z8gmm8pPDgB+lnZmTKyePgX/hGhKQZPfKm8fidbsG1FOEfHmBbUmWCwymdq484upLT4Oi5ygBaude61UqmEDQaNdGNA0F21lInPY1OtDI7h/e785QaN8y7L2uG6OfwKVgScoF/QgYv+xBS3aBWxlq8DGG30uPsRa1FGMVQ8WP03h4ASXD01E0kUDFdEsOMWxcBfHhwUwWRYE9teQ==" Dec 07 02:14:56 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:56-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:56 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:56-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:56 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:56-05:00" level=debug msg="completed challenge" Dec 07 02:14:56 gbvpi-bedroom go-librespot[1950]: time="2025-12-07T02:14:56-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:14:56 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:56 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:14:56 gbvpi-bedroom sudo[2003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:14:56 gbvpi-bedroom sudo[2003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:56 gbvpi-bedroom sudo[2005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:14:56 gbvpi-bedroom sudo[2005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:56 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 02:14:56 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 02:14:56 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 02:14:56 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 02:14:56 gbvpi-bedroom sudo[2003]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:56 gbvpi-bedroom sudo[2005]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:56 gbvpi-bedroom volumio[1749]: info: Successfully started MPD Monitor Dec 07 02:14:56 gbvpi-bedroom volumio[1749]: info: Successfully started MPD Monitor Dec 07 02:14:56 gbvpi-bedroom mpd_monitor.sh[2008]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 02:14:58 gbvpi-bedroom volumio[1749]: info: Initializing connection to go-librespot Websocket Dec 07 02:14:58 gbvpi-bedroom volumio[1749]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 02:14:58 gbvpi-bedroom volumio[1749]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 02:14:58 gbvpi-bedroom sudo[2029]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 02:14:58 gbvpi-bedroom sudo[2029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:58 gbvpi-bedroom sudo[2029]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:58 gbvpi-bedroom sudo[2031]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 02:14:58 gbvpi-bedroom sudo[2031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:58 gbvpi-bedroom sudo[2031]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:58 gbvpi-bedroom sudo[2035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 02:14:58 gbvpi-bedroom sudo[2035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:14:58 gbvpi-bedroom sudo[2035]: pam_unix(sudo:session): session closed for user root Dec 07 02:14:58 gbvpi-bedroom volumio[1749]: info: Upmpdcli Daemon Started Dec 07 02:14:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 07 02:14:59 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:59 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:14:59 gbvpi-bedroom go-librespot[2037]: go-librespot daemon starting... Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="app state loaded" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=info msg="zeroconf server listening on port 42785" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="obtained new client token: AABU2ug/kIqiBJ8NbYFJCzUEBujee0EnB8p5ieIceQ5Yrdtlmj1Rmyor27S32bJug04xq+8zaN3hG8NAzEwWRSOIkC5XNJCvBe8Iq4iKii6EqFJhTYw1mpnvq5EWUSc3ZR7bWsrnNOEddy6w3xgQBg4Da75x868bl3EnLL+E2hhorTp7+ONQH/UI24TzVJ0hbvPBHWvs+WMebUtIN4ET9JGZE8rQ+G9WrJno/XFr1NMeziH5ucyQxfjiuQ==" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="completed keyexchange" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14:59-05:00" level=debug msg="completed challenge" Dec 07 02:14:59 gbvpi-bedroom go-librespot[2038]: time="2025-12-07T02:14: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 07 02:14:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:14:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Initializing connection to go-librespot Websocket Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 02:15:01 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: MyVolumio login type: Token Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: Streaming services startup Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: Starting Streaming Daemon Dec 07 02:15:02 gbvpi-bedroom sudo[2046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 02:15:02 gbvpi-bedroom sudo[2046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 02:15:02 gbvpi-bedroom sudo[2046]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: error: Cannot start Volumio Streaming Daemon Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 02:15:02 gbvpi-bedroom volumio[1749]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 02:15:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 07 02:15:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:02 gbvpi-bedroom go-librespot[2052]: go-librespot daemon starting... Dec 07 02:15:02 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:02-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:15:02 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:02-05:00" level=debug msg="app state loaded" Dec 07 02:15:02 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:15:03 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:03 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:03 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:03 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:04 gbvpi-bedroom volumio[1749]: info: Initializing connection to go-librespot Websocket Dec 07 02:15:07 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:07-05:00" level=debug msg="new websocket client" Dec 07 02:15:07 gbvpi-bedroom volumio[1749]: info: Connection to go-librespot Websocket established Dec 07 02:15:08 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:15:08 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:15:08 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:15:08 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:08-05:00" level=info msg="zeroconf server listening on port 45549" Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: Getting Spotify volume Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: SPOTIFY: SPOTIFY VOLUME undefined Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: SPOTIFY: VOLUMIO VOLUME 91 Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: Aligning Spotify Volume to Volumio Volume Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:10 gbvpi-bedroom volumio[1749]: info: Setting Spotify Volume from Volumio: 91 Dec 07 02:15:12 gbvpi-bedroom volumio[1749]: SPOTIFY: SETTING SPOTIFY VOLUME 91 Dec 07 02:15:12 gbvpi-bedroom volumio[1749]: info: Sending Spotify command with payload to local API: /player/volume Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:15:13 gbvpi-bedroom volumio[1749]: info: Listing playlists Dec 07 02:15:13 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:13-05:00" level=debug msg="obtained new client token: AACXoXOcNQL3HR2DcZQ6MOc9idoL1NMqIxdSaLiy/JAgCFmueNyDQowe0sc28AmXePcSLEZEu5SzHEO++FmZtgG6Oq5Q/W394lyqDITkS7E0yI7otmcinaJnqnTJ8gTszvmjEj4Oc4W8ryf7brME6orN7tfKARgkN0sAO612D9jqC/xQdt8T2IgH443upA4mKLr1pi6hkUaXe9MP+meGucutE7Ywei9vrsCpTeRfURTeMXfJERbaXlE=" Dec 07 02:15:17 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:18 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:18-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 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MyVolumio token set successfully Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MYVOLUMIO: Adding device Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MYVOLUMIO: Evaluating Server Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MyVolumio Plan changed: premium Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Removing audio output: Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MYVOLUMIO: Adding device Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MYVOLUMIO: Evaluating Server Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Remote config written successfully Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Starting Tunnel 1 Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Starting Tunnel Connection Checker Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Completed starting MyVolumio Plugin Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MYVolumio Device enabled Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: MyVolumio status changed Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Streaming services startup Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: Starting Streaming Daemon Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 07 02:15:18 gbvpi-bedroom sudo[2133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 02:15:18 gbvpi-bedroom sudo[2133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 07 02:15:18 gbvpi-bedroom sudo[2133]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 07 02:15:18 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 07 02:15:19 gbvpi-bedroom sudo[2138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 07 02:15:19 gbvpi-bedroom sudo[2138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom sudo[2138]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: MultiRoom plugin initialized Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: STOPPING SNAPCLIENT Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: Snap server stop Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: STOPPING volumioStreaming Dec 07 02:15:19 gbvpi-bedroom sudo[2155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 07 02:15:19 gbvpi-bedroom sudo[2155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom sudo[2157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 07 02:15:19 gbvpi-bedroom sudo[2157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom sudo[2159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 07 02:15:19 gbvpi-bedroom sudo[2159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom sudo[2162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 07 02:15:19 gbvpi-bedroom sudo[2162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 07 02:15:19 gbvpi-bedroom sudo[2162]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 07 02:15:19 gbvpi-bedroom sudo[2155]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 07 02:15:19 gbvpi-bedroom sudo[2159]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 07 02:15:19 gbvpi-bedroom sudo[2157]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Preparing to generate the ALSA configuration file Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Discovery: Disconnected from remote: 192.168.1.28 Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: Pushing multiroomSync output for this device Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: Pushing multiroomSync output Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Adding audio output: Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Adding audio output: Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Reading ALSA contributions from plugins. Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: Removed streaming files Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: volumioStreaming STOPPED Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: SNAPSERVER STOPPED Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: MRS: SNAPCLIENT STOPPED Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: error: Cannot start Volumio Streaming Daemon Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Discovery: A device disappeared from network Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Discovery: Device northpi-soundstation disappeared from network Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Asound.conf file written Dec 07 02:15:19 gbvpi-bedroom sudo[2168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 02:15:19 gbvpi-bedroom sudo[2168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom sudo[2168]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Output device has changed, restarting MPD Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: Output device has changed, restarting Shairport Sync Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:19 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:19 gbvpi-bedroom sudo[2174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:15:19 gbvpi-bedroom sudo[2174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:19 gbvpi-bedroom sudo[2174]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:19 gbvpi-bedroom sudo[2178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:15:19 gbvpi-bedroom sudo[2178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 07 02:15:20 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 07 02:15:20 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:15:20 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:15:20 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.855s CPU time. Dec 07 02:15:20 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:15:20 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding METAVOLUMIO REST API Endpoints Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:15:20 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Preparing CD Folders Dec 07 02:15:20 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.36040 Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding CD REST API Endpoints Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Starting UDEV Watcher for CD Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: Detecting CD presence with UDEV Dec 07 02:15:20 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 07 02:15:20 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.36040 disconnected from D-Bus Dec 07 02:15:20 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:15:20 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:15:20 gbvpi-bedroom sudo[2194]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 02:15:20 gbvpi-bedroom sudo[2194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 02:15:20 gbvpi-bedroom sudo[2194]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:21 gbvpi-bedroom mpd[2196]: 2025-12-07T02:15:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 02:15:21 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 02:15:21 gbvpi-bedroom sudo[2178]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:21 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Dec 07 02:15:21 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:21-05:00" level=debug msg="completed keyexchange" Dec 07 02:15:21 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:21-05:00" level=debug msg="completed challenge" Dec 07 02:15:21 gbvpi-bedroom go-librespot[2053]: time="2025-12-07T02:15:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:15:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding inputs REST Endpoints Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Scanning Audio Inputs Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Checking against Known Cards name Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding Server instance for streaming Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: error: Hi Res Audio Failed Login: Missing Login Data Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 07 02:15:25 gbvpi-bedroom sudo[2204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 07 02:15:25 gbvpi-bedroom sudo[2204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 07 02:15:25 gbvpi-bedroom go-librespot[2199]: go-librespot daemon starting... Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding TIDAL REST API Endpoints Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Stopping AccessToken refresher cron for QOBUZ Dec 07 02:15:25 gbvpi-bedroom sudo[2212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 07 02:15:25 gbvpi-bedroom sudo[2212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="app state loaded" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:15:25 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 07 02:15:25 gbvpi-bedroom sudo[2204]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: AccessToken refresher cron started for QOBUZ Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: Adding QOBUZ REST API Endpoints Dec 07 02:15:25 gbvpi-bedroom sudo[2212]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::volumioGetBrowseSources Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: MRS: Getting audio outputs on start Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: info: MRS: Requesting all other devices output Dec 07 02:15:25 gbvpi-bedroom sudo[2221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 07 02:15:25 gbvpi-bedroom sudo[2221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[1654]: 20251207 02:15:25.318 [1654.1654] INFO SampleApp: Stopping Local configuration server Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: Error: socket hang up Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: at connResetException (node:internal/errors:720:14) Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: at Socket.emit (node:events:526:35) Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: code: 'ECONNRESET', Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: response: undefined Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: } Dec 07 02:15:25 gbvpi-bedroom volumio[1749]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=info msg="zeroconf server listening on port 34553" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="obtained new client token: AABFyqqbRCg3tlPo+GtyMRl5n3kPB1ZVCZz4AjwMPXEgsXorXi+cTsY1WomZOMwOMjp2Txyl8VXo8LkNZfsCOFwN/XrIlbCXojRusu9+vigiKVHCtEdTu3jf+i6zP1c2XPDXs+uve9bSOM88Lms5UemUGn2JmSGoUxynJISIk3xPKIO9xcVDgUA6N+6uHeMgYAVknHgQHLeDyApaOAgWiNoXSVKpum5qGZbToBlMERxPrvNpk7C+bhLYDA==" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="completed keyexchange" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=debug msg="completed challenge" Dec 07 02:15:25 gbvpi-bedroom go-librespot[2210]: time="2025-12-07T02:15:25-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:15:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:15:25 gbvpi-bedroom sudo[2241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 02:14' Dec 07 02:15:25 gbvpi-bedroom sudo[2241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:25 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:25 gbvpi-bedroom sudo[2241]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:25 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:15:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 07 02:15:25 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:15:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:25 gbvpi-bedroom sudo[2221]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:25 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: volumio.service: Consumed 18.799s CPU time. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: Error: Application ID was not specified! Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -m|--manufacturer: Manufacturer of the device Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -n|--deviceName: Device name Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -l|--model: Device's model name Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -s|--serialNumber: Device's serial number Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -o|--outputDevice: ALSA PCM device to play audio to Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -p|--port: Port to run the local configuration HTTP server on Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 07 02:15:25 gbvpi-bedroom qobuz-connect[2243]: -h|--help: Print this help Dec 07 02:15:25 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:25 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 07 02:15:25 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 02:15:26 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2243. Dec 07 02:15:26 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 07 02:15:26 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 07 02:15:26 gbvpi-bedroom systemd[1]: volumio.service: Consumed 18.799s CPU time. Dec 07 02:15:26 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module. Dec 07 02:15:26 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully. Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ----- Volumio3 ---- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ----- System startup ---- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: MYVOLUMIO Environment detected Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Plugin folders cleanup Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning into folder /volumio/app/plugins/ Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category audio_interface Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category miscellanea Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category music_service Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category plugins.json Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category system_controller Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category user_interface Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning into folder /data/plugins/ Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Scanning category music_service Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Plugin folders cleanup completed Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ----- Core plugins startup ---- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Loading plugins from folder /volumio/app/plugins/ Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Adding plugin upnp to MyMusic Plugins Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Loading plugins from folder /data/plugins/ Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Loading plugin "system"... Dec 07 02:15:27 gbvpi-bedroom volumio[2255]: info: Loading plugin "appearance"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "network"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Refreshing Cached IP Addresses Dec 07 02:15:28 gbvpi-bedroom sudo[2283]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 02:15:28 gbvpi-bedroom sudo[2283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:28 gbvpi-bedroom sudo[2285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 02:15:28 gbvpi-bedroom sudo[2285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:28 gbvpi-bedroom sudo[2283]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "services"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "alsa_controller"... Dec 07 02:15:28 gbvpi-bedroom sudo[2285]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:28 gbvpi-bedroom sudo[2293]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 07 02:15:28 gbvpi-bedroom sudo[2293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "wizard"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "networkfs"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Starting Udev Watcher for removable devices Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Ignoring mount for partition: boot Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Ignoring mount for partition: volumio Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Ignoring mount for partition: volumio_data Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "volumio_command_line_client"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "upnp"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: [1765091728366] Starting Upmpd Daemon Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "my_music"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "mpd"... Dec 07 02:15:28 gbvpi-bedroom volumio[2255]: info: Loading plugin "upnp_browser"... Dec 07 02:15:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 07 02:15:28 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:28 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:28 gbvpi-bedroom go-librespot[2316]: go-librespot daemon starting... Dec 07 02:15:28 gbvpi-bedroom go-librespot[2317]: time="2025-12-07T02:15:28-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:15:28 gbvpi-bedroom go-librespot[2317]: time="2025-12-07T02:15:28-05:00" level=debug msg="app state loaded" Dec 07 02:15:28 gbvpi-bedroom go-librespot[2317]: time="2025-12-07T02:15:28-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "alarm-clock"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "airplay_emulation"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Starting Shairport Sync Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "last_100"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "webradio"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "i2s_dacs"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: I2S DAC not set, start Auto-detection Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "volumiodiscovery"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: *** WARNING *** For more information see Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:15:29 gbvpi-bedroom node[2255]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: *** WARNING *** For more information see Dec 07 02:15:29 gbvpi-bedroom node[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:15:29 gbvpi-bedroom node[2255]: *** WARNING *** For more information see Dec 07 02:15:29 gbvpi-bedroom node[2255]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 07 02:15:29 gbvpi-bedroom node[2255]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 07 02:15:29 gbvpi-bedroom node[2255]: *** WARNING *** For more information see Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Discovery: Started advertising with name: GBVPi-Bedroom Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "jellyfin"... Dec 07 02:15:29 gbvpi-bedroom volumio[2255]: info: Loading plugin "spop"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading plugin "outputs"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading plugin "albumart"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Plugin example_plugin is not enabled Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading plugin "inputs"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading plugin "updater_comm"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Plugin mpdemulation is not enabled Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading plugin "rest_api"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading plugin "websocket"... Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Starting Socket.io Server version 1.7.4 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Loading i18n strings for locale en Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: Updating browse sources language Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::initPlayerControls Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: Express server listening on port 3000 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: [Metrics] WebUI: 3s 650.96ms Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::resetVolumioState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::getcurrentVolume Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Volumio Network Manager: Network status updated: 2 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: VolumeController:: Volume=91 Mute =false Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::pushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioPushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::updateTrackBlock Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrackBlock Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioRetrievevolume Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Reloading queue from file Dec 07 02:15:30 gbvpi-bedroom volumio[2325]: Forking 3 albumart workers Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::setRepeat null single undefined Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::pushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioPushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::setRandom null Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::pushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioPushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Setting Device type: Raspberry PI Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: VolumeController:: Volume=91 Mute =false Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreStateMachine::pushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioPushState Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Completed loading Core Plugins Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Preparing to generate the ALSA configuration file Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Asound.conf file written Dec 07 02:15:30 gbvpi-bedroom sudo[2379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 07 02:15:30 gbvpi-bedroom sudo[2379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:30 gbvpi-bedroom sudo[2379]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Output device has changed, restarting MPD Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Output device has changed, restarting Shairport Sync Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:30 gbvpi-bedroom sudo[2389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:15:30 gbvpi-bedroom sudo[2389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:30 gbvpi-bedroom sudo[2389]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:30 gbvpi-bedroom sudo[2390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:15:30 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:15:30] [connect] Successful connection Dec 07 02:15:30 gbvpi-bedroom sudo[2390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: ___________ START PLUGINS ___________ Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: ControllerMpd::onStart: Initializing MPD Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: Creating MPD Configuration file Dec 07 02:15:30 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 07 02:15:30 gbvpi-bedroom sudo[2398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 07 02:15:30 gbvpi-bedroom sudo[2398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: [1765091730975] CoreMusicLibrary::Adding element Media Servers Dec 07 02:15:30 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:15:30 gbvpi-bedroom sudo[2398]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:31 gbvpi-bedroom sudo[2400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 07 02:15:31 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:15:31 gbvpi-bedroom sudo[2400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.262s CPU time. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 1. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 07 02:15:31 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: [1765091731121] CoreMusicLibrary::Adding element Last_100 Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: [1765091731125] CoreMusicLibrary::Adding element Webradio Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 07 02:15:31 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon... Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: Initializing BBC Radios Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: Discovery: Getting this device information Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: [1765091731279] CoreMusicLibrary::Adding element Jellyfin Dec 07 02:15:31 gbvpi-bedroom sudo[2415]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 07 02:15:31 gbvpi-bedroom sudo[2415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: Cannot find translation for source Jellyfin Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"} Dec 07 02:15:31 gbvpi-bedroom sudo[2415]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: Creating Spotify config file Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:31 gbvpi-bedroom volumio[2255]: info: Volumio Calling Home Dec 07 02:15:31 gbvpi-bedroom volumio[2346]: Starting albumart workers Dec 07 02:15:31 gbvpi-bedroom volumio[2349]: Starting albumart workers Dec 07 02:15:31 gbvpi-bedroom volumio[2347]: Starting albumart workers Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: MPD Permissions set Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: MPD Permissions set Dec 07 02:15:32 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-07 02:15:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765091730 101 Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Spotify config file written Dec 07 02:15:32 gbvpi-bedroom sudo[2435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 07 02:15:32 gbvpi-bedroom sudo[2435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 07 02:15:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:32 gbvpi-bedroom sudo[2293]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: No valid Plugin REST Endpoint Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:32 gbvpi-bedroom sudo[2435]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:32 gbvpi-bedroom go-librespot[2443]: go-librespot daemon starting... Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: 20251207 02:15:32.415 [2413.2413] ERROR SampleApp: api request was not successful Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: Error: Application ID was not specified! Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -m|--manufacturer: Manufacturer of the device Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -n|--deviceName: Device name Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -l|--model: Device's model name Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -s|--serialNumber: Device's serial number Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -o|--outputDevice: ALSA PCM device to play audio to Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -p|--port: Port to run the local configuration HTTP server on Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 07 02:15:32 gbvpi-bedroom qobuz-connect[2413]: -h|--help: Print this help Dec 07 02:15:32 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:32 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:32-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:15:32 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:32-05:00" level=debug msg="app state loaded" Dec 07 02:15:32 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: No need to fix Spotify hosts Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Starting Shairport Sync Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Starting Shairport Sync Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Starting Shairport Sync Dec 07 02:15:32 gbvpi-bedroom sudo[2469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:15:32 gbvpi-bedroom sudo[2469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:32 gbvpi-bedroom sudo[2471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:15:32 gbvpi-bedroom sudo[2471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:15:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:15:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.691s CPU time. Dec 07 02:15:32 gbvpi-bedroom sudo[2477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 07 02:15:32 gbvpi-bedroom sudo[2477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:15:32 gbvpi-bedroom sudo[2469]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Shairport-Sync Started Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: Error adding Membership: Error: addMembership EINVAL Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 07 02:15:32 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully. Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:15:32 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 07 02:15:32 gbvpi-bedroom sudo[2471]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:32 gbvpi-bedroom sudo[2477]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Shairport-Sync Started Dec 07 02:15:32 gbvpi-bedroom volumio[2255]: info: Shairport-Sync Started Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: Listing playlists Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: Listing playlists Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: Listing playlists Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: Listing playlists Dec 07 02:15:33 gbvpi-bedroom mpd[2430]: 2025-12-07T02:15:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 07 02:15:33 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon. Dec 07 02:15:33 gbvpi-bedroom sudo[2400]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:33 gbvpi-bedroom sudo[2390]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: Completed starting Core Plugins Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: ----- MyVolumio plugins startup ---- Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: ------------------------------------------- Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: error: MPD error: The expression evaluated to a falsy value: Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: assert.ok(self.idling) Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: error: The expression evaluated to a falsy value: Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: assert.ok(self.idling) Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: error: updateQueue error: null Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: info: MPD running with PID2430 Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: ,establishing connection Dec 07 02:15:33 gbvpi-bedroom volumio[2255]: error: updateQueue error: null Dec 07 02:15:35 gbvpi-bedroom volumio[2255]: info: go-librespot daemon successfully initialized Dec 07 02:15:36 gbvpi-bedroom sudo[2502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:15:36 gbvpi-bedroom sudo[2502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:36 gbvpi-bedroom sudo[2504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 07 02:15:36 gbvpi-bedroom sudo[2504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:36 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 07 02:15:36 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 07 02:15:36 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 07 02:15:36 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 07 02:15:36 gbvpi-bedroom sudo[2504]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:36 gbvpi-bedroom sudo[2502]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:36 gbvpi-bedroom volumio[2255]: info: Successfully started MPD Monitor Dec 07 02:15:36 gbvpi-bedroom mpd_monitor.sh[2507]: MPD Monitor Service: Starting MPD Monitor Service Dec 07 02:15:36 gbvpi-bedroom volumio[2255]: info: Successfully started MPD Monitor Dec 07 02:15:36 gbvpi-bedroom volumio[2255]: info: Volumio called home Dec 07 02:15:37 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 2. Dec 07 02:15:37 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:37 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:37 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15: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-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:15:37 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:37-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:15:37 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:37-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:15:37 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:37-05:00" level=info msg="zeroconf server listening on port 33977" Dec 07 02:15:37 gbvpi-bedroom volumio[2255]: info: No valid Plugin REST Endpoint Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: 20251207 02:15:37.687 [2512.2512] ERROR SampleApp: api request was not successful Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: Error: Application ID was not specified! Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -m|--manufacturer: Manufacturer of the device Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -n|--deviceName: Device name Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -l|--model: Device's model name Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -s|--serialNumber: Device's serial number Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -o|--outputDevice: ALSA PCM device to play audio to Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -p|--port: Port to run the local configuration HTTP server on Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 07 02:15:37 gbvpi-bedroom qobuz-connect[2512]: -h|--help: Print this help Dec 07 02:15:37 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:37 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 07 02:15:38 gbvpi-bedroom volumio[2255]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 07 02:15:38 gbvpi-bedroom sudo[2529]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 07 02:15:38 gbvpi-bedroom sudo[2529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:38 gbvpi-bedroom sudo[2531]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 07 02:15:38 gbvpi-bedroom sudo[2529]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:38 gbvpi-bedroom sudo[2531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:38 gbvpi-bedroom sudo[2531]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:38 gbvpi-bedroom sudo[2534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 07 02:15:38 gbvpi-bedroom sudo[2534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:38 gbvpi-bedroom sudo[2534]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:38 gbvpi-bedroom volumio[2255]: info: Upmpdcli Daemon Started Dec 07 02:15:38 gbvpi-bedroom volumio[2255]: info: Initializing connection to go-librespot Websocket Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3 Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: Discovery: Found device NorthPi-Soundstation Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: Discovery: Connecting to remote: 192.168.1.28 Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: Discovery: Found device GBVPi-Bedroom Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:40 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Discovery: Connected to remote: 192.168.1.28 Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Discovery: Found device GBVPi-Bedroom Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:41 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:41-05:00" level=debug msg="new websocket client" Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Connection to go-librespot Websocket established Dec 07 02:15:41 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:41-05:00" level=debug msg="obtained new client token: AAB/90zMUqJij1lX5VLwQ/DbkSlrTA4X1l4dq1n6M7/UIzY68xww+4j1no+80W1K1tRYslGYFKVTpWfx5R4pQuZE9Kt6Litw8HOfd0n6pDxEI0dYCTWdr2y6icjRSwI5A7lGN07jpMQw0K4lUwBCYcUVgN3iCGO4SGYLciNJ2Hla7WGs5MDK5M3OofiQsme+ydI2vYoLdRmS3fkOQeF+bHySJjcTLlQSelUra5Rcwxa0MgtFKIbKY/eMxg==" Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:41 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin bluetooth to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin multiroom to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin metavolumio to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin cd_controller to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 07 02:15:41 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 07 02:15:41 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:41-05:00" level=debug msg="completed keyexchange" Dec 07 02:15:41 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:41-05:00" level=debug msg="completed challenge" Dec 07 02:15:42 gbvpi-bedroom go-librespot[2445]: time="2025-12-07T02:15:42-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:15:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:42 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: Starting MyVolumio Remote Streaming Endpoints Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: MyVolumio login type: Token Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 07 02:15:42 gbvpi-bedroom systemd[1]: qobuz-connect.service: Scheduled restart job, restart counter is at 3. Dec 07 02:15:42 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:42 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: Streaming services startup Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: Starting Streaming Daemon Dec 07 02:15:42 gbvpi-bedroom sudo[2539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 02:15:42 gbvpi-bedroom sudo[2539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:42 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 07 02:15:43 gbvpi-bedroom sudo[2539]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Discovery: Disconnected from remote: 192.168.1.28 Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Connection to go-librespot Websocket closed Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: error: Cannot start Volumio Streaming Daemon Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: An error occurred while refreshing Spotify Token Error: Bad Request Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: No valid Plugin REST Endpoint Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: 20251207 02:15:43.069 [2537.2537] ERROR SampleApp: api request was not successful Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: Error: Application ID was not specified! Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: Usage: /usr/local/bin/qobuz-connect-daemon [OPTIONS...] Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -m|--manufacturer: Manufacturer of the device Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -n|--deviceName: Device name Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -l|--model: Device's model name Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -s|--serialNumber: Device's serial number Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -o|--outputDevice: ALSA PCM device to play audio to Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -p|--port: Port to run the local configuration HTTP server on Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -q|--maxAudioQuality: Force maximum supported audio quality [CD, HIRES1, HIRES2, HIRES3] Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -v|--volumeDevice: ALSA mixer device to use to for volume & mute control Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -u|--volumeElement: Name of the element found on the volume device to use to for volume & mute control Dec 07 02:15:43 gbvpi-bedroom qobuz-connect[2537]: -h|--help: Print this help Dec 07 02:15:43 gbvpi-bedroom systemd[1]: qobuz-connect.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:43 gbvpi-bedroom systemd[1]: qobuz-connect.service: Failed with result 'exit-code'. Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::volumioGetState Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: CorePlayQueue::getTrack 0 Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MyVolumio token set successfully Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MYVOLUMIO: Adding device Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MYVOLUMIO: Evaluating Server Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Discovery: A device disappeared from network Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Discovery: Device northpi-soundstation disappeared from network Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MyVolumio Plan changed: premium Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Removing browser output: myVolumio user plan is not superstar Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Removing audio output: Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MYVOLUMIO: Adding device Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MYVOLUMIO: Evaluating Server Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Remote config written successfully Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Starting Tunnel 1 Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Starting Tunnel Connection Checker Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Completed starting MyVolumio Plugin Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MYVolumio Device enabled Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: MyVolumio status changed Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Streaming services startup Dec 07 02:15:43 gbvpi-bedroom volumio[2255]: info: Starting Streaming Daemon Dec 07 02:15:44 gbvpi-bedroom sudo[2585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 07 02:15:44 gbvpi-bedroom sudo[2585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: Setting Geolocation for MyVolumio to us1 Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:44 gbvpi-bedroom sudo[2585]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: error: Cannot start Volumio Streaming Daemon Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 07 02:15:44 gbvpi-bedroom sudo[2589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 07 02:15:44 gbvpi-bedroom sudo[2589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:44 gbvpi-bedroom sudo[2589]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: MRS: MultiRoom plugin initialized Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: MRS: STOPPING SNAPCLIENT Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: MRS: Snap server stop Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: MRS: STOPPING volumioStreaming Dec 07 02:15:44 gbvpi-bedroom sudo[2606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 07 02:15:44 gbvpi-bedroom sudo[2606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:44 gbvpi-bedroom sudo[2608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 07 02:15:44 gbvpi-bedroom sudo[2608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 07 02:15:44 gbvpi-bedroom sudo[2611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 07 02:15:44 gbvpi-bedroom sudo[2611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 07 02:15:44 gbvpi-bedroom sudo[2615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 07 02:15:44 gbvpi-bedroom sudo[2615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:44 gbvpi-bedroom sudo[2615]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 07 02:15:44 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 07 02:15:44 gbvpi-bedroom sudo[2608]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:45 gbvpi-bedroom sudo[2606]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 07 02:15:45 gbvpi-bedroom sudo[2611]: pam_unix(sudo:session): session closed for user root Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: Preparing to generate the ALSA configuration file Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: Updating MyVolumio device info Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: Getting Spotify volume Dec 07 02:15:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 07 02:15:45 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: Setting Geolocation for MyVolumio to us1 Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: info: Successfully Added MyVolumio device Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: errno: -111, Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: code: 'ECONNREFUSED', Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: syscall: 'connect', Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: address: '127.0.0.1', Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: port: 9879, Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: response: undefined Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: } Dec 07 02:15:45 gbvpi-bedroom volumio[2255]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 02:15:45 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 07 02:15:45 gbvpi-bedroom go-librespot[2617]: go-librespot daemon starting... Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=info msg="running go-librespot 0.4.0" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="app state loaded" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=info msg="zeroconf server listening on port 45123" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="obtained new client token: AAB43rkQE6k05V/M0XavpHiBk4Fea610nt2iqTwhd7pumTKMfe8BxGs6WeNVRt+IpNJmpjXO5jkrNT+kuyeoJVLhgwBhKAcY8k3ZZbm0tiApav4e/EfywvRiZDrEs2Fks1re+TQ1m23kk1Msxp2H0vDh/devXiUz/oKiuPF5o539AJPK7NGmnUMdDoHlapKkTbeEmzr2azwVR4gRfWlpI0m+ATuai2cEosQ5k6QBQ/D+gBe9FZVS3g//NQ==" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="completed keyexchange" Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=debug msg="completed challenge" Dec 07 02:15:45 gbvpi-bedroom sudo[2640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-07 02:14' Dec 07 02:15:45 gbvpi-bedroom sudo[2640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 07 02:15:45 gbvpi-bedroom go-librespot[2621]: time="2025-12-07T02:15:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Dec 07 02:15:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 07 02:15:45 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"