Dec 06 18:28:00 gbvpi-bedroom volumio[3951]: info: Discovery: Disconnected from remote: 192.168.1.28
Dec 06 18:28:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Dec 06 18:28:01 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:01 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4254]: go-librespot daemon starting...
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin multiroom to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="app state loaded"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=info msg="zeroconf server listening on port 38791"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="obtained new client token: AACGP9phs5FXMKaF5eG2OL2ameWDiPkM6jtBmQxB6JwQ8M8ENr+9d5Rd3lvr4WCTi704z3uAKhTCcFNOd/oA7kLoDD7NdlrJZzlgxdrSOzpL+o0OA53zFPh3j44FOfWLVoq3r59KEauUDCxN8JH9zgJC/bDikbbynwD8t9Z42kugFjh1owuvCwoCyDzt84eYXD8pY0CZDYwZdKn14ODkf2mymImDtx1y7gUDVEZGJDDwhh/ZLK7tM/dnew=="
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=debug msg="completed challenge"
Dec 06 18:28:01 gbvpi-bedroom go-librespot[4255]: time="2025-12-06T18:28:01-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:01 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: MyVolumio login type: Token
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 06 18:28:01 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: Streaming services startup
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: Starting Streaming Daemon
Dec 06 18:28:02 gbvpi-bedroom sudo[4263]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 18:28:02 gbvpi-bedroom sudo[4263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 06 18:28:02 gbvpi-bedroom sudo[4263]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: error: Cannot start Volumio Streaming Daemon
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: Discovery: A device disappeared from network
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: Discovery: Device northpi-soundstation disappeared from network
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:02 gbvpi-bedroom volumio[3951]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MyVolumio token set successfully
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MYVOLUMIO: Adding device
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MYVOLUMIO: Evaluating Server
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MyVolumio Plan changed: premium
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Removing browser output: myVolumio user plan is not superstar
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Removing audio output:
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MYVOLUMIO: Adding device
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MYVOLUMIO: Evaluating Server
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Remote config written successfully
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Starting Tunnel 1
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Starting Tunnel Connection Checker
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Completed starting MyVolumio Plugin
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MYVolumio Device enabled
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: MyVolumio status changed
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Streaming services startup
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: Starting Streaming Daemon
Dec 06 18:28:03 gbvpi-bedroom sudo[4308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 18:28:03 gbvpi-bedroom sudo[4308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"...
Dec 06 18:28:03 gbvpi-bedroom sudo[4308]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart
Dec 06 18:28:03 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "multiroom"...
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Dec 06 18:28:04 gbvpi-bedroom sudo[4312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Dec 06 18:28:04 gbvpi-bedroom sudo[4312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom sudo[4312]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: MultiRoom plugin initialized
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: STOPPING SNAPCLIENT
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: Snap server stop
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: STOPPING volumioStreaming
Dec 06 18:28:04 gbvpi-bedroom sudo[4329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Dec 06 18:28:04 gbvpi-bedroom sudo[4329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Dec 06 18:28:04 gbvpi-bedroom sudo[4331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Dec 06 18:28:04 gbvpi-bedroom sudo[4331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom sudo[4333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Dec 06 18:28:04 gbvpi-bedroom sudo[4333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Dec 06 18:28:04 gbvpi-bedroom sudo[4337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Dec 06 18:28:04 gbvpi-bedroom sudo[4337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Dec 06 18:28:04 gbvpi-bedroom sudo[4337]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Dec 06 18:28:04 gbvpi-bedroom sudo[4329]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Dec 06 18:28:04 gbvpi-bedroom sudo[4333]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"...
Dec 06 18:28:04 gbvpi-bedroom sudo[4331]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Preparing to generate the ALSA configuration file
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Setting Geolocation for MyVolumio to us4
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Reading ALSA contributions from plugins.
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Setting Geolocation for MyVolumio to us1
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: Removed streaming files
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: volumioStreaming STOPPED
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: SNAPSERVER STOPPED
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: SNAPCLIENT STOPPED
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: error: Cannot start Volumio Streaming Daemon
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Asound.conf file written
Dec 06 18:28:04 gbvpi-bedroom sudo[4343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 06 18:28:04 gbvpi-bedroom sudo[4343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom sudo[4343]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Output device has changed, restarting MPD
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Output device has changed, restarting Shairport Sync
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom sudo[4349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 18:28:04 gbvpi-bedroom sudo[4349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom sudo[4349]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 06 18:28:04 gbvpi-bedroom sudo[4353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 18:28:04 gbvpi-bedroom sudo[4353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output for this device
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding audio output:
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding audio output:
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.939s CPU time.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Dec 06 18:28:04 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.29107
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding METAVOLUMIO REST API Endpoints
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Preparing CD Folders
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding CD REST API Endpoints
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Starting UDEV Watcher for CD
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: Detecting CD presence with UDEV
Dec 06 18:28:04 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Dec 06 18:28:04 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.29107 disconnected from D-Bus
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:04 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:04 gbvpi-bedroom go-librespot[4370]: go-librespot daemon starting...
Dec 06 18:28:04 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:04-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:04 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:04-05:00" level=debug msg="app state loaded"
Dec 06 18:28:04 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:04-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:04 gbvpi-bedroom sudo[4369]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 18:28:04 gbvpi-bedroom sudo[4369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 18:28:04 gbvpi-bedroom sudo[4369]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=info msg="zeroconf server listening on port 40425"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="obtained new client token: AADL19seGU2alYOIkj6UolPTdrIdhr5wsv1Cme1D10X/sCskJKB8d7FfbK75E/dUNtCNJwa4P0CaV6CFwl4b5syliAGIUy7areDi7R+dwxDZFQOyO5jO5XKbrcj2An3adcuSDAAgjjimDWuacZob1wJG7EWpahB+mBMYgfyX33ghvQlef9MAgxECgkvgTkvT2PmD+M/fn/FLe8rzFMv/67Y6hWzoDmI2avIKhV7872rZlskqL/D1xxo="
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=debug msg="completed challenge"
Dec 06 18:28:05 gbvpi-bedroom go-librespot[4371]: time="2025-12-06T18:28:05-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:05 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:06 gbvpi-bedroom mpd[4378]: 2025-12-06T18:28:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 18:28:06 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 18:28:06 gbvpi-bedroom sudo[4353]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:08 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Dec 06 18:28:08 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:08 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4396]: go-librespot daemon starting...
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=debug msg="app state loaded"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=info msg="zeroconf server listening on port 40977"
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=debug msg="obtained new client token: AABxp7XEkol75D4CAtuDw7gsBM0gg38EHScrZd7dih1OEdrRU0fUqKXz3A7FcozmHePvvLSy6KX2vmEx2Z+0q9SYHxyrnRTuygqOODsXRQX719yABFHFi2nsXIbEWvKDYPjRf2btPm/UneatyAiY7o96sVMe0tyNOplAHTCE12Edi0xk1HyAlX+Xq+iKuo/Ry1++GVcleZdYgrPhGMev0Sma8F9X0J3B8Ddq7PCLlP2I47+riT0bnevP0A=="
Dec 06 18:28:08 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:09 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:09-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:09 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:09-05:00" level=debug msg="completed challenge"
Dec 06 18:28:09 gbvpi-bedroom go-librespot[4397]: time="2025-12-06T18:28:09-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:09 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: warn: [cd-plugin] cdspeedctl: device or media not ready
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding inputs REST Endpoints
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Scanning Audio Inputs
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Checking against Known Cards name
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding Server instance for streaming
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: error: Hi Res Audio Failed Login: Missing Login Data
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding HIGHRESAUDIO REST API Endpoints
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Dec 06 18:28:09 gbvpi-bedroom sudo[4408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: QobuzConnect: Starting Qobuz Connect socket and service
Dec 06 18:28:09 gbvpi-bedroom sudo[4408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding TIDAL REST API Endpoints
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Stopping AccessToken refresher cron for QOBUZ
Dec 06 18:28:09 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service...
Dec 06 18:28:09 gbvpi-bedroom sudo[4415]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Dec 06 18:28:09 gbvpi-bedroom systemd[1]: vtcs.service: Killing process 3856 (vtcs) with signal SIGKILL.
Dec 06 18:28:09 gbvpi-bedroom sudo[4415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:09 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully.
Dec 06 18:28:09 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service.
Dec 06 18:28:09 gbvpi-bedroom sudo[4408]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: AccessToken refresher cron started for QOBUZ
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Adding QOBUZ REST API Endpoints
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Updating MyVolumio device info
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: Updating MyVolumio device info
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: MRS: Getting audio outputs on start
Dec 06 18:28:09 gbvpi-bedroom volumio[3951]: info: MRS: Requesting all other devices output
Dec 06 18:28:09 gbvpi-bedroom sudo[4415]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:09 gbvpi-bedroom sudo[4419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Dec 06 18:28:09 gbvpi-bedroom sudo[4419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Successfully Added MyVolumio device
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Successfully Added MyVolumio device
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Dec 06 18:28:10 gbvpi-bedroom qobuz-connect[3817]: 20251206 18:28:10.017 [3817.3817] INFO SampleApp: Stopping Local configuration server
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: MPD Permissions set
Dec 06 18:28:10 gbvpi-bedroom sudo[4422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Dec 06 18:28:10 gbvpi-bedroom sudo[4422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:10 gbvpi-bedroom sudo[4422]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: error: updateQueue error: null
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioStop
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreStateMachine::stop
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Starting Shairport Sync
Dec 06 18:28:10 gbvpi-bedroom sudo[4438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Dec 06 18:28:10 gbvpi-bedroom sudo[4438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Adding audio output:
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Discovery: Found device NorthPi-Soundstation
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Discovery: Connecting to remote: 192.168.1.28
Dec 06 18:28:10 gbvpi-bedroom sudo[4440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:10 gbvpi-bedroom sudo[4440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Adding audio output:
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Successfully Updated MyVolumio device
Dec 06 18:28:10 gbvpi-bedroom autossh[3789]: received signal to exit (15)
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully.
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: MRS: Pushing audio output on request
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Discovery: Connected to remote: 192.168.1.28
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Successfully Updated MyVolumio device
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 18:28:10 gbvpi-bedroom sudo[4438]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.628s CPU time.
Dec 06 18:28:10 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:10 gbvpi-bedroom sudo[4440]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Remote SSH Started
Dec 06 18:28:10 gbvpi-bedroom autossh[4444]: port set to 0, monitoring disabled
Dec 06 18:28:10 gbvpi-bedroom autossh[4444]: starting ssh (count 1)
Dec 06 18:28:10 gbvpi-bedroom autossh[4444]: ssh child pid is 4448
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: Shairport-Sync Started
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Dec 06 18:28:10 gbvpi-bedroom volumiossh-tunnel[4448]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts.
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:10 gbvpi-bedroom volumio[3951]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 06 18:28:11 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully.
Dec 06 18:28:11 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 06 18:28:11 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 06 18:28:11 gbvpi-bedroom sudo[4419]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:11 gbvpi-bedroom volumio[3951]: info: Executing endpoint qc_getconfig
Dec 06 18:28:11 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.725 [4463.4463] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Dec 06 18:28:11 gbvpi-bedroom volumio[3951]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Dec 06 18:28:11 gbvpi-bedroom volumio[3951]: info: QobuzConnect: QOBUZ Connect daemon connected
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.729 [4463.4463] INFO VolumeManager: [0x14f5588]: Setting new playback volume: 75
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.729 [4463.4463] INFO VolumeManager: [0x14f5588]: Setting new mute state: 0
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.729 [4463.4463] INFO QobuzConnect: [0x14f5f58]: Client initialized!
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.729 [4463.4463] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.746 [4463.4463] INFO LocalConfigManager: [0x14f4e68]: Starting Local Configuration server
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.746 [4463.4463] INFO SampleApp: Starting Local configuration server
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.747 [4463.4463] INFO SampleApp: Connected to UNIX socket client 0x14df818
Dec 06 18:28:11 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:11.875 [4463.4463] INFO SampleApp: Playback volume changed: 75
Dec 06 18:28:11 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Dec 06 18:28:12 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:12 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4469]: go-librespot daemon starting...
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="app state loaded"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=info msg="zeroconf server listening on port 44531"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="obtained new client token: AABzdav1ScFDqcwq06yXA2RaG+Veyhba9dK8USPe8hjhGRtuG2DDmAskhNdrhdkzAgF50nes9DzURm8Ob4szOyTSXsHs+e1o0YgXWEL2oMdDxFzOSE++pH0dB35a+9sP0yoVtz82vul8ikPUQbRK4XSlpOJth7h9va+2yO/vcB+VlrSbun7AoLryFrPjQtrhvIHORS3mTLVtu06Ex4PV40kpMptVtwM0oTzsaIezuJyZUciwENf/hHcOPA=="
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28:12-05:00" level=debug msg="completed challenge"
Dec 06 18:28:12 gbvpi-bedroom go-librespot[4471]: time="2025-12-06T18:28: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 06 18:28:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:12 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:12 gbvpi-bedroom volumio[3951]: info: TidalConnect service stoped!
Dec 06 18:28:12 gbvpi-bedroom volumio[3951]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 06 18:28:12 gbvpi-bedroom volumio[3951]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 06 18:28:13 gbvpi-bedroom sudo[4487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 06 18:28:13 gbvpi-bedroom sudo[4487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:13 gbvpi-bedroom sudo[4491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 18:28:13 gbvpi-bedroom sudo[4491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:13 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Dec 06 18:28:13 gbvpi-bedroom sudo[4487]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:13 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 18:28:13 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 18:28:13 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 18:28:13 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 18:28:13 gbvpi-bedroom sudo[4491]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:13 gbvpi-bedroom mpd_monitor.sh[4495]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Successfully started MPD Monitor
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Executing endpoint tc_getconfig
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 06 18:28:13 gbvpi-bedroom vtcs[4493]: STARTING TidalConnect services, version: 1.5.2.56
Dec 06 18:28:13 gbvpi-bedroom vtcs[4493]: STARTED TidalConnect services.
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Executing endpoint tc_connect
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Connecting to TidalConnect
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::servicePushState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreStateMachine::pushState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output update for this device
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::servicePushState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreStateMachine::pushState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output update for this device
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect
Dec 06 18:28:13 gbvpi-bedroom volumio[3951]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Dec 06 18:28:16 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: TidalConnect service started!
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: [Metrics] CommandRouter: 29s 165.72ms
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::Close All Modals sent
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::Close All Modals sent
Dec 06 18:28:16 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4513]: go-librespot daemon starting...
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="app state loaded"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=info msg="zeroconf server listening on port 40077"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="obtained new client token: AABPm83EP9Rpz6so1EAdtfxfajhbCrPDDojsDgY/oVOeYK6du8sy63E7qnjp9DyZKBu/CLEwqWp2bisNVcrUMxYf3bJ5VXN0G7YpqCKwNb8y/xPx3FxoDpl62TnvR7sOclKxHe1dRBfQYtF4ZayyUGG/PtrKAgrYAXyNT5k78g9bkiDEymlPkCttMPH9AsTL6IzfdLS5/kfG70ZV2Gc4lUzg8fCBw3O/HQkmi2U9/WsOjmuS67BSfIPRNQ=="
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=debug msg="completed challenge"
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: Listing playlists
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: Listing playlists
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: Listing playlists
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: Listing playlists
Dec 06 18:28:16 gbvpi-bedroom go-librespot[4514]: time="2025-12-06T18:28:16-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:16 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Dec 06 18:28:16 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:17 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 06 18:28:17 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 06 18:28:17 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 06 18:28:19 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:19 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:19 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Dec 06 18:28:19 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:19 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:19 gbvpi-bedroom go-librespot[4538]: go-librespot daemon starting...
Dec 06 18:28:19 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:19-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:19 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:19-05:00" level=debug msg="app state loaded"
Dec 06 18:28:19 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:19-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=info msg="zeroconf server listening on port 35575"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="obtained new client token: AAAVHjFEiPcjkYKRjbBglzGdNBCUuPdwZPwfBkzkNK7MMpT34jrQOPzZx7s/LZo/E/hICj4V5DCrdGcBw4I7o3UEuswgVLF71MP8pBO8Bn9Li1qBuQXQoN8Bz/vwv2NZMhoG+NuxLt0EwPK3Tvozm/gcyJmfrzhZwc4qSoC1uvIc7+9nxDdPIczFi9R7sG5ohHbXdhMvEBJECXNTz+xbc9ZHmVj3gAo0PzNXF1ANgdyjXfOHM8zNnoY="
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=debug msg="completed challenge"
Dec 06 18:28:20 gbvpi-bedroom go-librespot[4539]: time="2025-12-06T18:28:20-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:20 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:20 gbvpi-bedroom volumio[3951]: info: MRS: Adding multiroomSync output
Dec 06 18:28:20 gbvpi-bedroom volumio[3951]: info: Adding audio output:
Dec 06 18:28:20 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 06 18:28:21 gbvpi-bedroom volumio-remote-updater[11354]: Test mode enabled
Dec 06 18:28:21 gbvpi-bedroom volumio-remote-updater[11354]: Alpha mode disabled
Dec 06 18:28:21 gbvpi-bedroom volumio-remote-updater[11354]: Alpha legacy test mode disabled
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"ANNOUNCEMENT
\n\n- Production line
\n
\nFIX
\n\n- Nodejs 20.5.1 version pinning with static package fallback
\n
\n","title":"Update v4.073","updateavailable":true}
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 06 18:28:21 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:22 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:22 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:23 gbvpi-bedroom volumio[3951]: info: BOOT COMPLETED
Dec 06 18:28:23 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Dec 06 18:28:23 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:23 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4550]: go-librespot daemon starting...
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=debug msg="app state loaded"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=info msg="zeroconf server listening on port 43787"
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=debug msg="obtained new client token: AACSt1YvS9WcvhLxtjnVRwCiw+exG6FdgePT2TPBsxo4ELtPwIO+3p92FDP6JQ4KF3qiGHa0nxHxWwiFoWKNWiRKWFazxJA/yAaaurZMFxR79JQcvWDNGKogNF9IkkaQHp7tMd2WY0pVFEcHZqGIiVOzI4kxAX5aFRqAyM3fKi2d206d1s9ubnT14IC9qwIYtEADW8BP7M4RcpipcSW2zqeHepPJlDYE7nyak2As254QXR3PwhG0kJiGDA=="
Dec 06 18:28:23 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:24 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:24-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:24 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:24-05:00" level=debug msg="completed challenge"
Dec 06 18:28:24 gbvpi-bedroom go-librespot[4551]: time="2025-12-06T18:28:24-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:24 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:25 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:25 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:25 gbvpi-bedroom volumio[3951]: info: MRS: Pushing audio output on request
Dec 06 18:28:25 gbvpi-bedroom volumio[3951]: info: MRS: Pushing multiroomSync output
Dec 06 18:28:26 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:26 gbvpi-bedroom volumio[3951]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Dec 06 18:28:27 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:27 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4558]: go-librespot daemon starting...
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="app state loaded"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=info msg="zeroconf server listening on port 37811"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="obtained new client token: AACDJEXV7RZRBXqKYqfmGaKyANSlYXaRR3BeGI+XwmE9nVSPXBeznzM4VeRfcfN0zOpcLaexSOb8PnNN+Zgf0eu9tVD4FtWgKknVbij950jJjsLaV1z4JW9HTMZtTG7pyeaCkKECKC6CUrdi206hQpqllxpTbWFv2o0VCHuCDEl3Mm3EOF28sYojutzDFJyx7P3H63cvjHcy0AFLr4X5ZQWd9hz+O3ulRIIseljLthCyjunAoXR2jxr/cg=="
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=debug msg="completed challenge"
Dec 06 18:28:27 gbvpi-bedroom go-librespot[4559]: time="2025-12-06T18:28:27-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:27 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:28 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:28 gbvpi-bedroom volumio[3951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:28 gbvpi-bedroom volumio[3951]: info: MRS: Updating multiroomSync output
Dec 06 18:28:28 gbvpi-bedroom volumio[3951]: info: MRS: Updating multiroomSync output
Dec 06 18:28:30 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Dec 06 18:28:30 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:30 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:30 gbvpi-bedroom go-librespot[4580]: go-librespot daemon starting...
Dec 06 18:28:30 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:30-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:30 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:30-05:00" level=debug msg="app state loaded"
Dec 06 18:28:30 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:30-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=info msg="zeroconf server listening on port 46761"
Dec 06 18:28:31 gbvpi-bedroom volumio[3951]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="new websocket client"
Dec 06 18:28:31 gbvpi-bedroom volumio[3951]: info: Connection to go-librespot Websocket established
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="obtained new client token: AACut+WKshzYDgSxhgDAKyjXJ4eJMuDpgtl5IAXBAmnRY5A9RjXX1PrNBw37K6IdieOWnaZrGgilbrc3tb8L2/EgfjtqVtGhvEOpx75cpjNrVZL9tUrma5oB5mxkGoixlCLcHtganlx+6k+6l72tTEHBmfyFrptqDk5cSCcDkSnHE4Q29t/9pqgXJwtjz+NsTO4kVsBM/sfoKONf00zrhEQCqCxJru6UT/g3fYpVt6muJCg2TdRcd/k="
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=debug msg="completed challenge"
Dec 06 18:28:31 gbvpi-bedroom go-librespot[4581]: time="2025-12-06T18:28:31-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:31 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:31 gbvpi-bedroom volumio[3951]: info: Connection to go-librespot Websocket closed
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: info: Getting Spotify volume
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: errno: -111,
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: code: 'ECONNREFUSED',
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: syscall: 'connect',
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: address: '127.0.0.1',
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: port: 9879,
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: response: undefined
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: }
Dec 06 18:28:34 gbvpi-bedroom volumio[3951]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4604]: go-librespot daemon starting...
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="app state loaded"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:34 gbvpi-bedroom sudo[4614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 18:27'
Dec 06 18:28:34 gbvpi-bedroom sudo[4614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=info msg="zeroconf server listening on port 33717"
Dec 06 18:28:34 gbvpi-bedroom sudo[4614]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:34 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:28:34.719 [4463.4463] INFO SampleApp: Socket closed
Dec 06 18:28:34 gbvpi-bedroom vtcs[4493]: [2025-12-06 18:28:34.719] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected
Dec 06 18:28:34 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:34] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Dec 06 18:28:34 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:34] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.339s CPU time.
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="obtained new client token: AACIm5UVI1SCEs19GOBiq1qE03CvbdXYx6U7RyRJjScn65HfCdD/nh+KGkytsNRu/2Vzhfv6p/O9tqpvfCzK3dhzztg96UB6Y72YzIx3SVRmuVXuu5f1h1P6Kj4JA41ohuhYfrIka5Njysb4w2iFBnGbuPYMt5AF4GZMuSIPLkb1xX8Nz8jWJ3FlW3NQLXWGl6xYt6sjAshll/0j093WN/QltNvDFLw452+ftPX/7/5YYky8KmrE9idCCw=="
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=debug msg="completed challenge"
Dec 06 18:28:34 gbvpi-bedroom go-librespot[4605]: time="2025-12-06T18:28:34-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1818.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: volumio.service: Consumed 21.339s CPU time.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 06 18:28:34 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 18:28:35 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:35 gbvpi-bedroom volumio[4626]: info: ----- Volumio3 ----
Dec 06 18:28:35 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:35 gbvpi-bedroom volumio[4626]: info: ----- System startup ----
Dec 06 18:28:35 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: MYVOLUMIO Environment detected
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Plugin folders cleanup
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning into folder /volumio/app/plugins/
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category audio_interface
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category miscellanea
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category music_service
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category plugins.json
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category system_controller
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category user_interface
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning into folder /data/plugins/
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Scanning category music_service
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Plugin folders cleanup completed
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: ----- Core plugins startup ----
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Loading plugins from folder /volumio/app/plugins/
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Adding plugin upnp to MyMusic Plugins
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Loading plugins from folder /data/plugins/
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Loading plugin "system"...
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Loading plugin "appearance"...
Dec 06 18:28:36 gbvpi-bedroom volumio[4626]: info: Loading plugin "network"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Refreshing Cached IP Addresses
Dec 06 18:28:37 gbvpi-bedroom sudo[4654]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 18:28:37 gbvpi-bedroom sudo[4654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:37 gbvpi-bedroom sudo[4656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "services"...
Dec 06 18:28:37 gbvpi-bedroom sudo[4656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:37 gbvpi-bedroom sudo[4654]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "alsa_controller"...
Dec 06 18:28:37 gbvpi-bedroom sudo[4656]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:37 gbvpi-bedroom sudo[4663]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 06 18:28:37 gbvpi-bedroom sudo[4663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "wizard"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "networkfs"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Starting Udev Watcher for removable devices
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Ignoring mount for partition: boot
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Ignoring mount for partition: volumio
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Ignoring mount for partition: volumio_data
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "volumio_command_line_client"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "upnp"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: [1765063717139] Starting Upmpd Daemon
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "my_music"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "mpd"...
Dec 06 18:28:37 gbvpi-bedroom volumio[4626]: info: Loading plugin "upnp_browser"...
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "alarm-clock"...
Dec 06 18:28:38 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Dec 06 18:28:38 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "airplay_emulation"...
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Starting Shairport Sync
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "last_100"...
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "webradio"...
Dec 06 18:28:38 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4687]: go-librespot daemon starting...
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=debug msg="app state loaded"
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "i2s_dacs"...
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: I2S DAC not set, start Auto-detection
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "volumiodiscovery"...
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: *** WARNING *** For more information see
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: *** WARNING *** For more information see
Dec 06 18:28:38 gbvpi-bedroom node[4626]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:38 gbvpi-bedroom node[4626]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:38 gbvpi-bedroom node[4626]: *** WARNING *** For more information see
Dec 06 18:28:38 gbvpi-bedroom node[4626]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:38 gbvpi-bedroom node[4626]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:38 gbvpi-bedroom node[4626]: *** WARNING *** For more information see
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Discovery: Started advertising with name: GBVPi-Bedroom
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "jellyfin"...
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=info msg="zeroconf server listening on port 34839"
Dec 06 18:28:38 gbvpi-bedroom volumio[4626]: info: Loading plugin "spop"...
Dec 06 18:28:38 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:38-05:00" level=debug msg="obtained new client token: AABmmSJSvyygdk9AScV0TZB4+NHn4jfAfAxZkR7ZhZSJjKkxOdla4FCYM50IzeIUZ2leciToBDxufFu4kjeNrat/RuvLokuzKSuadq6HdZd+B22+J2b7t3AtSdsm1OmfuVp+GI2u0hkZxt9fko1gzVJHMnaOwfzoWXYv4XRStbnoXbKrOAgyVzbois3nhtu6PPUB8X7cCGC1txQl4wnf7qtu9FfWaehA8Vj0cQ5gvbRb103kpxXS8gA6Dg=="
Dec 06 18:28:39 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:39-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading plugin "outputs"...
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading plugin "albumart"...
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Plugin example_plugin is not enabled
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading plugin "inputs"...
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading plugin "updater_comm"...
Dec 06 18:28:39 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:39-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:39 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:39-05:00" level=debug msg="completed challenge"
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Plugin mpdemulation is not enabled
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading plugin "rest_api"...
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading plugin "websocket"...
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Starting Socket.io Server version 1.7.4
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Loading i18n strings for locale en
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: Updating browse sources language
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::initPlayerControls
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: Express server listening on port 3000
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: [Metrics] WebUI: 3s 699.08ms
Dec 06 18:28:39 gbvpi-bedroom go-librespot[4688]: time="2025-12-06T18:28:39-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::resetVolumioState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::getcurrentVolume
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Volumio Network Manager: Network status updated: 2
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:39 gbvpi-bedroom volumio[4697]: Forking 3 albumart workers
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: VolumeController:: Volume=91 Mute =false
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::pushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::updateTrackBlock
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrackBlock
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Reloading queue from file
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Setting Device type: Raspberry PI
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::setRepeat null single undefined
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::pushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::setRandom null
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::pushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Listing playlists
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Listing playlists
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Listing playlists
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Listing playlists
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: VolumeController:: Volume=91 Mute =false
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreStateMachine::pushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Discovery: A device disappeared from network
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Discovery: Browse raised the following error TypeError: Cannot read properties of undefined (reading 'toLowerCase')
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Completed loading Core Plugins
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Preparing to generate the ALSA configuration file
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Asound.conf file written
Dec 06 18:28:39 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:39] [connect] Successful connection
Dec 06 18:28:39 gbvpi-bedroom sudo[4755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 06 18:28:39 gbvpi-bedroom sudo[4755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:39 gbvpi-bedroom sudo[4755]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Output device has changed, restarting MPD
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Output device has changed, restarting Shairport Sync
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom sudo[4762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 18:28:39 gbvpi-bedroom sudo[4762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:39 gbvpi-bedroom sudo[4763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 18:28:39 gbvpi-bedroom sudo[4763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: ___________ START PLUGINS ___________
Dec 06 18:28:39 gbvpi-bedroom sudo[4762]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: ControllerMpd::onStart: Initializing MPD
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Creating MPD Configuration file
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 18:28:39 gbvpi-bedroom sudo[4771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 18:28:39 gbvpi-bedroom sudo[4771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.297s CPU time.
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 18:28:39 gbvpi-bedroom sudo[4771]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: [1765063719939] CoreMusicLibrary::Adding element Media Servers
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:39 gbvpi-bedroom sudo[4775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 18:28:39 gbvpi-bedroom sudo[4775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:39 gbvpi-bedroom volumio[4626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:39 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: [1765063720066] CoreMusicLibrary::Adding element Last_100
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: [1765063720069] CoreMusicLibrary::Adding element Webradio
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:40 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Initializing BBC Radios
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:40 gbvpi-bedroom sudo[4788]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 18:28:40 gbvpi-bedroom sudo[4788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Discovery: Getting this device information
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 06 18:28:40 gbvpi-bedroom sudo[4788]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: [1765063720252] CoreMusicLibrary::Adding element Jellyfin
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: Cannot find translation for source Jellyfin
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"}
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Creating Spotify config file
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:40 gbvpi-bedroom volumio[4716]: Starting albumart workers
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Volumio Calling Home
Dec 06 18:28:40 gbvpi-bedroom volumio[4715]: Starting albumart workers
Dec 06 18:28:40 gbvpi-bedroom volumio[4718]: Starting albumart workers
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: MPD Permissions set
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: MPD Permissions set
Dec 06 18:28:40 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765063719 101
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Dec 06 18:28:40 gbvpi-bedroom volumio[4626]: info: Spotify config file written
Dec 06 18:28:41 gbvpi-bedroom sudo[4814]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 06 18:28:41 gbvpi-bedroom sudo[4814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom sudo[4663]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4816]: go-librespot daemon starting...
Dec 06 18:28:41 gbvpi-bedroom sudo[4814]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: No need to fix Spotify hosts
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=debug msg="app state loaded"
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Volumio called home
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Starting Shairport Sync
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Starting Shairport Sync
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=info msg="zeroconf server listening on port 45459"
Dec 06 18:28:41 gbvpi-bedroom sudo[4847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:41 gbvpi-bedroom sudo[4847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Starting Shairport Sync
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 18:28:41 gbvpi-bedroom sudo[4850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:41 gbvpi-bedroom sudo[4850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.686s CPU time.
Dec 06 18:28:41 gbvpi-bedroom sudo[4852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:41 gbvpi-bedroom sudo[4852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:41 gbvpi-bedroom sudo[4847]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Shairport-Sync Started
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=debug msg="obtained new client token: AABaaca4DC94Ja50Nff9hVqBmTR8Om8NXnEFGDzxhLb5IMg+jqlno/AZcaVnGEy1kxtOITF4mEKnfuDS/zPMtHRFLWsDPPAT4DqQBdw41CvFq/61kM7TU3KIPxJEYnARx0bBuiFOgCDsw3a3gvpo9U5wxQ0p+KJLuPpkP+qE9YF2YVBhdgAkStI08NStt1RDAZdzxE+Zq+TLDXEHgbVMy6UmJORHt49ALlXwohhnK/iL5uNcmcxDS2wwPg=="
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: Error adding Membership: Error: addMembership EINVAL
Dec 06 18:28:41 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:41 gbvpi-bedroom sudo[4850]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:41 gbvpi-bedroom sudo[4852]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Shairport-Sync Started
Dec 06 18:28:41 gbvpi-bedroom volumio[4626]: info: Shairport-Sync Started
Dec 06 18:28:41 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:42 gbvpi-bedroom mpd[4803]: 2025-12-06T18:28:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 18:28:42 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 18:28:42 gbvpi-bedroom sudo[4763]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:42 gbvpi-bedroom sudo[4775]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: info: Completed starting Core Plugins
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: info: ----- MyVolumio plugins startup ----
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: info: -------------------------------------------
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: assert.ok(self.idling)
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: error: The expression evaluated to a falsy value:
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: assert.ok(self.idling)
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: info: MPD running with PID4803
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: ,establishing connection
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: error: updateQueue error: null
Dec 06 18:28:42 gbvpi-bedroom volumio[4626]: error: updateQueue error: null
Dec 06 18:28:43 gbvpi-bedroom volumio[4626]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3
Dec 06 18:28:43 gbvpi-bedroom volumio[4626]: info: Discovery: Found device NorthPi-Soundstation
Dec 06 18:28:43 gbvpi-bedroom volumio[4626]: info: Discovery: Connecting to remote: 192.168.1.28
Dec 06 18:28:43 gbvpi-bedroom volumio[4626]: info: Discovery: this is already registered, 357de02c-99c5-4ddd-be16-8ae369ed89c3
Dec 06 18:28:43 gbvpi-bedroom volumio[4626]: info: Discovery: Found device NorthPi-Soundstation
Dec 06 18:28:43 gbvpi-bedroom volumio[4626]: info: Discovery: Connecting to remote: 192.168.1.28
Dec 06 18:28:43 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:43-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:43 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:43-05:00" level=debug msg="completed challenge"
Dec 06 18:28:43 gbvpi-bedroom go-librespot[4823]: time="2025-12-06T18:28:43-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:43 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:44 gbvpi-bedroom volumio[4626]: info: Discovery: Connected to remote: 192.168.1.28
Dec 06 18:28:44 gbvpi-bedroom volumio[4626]: info: go-librespot daemon successfully initialized
Dec 06 18:28:45 gbvpi-bedroom sudo[4878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 18:28:45 gbvpi-bedroom sudo[4878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:45 gbvpi-bedroom sudo[4880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 18:28:45 gbvpi-bedroom sudo[4880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:45 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 18:28:45 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 18:28:45 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 18:28:45 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 18:28:45 gbvpi-bedroom sudo[4878]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:45 gbvpi-bedroom volumio[4626]: info: Successfully started MPD Monitor
Dec 06 18:28:45 gbvpi-bedroom mpd_monitor.sh[4883]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 18:28:45 gbvpi-bedroom sudo[4880]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:45 gbvpi-bedroom volumio[4626]: info: Successfully started MPD Monitor
Dec 06 18:28:46 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:46 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:46 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:46 gbvpi-bedroom volumio[4626]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Dec 06 18:28:47 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:47 gbvpi-bedroom volumio[4626]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Dec 06 18:28:47 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4895]: go-librespot daemon starting...
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="app state loaded"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:47 gbvpi-bedroom sudo[4909]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 18:28:47 gbvpi-bedroom sudo[4909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:47 gbvpi-bedroom sudo[4909]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:47 gbvpi-bedroom sudo[4911]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 18:28:47 gbvpi-bedroom sudo[4911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:47 gbvpi-bedroom sudo[4911]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:47 gbvpi-bedroom sudo[4915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 06 18:28:47 gbvpi-bedroom sudo[4915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:47 gbvpi-bedroom sudo[4915]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:47 gbvpi-bedroom volumio[4626]: info: Upmpdcli Daemon Started
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=info msg="zeroconf server listening on port 41801"
Dec 06 18:28:47 gbvpi-bedroom volumio[4626]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="new websocket client"
Dec 06 18:28:47 gbvpi-bedroom volumio[4626]: info: Connection to go-librespot Websocket established
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="obtained new client token: AAAFR/UotnCKD4N3uSI4uSQn0T+7wN7prz3IntTRmDG+ZyimitzMHk8fjcl5znDXg4pXoIWLD9IUsT/J0MQzWKzekOWFC0KAdTmJIxvgK9Wtu/pydEL1FRy4vwjcesJZxSnA/euDkUZQaJ5Rn1RdtxD0qf6LpXCq3LLiZuIuyrN1CpXVUSLyB4u9bGHX0/CPfDqnZ39o+gYC0MBxCmkUuYDrV+THRn/84so1MxuiOjZOPe0XYUuz57tDVQ=="
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=debug msg="completed challenge"
Dec 06 18:28:47 gbvpi-bedroom go-librespot[4902]: time="2025-12-06T18:28:47-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:47 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:47 gbvpi-bedroom volumio[4626]: info: Connection to go-librespot Websocket closed
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin multiroom to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: MyVolumio login type: Token
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 06 18:28:50 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 06 18:28:50 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Dec 06 18:28:50 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:50 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:50 gbvpi-bedroom go-librespot[4918]: go-librespot daemon starting...
Dec 06 18:28:50 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:50-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:50 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:50-05:00" level=debug msg="app state loaded"
Dec 06 18:28:50 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:50-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=info msg="zeroconf server listening on port 34945"
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="obtained new client token: AAAWgiVLtKd1ku3PemmFqs3Gbw9G9Fl53KodvKwB1mqHBwwz+J9hvd8OPaeRy94AthO+4moLWqk+hdqHjEk8yx96QVCT3g1COjocPgHC0RCJ6PfOJK3UmY9p5RnoT+p8wQq7hGyYYdE0o/IN0bmeiE7u/DR+Fw9X/Y08SDBwhG/mMVAJi7EGYFi0e6cLtErkuF6/WAIzkyzQC4C5tAIF+Gidq3I+rbR9yQq5m3d6eEkuxDinq+GEkDM="
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: Streaming services startup
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: Starting Streaming Daemon
Dec 06 18:28:51 gbvpi-bedroom sudo[4927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 18:28:51 gbvpi-bedroom sudo[4927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=debug msg="completed challenge"
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 06 18:28:51 gbvpi-bedroom sudo[4927]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: Getting Spotify volume
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: info: Initializing connection to go-librespot Websocket
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: error: Cannot start Volumio Streaming Daemon
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 18:28:51 gbvpi-bedroom go-librespot[4919]: time="2025-12-06T18:28:51-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:51 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: Error: read ECONNRESET
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: at TCP.onStreamRead (node:internal/stream_base_commons:217:20) {
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: errno: -104,
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: code: 'ECONNRESET',
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: syscall: 'read',
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: response: undefined
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: }
Dec 06 18:28:51 gbvpi-bedroom volumio[4626]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 18:28:51 gbvpi-bedroom sudo[4947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 18:27'
Dec 06 18:28:51 gbvpi-bedroom sudo[4947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:51 gbvpi-bedroom sudo[4947]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:52 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Dec 06 18:28:52 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: volumio.service: Failed with result 'exit-code'.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: volumio.service: Consumed 15.320s CPU time.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1819.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: Started dynamicswap.service - dynamicswap service.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: Stopped volumio.service - Volumio Backend Module.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: volumio.service: Consumed 15.320s CPU time.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: Started volumio.service - Volumio Backend Module.
Dec 06 18:28:52 gbvpi-bedroom systemd[1]: dynamicswap.service: Deactivated successfully.
Dec 06 18:28:53 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:28:53 gbvpi-bedroom volumio[4963]: info: ----- Volumio3 ----
Dec 06 18:28:53 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:28:53 gbvpi-bedroom volumio[4963]: info: ----- System startup ----
Dec 06 18:28:53 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: MYVOLUMIO Environment detected
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Plugin folders cleanup
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning into folder /volumio/app/plugins/
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category audio_interface
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category miscellanea
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category music_service
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category plugins.json
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category system_controller
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category user_interface
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning into folder /data/plugins/
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Scanning category music_service
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Plugin folders cleanup completed
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: ----- Core plugins startup ----
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugins from folder /volumio/app/plugins/
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Adding plugin upnp to MyMusic Plugins
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Adding plugin airplay_emulation to MyMusic Plugins
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Adding plugin upnp_browser to MyMusic Plugins
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugins from folder /data/plugins/
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugin "system"...
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugin "appearance"...
Dec 06 18:28:54 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Dec 06 18:28:54 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:54 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4990]: go-librespot daemon starting...
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=debug msg="app state loaded"
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=info msg="zeroconf server listening on port 35745"
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugin "network"...
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Refreshing Cached IP Addresses
Dec 06 18:28:54 gbvpi-bedroom sudo[4999]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 18:28:54 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:54-05:00" level=debug msg="obtained new client token: AADo8qPeR2I+LYUjUAfNhqf3zMP0aa4uaxs/8Mj8sAHcvN3/984PKeI0tqnmPaMcGANHogrgd5qf5cf7RNQHIEBNXRtmfsZNK5mt6ayeR6+zqa8aWnLWtVd1wt1O0gKpu8or1T76PdubkLr/zjI4J6WUMrcSi5ECBLIVqyT/k/cgvghGCs31NSUg4bvzW79WMqUgl0cr+GoQmkVGd59yjauinAGam1hnRSyV/coHe0Nr2cxTQjyCH0j+rg=="
Dec 06 18:28:54 gbvpi-bedroom sudo[4999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:54 gbvpi-bedroom sudo[4999]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugin "services"...
Dec 06 18:28:54 gbvpi-bedroom sudo[5001]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 18:28:54 gbvpi-bedroom sudo[5001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:54 gbvpi-bedroom volumio[4963]: info: Loading plugin "alsa_controller"...
Dec 06 18:28:54 gbvpi-bedroom sudo[5001]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:54 gbvpi-bedroom sudo[5009]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Dec 06 18:28:54 gbvpi-bedroom sudo[5009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:55 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "wizard"...
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "networkfs"...
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Starting Udev Watcher for removable devices
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Ignoring mount for partition: boot
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Ignoring mount for partition: volumio
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Ignoring mount for partition: volumio_data
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "volumio_command_line_client"...
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "upnp"...
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: [1765063735075] Starting Upmpd Daemon
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "my_music"...
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "mpd"...
Dec 06 18:28:55 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:55-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:55 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:55-05:00" level=debug msg="completed challenge"
Dec 06 18:28:55 gbvpi-bedroom go-librespot[4991]: time="2025-12-06T18:28:55-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:55 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "upnp_browser"...
Dec 06 18:28:55 gbvpi-bedroom volumio[4963]: info: Loading plugin "alarm-clock"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "airplay_emulation"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Starting Shairport Sync
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "last_100"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "webradio"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "i2s_dacs"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: I2S DAC not set, start Auto-detection
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "volumiodiscovery"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: *** WARNING *** For more information see
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:56 gbvpi-bedroom node[4963]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: *** WARNING *** For more information see
Dec 06 18:28:56 gbvpi-bedroom node[4963]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:56 gbvpi-bedroom node[4963]: *** WARNING *** For more information see
Dec 06 18:28:56 gbvpi-bedroom node[4963]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Dec 06 18:28:56 gbvpi-bedroom node[4963]: *** WARNING *** Please fix your application to use the native API of Avahi!
Dec 06 18:28:56 gbvpi-bedroom node[4963]: *** WARNING *** For more information see
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Applying required configuration parameters for plugin volumiodiscovery
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Discovery: Started advertising with name: GBVPi-Bedroom
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "jellyfin"...
Dec 06 18:28:56 gbvpi-bedroom volumio[4963]: info: Loading plugin "spop"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading plugin "outputs"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading plugin "albumart"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Plugin example_plugin is not enabled
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading plugin "inputs"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading plugin "updater_comm"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Plugin mpdemulation is not enabled
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading plugin "rest_api"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading plugin "websocket"...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Starting Socket.io Server version 1.7.4
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Loading i18n strings for locale en
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: Updating browse sources language
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::initPlayerControls
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: Express server listening on port 3000
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: [Metrics] WebUI: 3s 695.05ms
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::resetVolumioState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::getcurrentVolume
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Volumio Network Manager: Network status updated: 2
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[5034]: Forking 3 albumart workers
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: VolumeController:: Volume=91 Mute =false
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::pushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::updateTrackBlock
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrackBlock
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioRetrievevolume
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Reloading queue from file
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::setRepeat null single undefined
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::pushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::setRandom null
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::pushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Setting Device type: Raspberry PI
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: VolumeController:: Volume=91 Mute =false
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::pushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioPushState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Completed loading Core Plugins
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Preparing to generate the ALSA configuration file
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Asound.conf file unchanged, so no further update is needed
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Output device has changed, restarting MPD
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Output device has changed, restarting Shairport Sync
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom sudo[5090]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 18:28:57 gbvpi-bedroom sudo[5094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 18:28:57 gbvpi-bedroom sudo[5094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:57 gbvpi-bedroom sudo[5090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:57 gbvpi-bedroom sudo[5090]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: ___________ START PLUGINS ___________
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: ControllerMpd::onStart: Initializing MPD
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Creating MPD Configuration file
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 18:28:57 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:57] [connect] Successful connection
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: [1765063737698] CoreMusicLibrary::Adding element Media Servers
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.895s CPU time.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 18:28:57 gbvpi-bedroom sudo[5100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 18:28:57 gbvpi-bedroom sudo[5100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:57 gbvpi-bedroom sudo[5100]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:57 gbvpi-bedroom sudo[5102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 18:28:57 gbvpi-bedroom sudo[5102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: [1765063737776] CoreMusicLibrary::Adding element Last_100
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: [1765063737783] CoreMusicLibrary::Adding element Webradio
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Initializing BBC Radios
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 18:28:57 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Discovery: Getting this device information
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: [1765063737915] CoreMusicLibrary::Adding element Jellyfin
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: Cannot find translation for source Jellyfin
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.97","id":"74ce6260-2045-48bb-acbd-0b75ccb5d93e","name":"GBVPi-Bedroom","serviceName":"Volumio","state":{"albumart":"https://jellyfin.lukeaurio.net/Items/4ca3014131d666da7f92ae9ddc7e7309/Images/Primary?maxWidth=500&maxHeight=500&quality=90","artist":"Robert Pollard","mute":false,"status":"stop","track":"Run Son Run","volume":91},"type":"device"}
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: Creating Spotify config file
Dec 06 18:28:57 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom sudo[5129]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 18:28:58 gbvpi-bedroom sudo[5129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 18:28:58 gbvpi-bedroom sudo[5129]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Volumio Calling Home
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:58 gbvpi-bedroom go-librespot[5136]: go-librespot daemon starting...
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Dec 06 18:28:58 gbvpi-bedroom go-librespot[5137]: time="2025-12-06T18:28:58-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:58 gbvpi-bedroom volumio[5051]: Starting albumart workers
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: adding 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: Found device NorthPi-Soundstation
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: Connecting to remote: 192.168.1.28
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: this is already registered, 74ce6260-2045-48bb-acbd-0b75ccb5d93e
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Discovery: Found device GBVPi-Bedroom
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: MPD Permissions set
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: MPD Permissions set
Dec 06 18:28:58 gbvpi-bedroom volumio-remote-updater[11354]: [2025-12-06 18:28:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765063737 101
Dec 06 18:28:58 gbvpi-bedroom volumio[5052]: Starting albumart workers
Dec 06 18:28:58 gbvpi-bedroom volumio[5053]: Starting albumart workers
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Spotify config file written
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: Volumio called home
Dec 06 18:28:58 gbvpi-bedroom sudo[5160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom sudo[5160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:58 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5168]: go-librespot daemon starting...
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: No need to fix Spotify hosts
Dec 06 18:28:59 gbvpi-bedroom sudo[5160]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=debug msg="app state loaded"
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:28:59 gbvpi-bedroom sudo[5009]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28: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 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28: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 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28: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 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=info msg="zeroconf server listening on port 42757"
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=debug msg="obtained new client token: AAAjXB8MIz86vLiUJ50rTxZYUZZB//TWd2ZP+VOseaErjgAK5mlZYXikn1lVvFTPYBawbGSlqGT2O/axPhnFkEC6nsxFwcmMXZqeckFp7snSamy82nHrK+eZPaShUM9/bKk+aT83Ec4xfaH9LE/9dCBhZWMh8ApIBT0VMzoybID2mw0gVK4W+2QCKok9dDKjttdc/LLFWhTPKhwqH7bEWhNAlhFEzl8xoGwxQKNnlKtC/zhL/2lFIaMmhA=="
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: [jellyfin-poller] Polled HTTPS://jellyfin.lukeaurio.net: online
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: setdatetime-helper.service: Deactivated successfully.
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=debug msg="completed keyexchange"
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=debug msg="completed challenge"
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: Starting Shairport Sync
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: Starting Shairport Sync
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: Starting Shairport Sync
Dec 06 18:28:59 gbvpi-bedroom go-librespot[5175]: time="2025-12-06T18:28:59-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:28:59 gbvpi-bedroom sudo[5211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:28:59 gbvpi-bedroom sudo[5211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:59 gbvpi-bedroom sudo[5214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:59 gbvpi-bedroom sudo[5215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:28:59 gbvpi-bedroom sudo[5215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:59 gbvpi-bedroom sudo[5214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.647s CPU time.
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:28:59 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:28:59 gbvpi-bedroom sudo[5211]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:59 gbvpi-bedroom sudo[5215]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:59 gbvpi-bedroom sudo[5214]: pam_unix(sudo:session): session closed for user root
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: Shairport-Sync Started
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: Error adding Membership: Error: addMembership EINVAL
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: Shairport-Sync Started
Dec 06 18:28:59 gbvpi-bedroom volumio[4963]: info: Shairport-Sync Started
Dec 06 18:29:00 gbvpi-bedroom mpd[5131]: 2025-12-06T18:29:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 18:29:00 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 18:29:00 gbvpi-bedroom sudo[5102]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:00 gbvpi-bedroom sudo[5094]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: info: Completed starting Core Plugins
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: info: ----- MyVolumio plugins startup ----
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: info: -------------------------------------------
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Fetching plans data....
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: error: MPD error: The expression evaluated to a falsy value:
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: assert.ok(self.idling)
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: error: The expression evaluated to a falsy value:
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: assert.ok(self.idling)
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: info: MPD running with PID5131
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: ,establishing connection
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: error: updateQueue error: null
Dec 06 18:29:00 gbvpi-bedroom volumio[4963]: error: updateQueue error: null
Dec 06 18:29:02 gbvpi-bedroom volumio[4963]: info: go-librespot daemon successfully initialized
Dec 06 18:29:02 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Dec 06 18:29:02 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:02 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:02 gbvpi-bedroom go-librespot[5239]: go-librespot daemon starting...
Dec 06 18:29:02 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:02-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:02 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:02-05:00" level=debug msg="app state loaded"
Dec 06 18:29:02 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:02-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=info msg="zeroconf server listening on port 39069"
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="obtained new client token: AADGIoCE6XvQVZ+nqiRUN4PgiJ/xqSj7iBwC0TSqncjze7g3piut/aQvPiXHT+TrvadpcVEy6hZor5V/ovtFOJTdnaTijBQOPGOl8MjNISrjyr941fduXT6+Lv7Zu7iwvwjJzgBgSM9JBQIif2y8e1mToq4+0oruIThh8dtfC11pNfaIz53msz82sp6a+7LUnmBmmb7jBj04Oy3w3lR6t9qnze3esZdh6XYuTSE5/YMHzTkTOYiLY+A="
Dec 06 18:29:03 gbvpi-bedroom sudo[5248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 18:29:03 gbvpi-bedroom sudo[5248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:03 gbvpi-bedroom sudo[5250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 18:29:03 gbvpi-bedroom sudo[5250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:03 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 18:29:03 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 18:29:03 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=debug msg="completed challenge"
Dec 06 18:29:03 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 18:29:03 gbvpi-bedroom sudo[5250]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:03 gbvpi-bedroom sudo[5248]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:03 gbvpi-bedroom mpd_monitor.sh[5253]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 18:29:03 gbvpi-bedroom volumio[4963]: info: Successfully started MPD Monitor
Dec 06 18:29:03 gbvpi-bedroom volumio[4963]: info: Successfully started MPD Monitor
Dec 06 18:29:03 gbvpi-bedroom go-librespot[5240]: time="2025-12-06T18:29:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:29:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:03 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:03 gbvpi-bedroom volumio[4963]: info: Discovery: Connected to remote: 192.168.1.28
Dec 06 18:29:05 gbvpi-bedroom sudo[5272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 06 18:29:05 gbvpi-bedroom sudo[5272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:05 gbvpi-bedroom sudo[5274]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 06 18:29:05 gbvpi-bedroom sudo[5272]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:05 gbvpi-bedroom sudo[5274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:05 gbvpi-bedroom sudo[5274]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:05 gbvpi-bedroom sudo[5277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Dec 06 18:29:05 gbvpi-bedroom sudo[5277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:05 gbvpi-bedroom sudo[5277]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:05 gbvpi-bedroom volumio[4963]: info: Upmpdcli Daemon Started
Dec 06 18:29:05 gbvpi-bedroom volumio[4963]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Dec 06 18:29:05 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:05 gbvpi-bedroom volumio[4963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:06 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:06 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:29:06 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:06 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:29:06 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Dec 06 18:29:06 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:06 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5280]: go-librespot daemon starting...
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=debug msg="app state loaded"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=info msg="zeroconf server listening on port 41869"
Dec 06 18:29:06 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:06-05:00" level=debug msg="obtained new client token: AADT3rPk1IypwCedrmWbXb00pqtHpzUxkXcS8CqU2RWUBExLYZKrw7gq2FiK1sMmtuWAWeEtd3zuNc9kGqr6BYoR2+TUVAQ3BBDJx59c5tt1dktMmcL7X48qwS4QvIFPgE5adLiKm5tNBOk7tytyHzml6zj/JArkoBMUPfV1aXuHP0+o5SMYBIG3swYuPg+f5mpNsWL8VYGaOBM/g6f30/qPw76duGXaMscfWzsSdvQUlfKUwwMG2wPy0w=="
Dec 06 18:29:07 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:07 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:07-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:07 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:07-05:00" level=debug msg="completed challenge"
Dec 06 18:29:07 gbvpi-bedroom go-librespot[5281]: time="2025-12-06T18:29:07-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:29:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:07 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin bluetooth to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin multiroom to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin metavolumio to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin cd_controller to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin qobuzconnect to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin smart_inputs to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: Adding plugin tidalconnect to MyMusic Plugins
Dec 06 18:29:08 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: Starting MyVolumio Remote Streaming Endpoints
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: MyVolumio login type: Token
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: Streaming services startup
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: Starting Streaming Daemon
Dec 06 18:29:09 gbvpi-bedroom sudo[5289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 18:29:09 gbvpi-bedroom sudo[5289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Dec 06 18:29:09 gbvpi-bedroom sudo[5289]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: error: Cannot start Volumio Streaming Daemon
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:09 gbvpi-bedroom volumio[4963]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MyVolumio token set successfully
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MYVOLUMIO: Adding device
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MYVOLUMIO: Evaluating Server
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MyVolumio Plan changed: premium
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Removing browser output: myVolumio user plan is not superstar
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Removing audio output:
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MYVOLUMIO: Adding device
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MYVOLUMIO: Evaluating Server
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Remote config written successfully
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Starting Tunnel 1
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Starting Tunnel Connection Checker
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Completed starting MyVolumio Plugin
Dec 06 18:29:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Dec 06 18:29:10 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:10 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5318]: go-librespot daemon starting...
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="app state loaded"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MYVolumio Device enabled
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: MyVolumio status changed
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Streaming services startup
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: Starting Streaming Daemon
Dec 06 18:29:10 gbvpi-bedroom sudo[5341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Dec 06 18:29:10 gbvpi-bedroom sudo[5341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"...
Dec 06 18:29:10 gbvpi-bedroom sudo[5341]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=info msg="zeroconf server listening on port 39443"
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart
Dec 06 18:29:10 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "multiroom"...
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="obtained new client token: AAAGZl25Uzdh5hYn4y06n6STFXOYAXJOsn1FwMd8gqjl1t3TVwsyDYRh+fiNEzkSFUYaaK8KfK6oyHGIpbrn3dqTu342TyK347sSl7dHie8nUdAGnq+pf9qQLH4KcU0aNDGChTbSWsxPoTBASLBAC8rkcpI/SqkON480YcwgBufNbuY96q0C7ESZGjH1t/fVftKB1Mc9fXselCVkNRaesnxAk4kZ0STcDziD57zlAO9pSOJZaoW0fftJ4A=="
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=debug msg="completed challenge"
Dec 06 18:29:10 gbvpi-bedroom go-librespot[5327]: time="2025-12-06T18:29:10-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:29:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:10 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Dec 06 18:29:11 gbvpi-bedroom sudo[5346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Dec 06 18:29:11 gbvpi-bedroom sudo[5346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom sudo[5346]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: MultiRoom plugin initialized
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: STOPPING SNAPCLIENT
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: Snap server stop
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: STOPPING volumioStreaming
Dec 06 18:29:11 gbvpi-bedroom sudo[5363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Dec 06 18:29:11 gbvpi-bedroom sudo[5363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom sudo[5365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Dec 06 18:29:11 gbvpi-bedroom sudo[5365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Dec 06 18:29:11 gbvpi-bedroom sudo[5367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Dec 06 18:29:11 gbvpi-bedroom sudo[5367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Dec 06 18:29:11 gbvpi-bedroom sudo[5371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Dec 06 18:29:11 gbvpi-bedroom sudo[5371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Dec 06 18:29:11 gbvpi-bedroom sudo[5371]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Dec 06 18:29:11 gbvpi-bedroom sudo[5367]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom sudo[5363]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Dec 06 18:29:11 gbvpi-bedroom sudo[5365]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"...
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Preparing to generate the ALSA configuration file
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Setting Geolocation for MyVolumio to us1
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Reading ALSA contributions from plugins.
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Setting Geolocation for MyVolumio to us1
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: Removed streaming files
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: volumioStreaming STOPPED
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: SNAPSERVER STOPPED
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: SNAPCLIENT STOPPED
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: error: Cannot start Volumio Streaming Daemon
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Asound.conf file written
Dec 06 18:29:11 gbvpi-bedroom sudo[5377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 06 18:29:11 gbvpi-bedroom sudo[5377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom sudo[5377]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Output device has changed, restarting MPD
Dec 06 18:29:11 gbvpi-bedroom sudo[5383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 06 18:29:11 gbvpi-bedroom sudo[5383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom sudo[5383]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Output device has changed, restarting Shairport Sync
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 06 18:29:11 gbvpi-bedroom sudo[5387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom sudo[5387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: Stopping mpd.service - Music Player Daemon...
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output for this device
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding audio output:
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding audio output:
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: mpd.service: Deactivated successfully.
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: Stopped mpd.service - Music Player Daemon.
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: mpd.service: Consumed 1.969s CPU time.
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: mpd.socket: Deactivated successfully.
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:11 gbvpi-bedroom bluetoothd[807]: Path / reserved for Adv Monitor app :1.29132
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding METAVOLUMIO REST API Endpoints
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Preparing CD Folders
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding CD REST API Endpoints
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Dec 06 18:29:11 gbvpi-bedroom bluetoothd[807]: Adv Monitor app :1.29132 disconnected from D-Bus
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Starting UDEV Watcher for CD
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: Detecting CD presence with UDEV
Dec 06 18:29:11 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Dec 06 18:29:11 gbvpi-bedroom systemd[1]: Starting mpd.service - Music Player Daemon...
Dec 06 18:29:12 gbvpi-bedroom sudo[5403]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 06 18:29:12 gbvpi-bedroom sudo[5403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Dec 06 18:29:12 gbvpi-bedroom sudo[5403]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:13 gbvpi-bedroom mpd[5405]: 2025-12-06T18:29:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 06 18:29:13 gbvpi-bedroom systemd[1]: Started mpd.service - Music Player Daemon.
Dec 06 18:29:13 gbvpi-bedroom sudo[5387]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Dec 06 18:29:14 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:14 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5408]: go-librespot daemon starting...
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="app state loaded"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=info msg="zeroconf server listening on port 33093"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="obtained new client token: AAA1uNfRTz7r3z5bp4mvM3XF1lnJyXBb8XqNfOZzjD9TNa8CVSR0AhMFfe8tsGjt4kVC/MDqwj4r7eA2tbv5HGVWYriiNhKPraECjPtfgPRXbHhh6MjIE0iscc/gmgaDB+hlYETdyTX6D0dBlyZQ0X8EeU6L2vWcsGbtDMpKidmrXWheFx0d4PPgtIGKQipqr5k8X+pwPGdvRNEPRMIcFa+6bK4wjUJCdkxERyl9SuMhQQ7atsCWSbk7Ag=="
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=debug msg="completed challenge"
Dec 06 18:29:14 gbvpi-bedroom go-librespot[5409]: time="2025-12-06T18:29:14-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:29:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:14 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: warn: [cd-plugin] cdspeedctl: device or media not ready
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding inputs REST Endpoints
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Scanning Audio Inputs
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Checking against Known Cards name
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding Server instance for streaming
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: error: Hi Res Audio Failed Login: Missing Login Data
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding HIGHRESAUDIO REST API Endpoints
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Dec 06 18:29:16 gbvpi-bedroom sudo[5434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: QobuzConnect: Starting Qobuz Connect socket and service
Dec 06 18:29:16 gbvpi-bedroom sudo[5434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Adding TIDAL REST API Endpoints
Dec 06 18:29:16 gbvpi-bedroom volumio[4963]: info: Stopping AccessToken refresher cron for QOBUZ
Dec 06 18:29:16 gbvpi-bedroom systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service...
Dec 06 18:29:16 gbvpi-bedroom sudo[5441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Dec 06 18:29:16 gbvpi-bedroom sudo[5441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:16 gbvpi-bedroom systemd[1]: vtcs.service: Deactivated successfully.
Dec 06 18:29:16 gbvpi-bedroom systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service.
Dec 06 18:29:17 gbvpi-bedroom sudo[5434]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: AccessToken refresher cron started for QOBUZ
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Adding QOBUZ REST API Endpoints
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Updating MyVolumio device info
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom sudo[5441]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Updating MyVolumio device info
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: MRS: Getting audio outputs on start
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: MRS: Requesting all other devices output
Dec 06 18:29:17 gbvpi-bedroom sudo[5444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Dec 06 18:29:17 gbvpi-bedroom sudo[5444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Successfully Added MyVolumio device
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[4463]: 20251206 18:29:17.071 [4463.4463] INFO SampleApp: Stopping Local configuration server
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Successfully Added MyVolumio device
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: MPD Permissions set
Dec 06 18:29:17 gbvpi-bedroom sudo[5448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Dec 06 18:29:17 gbvpi-bedroom sudo[5448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:29:17 gbvpi-bedroom sudo[5448]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: error: updateQueue error: null
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioStop
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::stop
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Listing playlists
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Starting Shairport Sync
Dec 06 18:29:17 gbvpi-bedroom sudo[5463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Dec 06 18:29:17 gbvpi-bedroom sudo[5463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: MRS: Found cast device: SmartTV-4K-fe72c264393a59c76d38e27b8168114d
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Adding audio output:
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: MRS: Found cast device: Google-Home-Mini-f209fa314cb426d40a59bcf66354ddc9
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Adding audio output:
Dec 06 18:29:17 gbvpi-bedroom sudo[5465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 06 18:29:17 gbvpi-bedroom sudo[5465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:17 gbvpi-bedroom autossh[4444]: received signal to exit (15)
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: sshtunnel.service: Deactivated successfully.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Successfully Updated MyVolumio device
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Successfully Updated MyVolumio device
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: shairport-sync.service: Consumed 1.624s CPU time.
Dec 06 18:29:17 gbvpi-bedroom autossh[5469]: port set to 0, monitoring disabled
Dec 06 18:29:17 gbvpi-bedroom sudo[5463]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:17 gbvpi-bedroom autossh[5469]: starting ssh (count 1)
Dec 06 18:29:17 gbvpi-bedroom autossh[5469]: ssh child pid is 5473
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Remote SSH Started
Dec 06 18:29:17 gbvpi-bedroom sudo[5465]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Shairport-Sync Started
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Dec 06 18:29:17 gbvpi-bedroom volumiossh-tunnel[5473]: Warning: Permanently added '[us1.myvolumio.org]:2222' (RSA) to the list of known hosts.
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5488]: go-librespot daemon starting...
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=debug msg="app state loaded"
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: qobuz-connect.service: Deactivated successfully.
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=info msg="zeroconf server listening on port 43015"
Dec 06 18:29:17 gbvpi-bedroom systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Dec 06 18:29:17 gbvpi-bedroom sudo[5444]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: Executing endpoint qc_getconfig
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.956 [5496.5496] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Dec 06 18:29:17 gbvpi-bedroom volumio[4963]: info: QobuzConnect: QOBUZ Connect daemon connected
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.960 [5496.5496] INFO VolumeManager: [0xace588]: Setting new playback volume: 75
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.960 [5496.5496] INFO VolumeManager: [0xace588]: Setting new mute state: 0
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.960 [5496.5496] INFO QobuzConnect: [0xacef58]: Client initialized!
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.960 [5496.5496] INFO SampleApp: Starting Avahi advertising, name: GBVPi-Bedroom, service name: _qobuz-connect._tcp
Dec 06 18:29:17 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:17-05:00" level=debug msg="obtained new client token: AAC0ql20d3U2wsOZvXIcwACZvRxk45JSHU70J09nzd/olgh1m1jm32HJR74F72fUsXBR9yaFNLVZfzhIITiRsruceu+gLlxavA7EuNCKex9BdljLslTBTYvP7/aUKTiFVywO6sTU3PuoExcwpmRMg27dRDaTUluDGqkAZUqBlhwHqTPZGcdA5xkYelmsGZjJqevgfgQgZa/xa3VGz1Jm3cT4wQa0l44Y9oxfOhMSIUeFy0RjBxH7Qh9HMA=="
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.982 [5496.5496] INFO LocalConfigManager: [0xacde68]: Starting Local Configuration server
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.982 [5496.5496] INFO SampleApp: Starting Local configuration server
Dec 06 18:29:17 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:17.982 [5496.5496] INFO SampleApp: Connected to UNIX socket client 0xab8818
Dec 06 18:29:18 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:18 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:18-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:18 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29:18-05:00" level=debug msg="completed challenge"
Dec 06 18:29:18 gbvpi-bedroom qobuz-connect[5496]: 20251206 18:29:18.107 [5496.5496] INFO SampleApp: Playback volume changed: 75
Dec 06 18:29:18 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:18 gbvpi-bedroom go-librespot[5489]: time="2025-12-06T18:29: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 06 18:29:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:18 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:19 gbvpi-bedroom volumio[4963]: info: Discovery: Disconnected from remote: 192.168.1.28
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: TidalConnect service stoped!
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 06 18:29:20 gbvpi-bedroom sudo[5511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 06 18:29:20 gbvpi-bedroom sudo[5511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:20 gbvpi-bedroom sudo[5515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:20 gbvpi-bedroom sudo[5515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Discovery: A device disappeared from network
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Discovery: Device northpi-soundstation disappeared from network
Dec 06 18:29:20 gbvpi-bedroom systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Dec 06 18:29:20 gbvpi-bedroom sudo[5511]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:20 gbvpi-bedroom systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Dec 06 18:29:20 gbvpi-bedroom systemd[1]: mpd_monitor.service: Deactivated successfully.
Dec 06 18:29:20 gbvpi-bedroom systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Dec 06 18:29:20 gbvpi-bedroom systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Dec 06 18:29:20 gbvpi-bedroom mpd_monitor.sh[5519]: MPD Monitor Service: Starting MPD Monitor Service
Dec 06 18:29:20 gbvpi-bedroom sudo[5515]: pam_unix(sudo:session): session closed for user root
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Successfully started MPD Monitor
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Executing endpoint tc_getconfig
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 06 18:29:20 gbvpi-bedroom vtcs[5517]: STARTING TidalConnect services, version: 1.5.2.56
Dec 06 18:29:20 gbvpi-bedroom vtcs[5517]: STARTED TidalConnect services.
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Executing endpoint tc_connect
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Connecting to TidalConnect
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::servicePushState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::pushState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioPushState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output update for this device
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::servicePushState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreStateMachine::pushState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioPushState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output update for this device
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: CorePlayQueue::getTrack 0
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received tidalconnect
Dec 06 18:29:20 gbvpi-bedroom volumio[4963]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.KgLfU6XUUlR7svHZAvNpgZIq9af1.66712a116082b2e6ca4ffe3109a843e6.state.status'
Dec 06 18:29:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Dec 06 18:29:21 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:21 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5537]: go-librespot daemon starting...
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="app state loaded"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29: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-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=info msg="zeroconf server listening on port 43025"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="obtained new client token: AAAKXkhHS8AGujQLXv56tPX7colsxfoK2PRfNM1UORztUIxdiuYNPtipPOWFTVhlvRtFl/YPEXGHt4KzY4fBtq5d6st5oYeCNkkWSD4HsMY9D9tNPwwg9XxM/jo3AAlLoAGKf8Xf4fD2C7DOqM/54S1+GIOl7v3k060a8tNWLcfeQhj18lUCGIYWL0/VJfZPQMITcGRBolhk4tQaAOArDgbATydz1bAuLyX0oAP7wHdnnCj8iyxHoTAR6Q=="
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29:21-05:00" level=debug msg="completed challenge"
Dec 06 18:29:21 gbvpi-bedroom go-librespot[5538]: time="2025-12-06T18:29: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 06 18:29:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:21 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: TidalConnect service started!
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: [Metrics] CommandRouter: 29s 285.99ms
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::Close All Modals sent
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::Close All Modals sent
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: Discovery: adding 357de02c-99c5-4ddd-be16-8ae369ed89c3
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: Discovery: Found device NorthPi-Soundstation
Dec 06 18:29:23 gbvpi-bedroom volumio[4963]: info: Discovery: Connecting to remote: 192.168.1.28
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: MRS: Pushing audio output on request
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: MRS: Pushing multiroomSync output
Dec 06 18:29:24 gbvpi-bedroom volumio[4963]: info: Discovery: Connected to remote: 192.168.1.28
Dec 06 18:29:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Dec 06 18:29:25 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:25 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5564]: go-librespot daemon starting...
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="app state loaded"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29: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-gew1.spotify.com:80]"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=info msg="zeroconf server listening on port 43285"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="obtained new client token: AADrmkZP9N3vZmyoAM0RdhAhDlQuUtd79ra+hacq7yWxnJvbI74fEdxvEJ15RQ6kKNKtx5f7Ig5/GP+aIzk8aT5Q+4o1WKATZyfvE+vBXbYWIX0ZZ5bvx63eME3q4pRCDXRAInGwm12nQQxiZA5Nzt6yLtkzW0PsJTFu/0iyrh/MpUvValOJ1fWej70NkK5na4cu+DnMPRil/6gyOhzh40dqDINfawg7rIkRbMqfMv79+/5hNNZXSNqseg=="
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29:25-05:00" level=debug msg="completed challenge"
Dec 06 18:29:25 gbvpi-bedroom go-librespot[5565]: time="2025-12-06T18:29: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 06 18:29:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:25 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:26 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:26 gbvpi-bedroom volumio[4963]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:26 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:26 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetState
Dec 06 18:29:28 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:29:28 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 06 18:29:28 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 06 18:29:28 gbvpi-bedroom volumio-remote-updater[11354]: Test mode enabled
Dec 06 18:29:28 gbvpi-bedroom volumio-remote-updater[11354]: Alpha mode disabled
Dec 06 18:29:28 gbvpi-bedroom volumio-remote-updater[11354]: Alpha legacy test mode disabled
Dec 06 18:29:28 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 06 18:29:28 gbvpi-bedroom volumio[4963]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"ANNOUNCEMENT
\n\n- Production line
\n
\nFIX
\n\n- Nodejs 20.5.1 version pinning with static package fallback
\n
\n","title":"Update v4.073","updateavailable":true}
Dec 06 18:29:28 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 06 18:29:28 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Dec 06 18:29:28 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:28 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:28 gbvpi-bedroom go-librespot[5576]: go-librespot daemon starting...
Dec 06 18:29:28 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:28-05:00" level=info msg="running go-librespot 0.4.0"
Dec 06 18:29:28 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:28-05:00" level=debug msg="app state loaded"
Dec 06 18:29:28 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:28-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=info msg="zeroconf server listening on port 35343"
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: Initializing connection to go-librespot Websocket
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="new websocket client"
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: Connection to go-librespot Websocket established
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="obtained new client token: AABKz9S9TwR2BKaWQ0MmFV4rSZMSmlCKdYv3zbHFyglZ4AlkVz753VbLXkEglA1izL8tKF7uEPT5TvRFpV/h6+FHeYHKNwG35KPK3ksrR2lHBilKP9jdIYICnHeHKB0pYBq2FzRrZBDxdmhEL07b1Yil1jdO5YwpbkHz41DKWi84wvwOR5wtneBRac5v35eEd+W/gKVdAGmgrpIz6YFvA870tiVN7ZBjjn34LbQHO4rlyqh3XGQh6Bk="
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-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 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="connected to ap-gue1.spotify.com:443"
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="completed keyexchange"
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=debug msg="completed challenge"
Dec 06 18:29:29 gbvpi-bedroom go-librespot[5577]: time="2025-12-06T18:29:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Dec 06 18:29:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 06 18:29:29 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 06 18:29:29 gbvpi-bedroom volumio[4963]: info: Connection to go-librespot Websocket closed
Dec 06 18:29:30 gbvpi-bedroom volumio[4963]: info: BOOT COMPLETED
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: info: Getting Spotify volume
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: errno: -111,
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: code: 'ECONNREFUSED',
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: syscall: 'connect',
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: address: '127.0.0.1',
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: port: 9879,
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: response: undefined
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: }
Dec 06 18:29:32 gbvpi-bedroom volumio[4963]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 06 18:29:32 gbvpi-bedroom sudo[5598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-06 18:28'
Dec 06 18:29:32 gbvpi-bedroom sudo[5598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 06 18:29:32 gbvpi-bedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Dec 06 18:29:32 gbvpi-bedroom systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:32 gbvpi-bedroom systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 06 18:29:32 gbvpi-bedroom go-librespot[5600]: go-librespot daemon starting...
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"