Jul 30 18:09:01 headpi volumio[1287]: info: Loading i18n strings for locale en
Jul 30 18:09:01 headpi volumio[1287]: Updating browse sources language
Jul 30 18:09:01 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 30 18:09:02 headpi volumio[1418]: Starting albumart workers
Jul 30 18:09:02 headpi volumio[1419]: Starting albumart workers
Jul 30 18:09:02 headpi volumio[1417]: Starting albumart workers
Jul 30 18:09:03 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 30 18:09:03 headpi volumio[1287]: info: CoreCommandRouter::initPlayerControls
Jul 30 18:09:03 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 30 18:09:04 headpi volumio[1287]: Express server listening on port 3000
Jul 30 18:09:04 headpi volumio[1287]: [Metrics] WebUI: 51s 871.22ms
Jul 30 18:09:04 headpi volumio[1287]: info: CoreStateMachine::resetVolumioState
Jul 30 18:09:04 headpi volumio[1287]: info: CoreStateMachine::getcurrentVolume
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::volumioRetrievevolume
Jul 30 18:09:04 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:05 headpi volumio[1287]: info: Volumio Network Manager: Network status updated: 1
Jul 30 18:09:05 headpi volumio[1287]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'.
Jul 30 18:09:05 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5.
Jul 30 18:09:05 headpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:06 headpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:06 headpi upmpdcli[1481]: Could not open config: /tmp/upmpdcli.conf
Jul 30 18:09:06 headpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:09:06 headpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Jul 30 18:09:06 headpi volumio-remote-updater[693]: [2026-07-30 18:09:06] [connect] Successful connection
Jul 30 18:09:06 headpi volumio[1287]: info: VolumeController:: Volume=undefined Mute =false
Jul 30 18:09:06 headpi volumio[1287]: info: CoreStateMachine::pushState
Jul 30 18:09:06 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:06 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 30 18:09:06 headpi volumio[1287]: info: CoreCommandRouter::volumioPushState
Jul 30 18:09:06 headpi volumio[1287]: info: CoreStateMachine::updateTrackBlock
Jul 30 18:09:06 headpi volumio[1287]: info: CorePlayQueue::getTrackBlock
Jul 30 18:09:06 headpi volumio[1287]: info: CoreCommandRouter::volumioRetrievevolume
Jul 30 18:09:07 headpi volumio[1287]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'.
Jul 30 18:09:07 headpi volumio[1287]: info: Reloading queue from file
Jul 30 18:09:07 headpi volumio[1287]: info: Setting Device type: Raspberry PI
Jul 30 18:09:07 headpi volumio[1287]: info: CoreStateMachine::setRepeat null single undefined
Jul 30 18:09:07 headpi volumio[1287]: info: CoreStateMachine::pushState
Jul 30 18:09:07 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:07 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 30 18:09:07 headpi volumio[1287]: info: CoreCommandRouter::volumioPushState
Jul 30 18:09:07 headpi volumio[1287]: info: CoreStateMachine::setRandom null
Jul 30 18:09:07 headpi volumio[1287]: info: CoreStateMachine::pushState
Jul 30 18:09:07 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:07 headpi volumio[1287]: info: CoreCommandRouter::volumioPushState
Jul 30 18:09:08 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1
Jul 30 18:09:08 headpi volumio[1287]: info: VolumeController:: Volume=undefined Mute =false
Jul 30 18:09:08 headpi volumio[1287]: info: CoreStateMachine::pushState
Jul 30 18:09:08 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:08 headpi volumio[1287]: info: CoreCommandRouter::volumioPushState
Jul 30 18:09:08 headpi volumio-remote-updater[693]: [2026-07-30 18:09:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1785449346 101
Jul 30 18:09:08 headpi volumio[1287]: 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: 2
Jul 30 18:09:08 headpi volumio[1287]: info: Completed loading Core Plugins
Jul 30 18:09:08 headpi volumio[1287]: info: Preparing to generate the ALSA configuration file
Jul 30 18:09:08 headpi volumio[1287]: info: Asound.conf file unchanged, so no further update is needed
Jul 30 18:09:08 headpi volumio[1287]: info: Output device has changed, restarting MPD
Jul 30 18:09:09 headpi volumio[1287]: info: Output device has changed, restarting Shairport Sync
Jul 30 18:09:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:09 headpi sudo[1517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 30 18:09:09 headpi sudo[1517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:09 headpi sudo[1519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 30 18:09:09 headpi sudo[1517]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:09 headpi sudo[1519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:09 headpi volumio[1287]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 30 18:09:09 headpi volumio[1287]: info: ___________ START PLUGINS ___________
Jul 30 18:09:09 headpi systemd[1]: musicservicesshield.service: Deactivated successfully.
Jul 30 18:09:09 headpi volumio[1287]: info: ControllerMpd::onStart: Initializing MPD
Jul 30 18:09:09 headpi volumio[1287]: info: Creating MPD Configuration file
Jul 30 18:09:09 headpi systemd[1]: Stopped musicservicesshield.service - Shield Volumio Music Services in the User CPU Set.
Jul 30 18:09:09 headpi systemd[1]: musicservicesshield.service: Consumed 2.260s CPU time.
Jul 30 18:09:09 headpi systemd[1]: Stopping musicservicesshield.service - Shield Volumio Music Services in the User CPU Set...
Jul 30 18:09:09 headpi sudo[1529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service
Jul 30 18:09:09 headpi sudo[1529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:09 headpi systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Jul 30 18:09:09 headpi systemd[1]: Starting mpd.service - Music Player Daemon...
Jul 30 18:09:09 headpi sudo[1533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 30 18:09:09 headpi sudo[1533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:09 headpi sudo[1530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 30 18:09:09 headpi sudo[1530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:09 headpi sudo[1530]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:09 headpi volumio[1287]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 30 18:09:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:09 headpi systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Jul 30 18:09:10 headpi sudo[1535]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jul 30 18:09:10 headpi sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jul 30 18:09:10 headpi sudo[1543]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Jul 30 18:09:10 headpi sudo[1535]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:10 headpi sudo[1529]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:10 headpi volumio[1287]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 30 18:09:10 headpi volumio[1287]: info: [1785449350199] CoreMusicLibrary::Adding element Last_100
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 30 18:09:10 headpi systemd[1]: mpd.service: Deactivated successfully.
Jul 30 18:09:10 headpi systemd[1]: Stopped mpd.service - Music Player Daemon.
Jul 30 18:09:10 headpi systemd[1]: mpd.socket: Deactivated successfully.
Jul 30 18:09:10 headpi systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Jul 30 18:09:10 headpi systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 30 18:09:10 headpi volumio[1287]: info: [1785449350250] CoreMusicLibrary::Adding element Webradio
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 30 18:09:10 headpi systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Jul 30 18:09:10 headpi systemd[1]: Starting mpd.service - Music Player Daemon...
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 30 18:09:10 headpi volumio[1287]: info: Initializing BBC Radios
Jul 30 18:09:10 headpi sudo[1550]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jul 30 18:09:10 headpi sudo[1563]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Jul 30 18:09:10 headpi sudo[1550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jul 30 18:09:10 headpi sudo[1550]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:10 headpi volumio5-onboarding[1541]: time=2026-07-30T18:09:10.938-04:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 30 18:09:10 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:11 headpi volumio[1287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 30 18:09:11 headpi volumio[1287]: info: [1785449351054] CoreMusicLibrary::Adding element SoundCloud
Jul 30 18:09:11 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 30 18:09:11 headpi volumio[1287]: Cannot find translation for source SoundCloud
Jul 30 18:09:11 headpi volumio[1287]: info: Creating Spotify config file
Jul 30 18:09:11 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:14 headpi volumio[1287]: info: [squeezelite_mc] Starting proxy server...
Jul 30 18:09:15 headpi ntpd[1036]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101
Jul 30 18:09:15 headpi ntpd[1036]: DNS: dns_check: DNS error: -11, System error
Jul 30 18:09:15 headpi ntpd[1036]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12
Jul 30 18:09:15 headpi volumio[1287]: info: [now-playing] ConfigUpdater: config is up to date.
Jul 30 18:09:15 headpi volumio[1287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 30 18:09:15 headpi volumio[1287]: info: [1785449355943] CoreMusicLibrary::Adding element 80s80s Radio
Jul 30 18:09:15 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 30 18:09:15 headpi volumio[1287]: Cannot find translation for source SoundCloud
Jul 30 18:09:15 headpi volumio[1287]: Cannot find translation for source 80s80s Radio
Jul 30 18:09:16 headpi ntpd[1036]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101
Jul 30 18:09:17 headpi volumio[1287]: info: Loading i18n strings for locale en
Jul 30 18:09:17 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 30 18:09:17 headpi volumio[1287]: info: Volumio Calling Home
Jul 30 18:09:18 headpi sudo[1622]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge
Jul 30 18:09:18 headpi sudo[1622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:18 headpi sudo[1622]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:18 headpi sudo[1619]: volumio : PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh
Jul 30 18:09:18 headpi volumio[1287]: info: [squeezelite_mc] Proxy server started on port 44449
Jul 30 18:09:18 headpi sudo[1619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:18 headpi sudo[1637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service
Jul 30 18:09:18 headpi sudo[1637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:19 headpi sudo[1640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service
Jul 30 18:09:19 headpi sudo[1640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:19 headpi sudo[1642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Jul 30 18:09:19 headpi sudo[1642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:19 headpi sudo[1637]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:19 headpi systemd[1]: Reloading.
Jul 30 18:09:20 headpi volumio[1287]: info: CoreCommandRouter::volumioRetrievevolume
Jul 30 18:09:20 headpi volumio5-onboarding[1541]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:38220->127.0.0.1:3000: i/o timeout
Jul 30 18:09:20 headpi volumio[1287]: info: [now-playing] App is listening on port 4004.
Jul 30 18:09:21 headpi systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal
Jul 30 18:09:21 headpi volumio[1287]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds
Jul 30 18:09:21 headpi mpd[1564]: 2026-07-30T18:09:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 30 18:09:21 headpi volumio[1287]: info: touch_display: Backlight interface detected.
Jul 30 18:09:21 headpi volumio[1287]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'.
Jul 30 18:09:21 headpi volumio[1287]: info: touch_display: systemctl stop getty@tty1.service succeeded.
Jul 30 18:09:22 headpi volumio[1287]: info: MPD Permissions set
Jul 30 18:09:22 headpi volumio[1287]: info: MPD Permissions set
Jul 30 18:09:22 headpi volumio[1287]: info: VolumeController:: Volume=undefined Mute =false
Jul 30 18:09:22 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:09:22 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:22 headpi volumio[1287]: info: CoreStateMachine::pushState
Jul 30 18:09:22 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:22 headpi volumio[1287]: info: CoreCommandRouter::volumioPushState
Jul 30 18:09:22 headpi systemd[1]: Started mpd.service - Music Player Daemon.
Jul 30 18:09:22 headpi systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:09:22 headpi systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Jul 30 18:09:22 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 6.
Jul 30 18:09:22 headpi sudo[1642]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:22 headpi sudo[1686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/
Jul 30 18:09:22 headpi sudo[1686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:22 headpi sudo[1519]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:22 headpi volumio[1287]: info: [squeezelite_mc] Server discovery started
Jul 30 18:09:22 headpi systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1.
Jul 30 18:09:22 headpi systemd[1]: Reloading.
Jul 30 18:09:22 headpi sudo[1686]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:22 headpi volumio[1287]: info: [squeezelite_mc] Player finder started
Jul 30 18:09:22 headpi sudo[1533]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:22 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:22 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:22 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:22 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 30 18:09:22 headpi volumio[1287]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true
Jul 30 18:09:23 headpi volumio[1287]: info: Spotify config file written
Jul 30 18:09:23 headpi sudo[1711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 30 18:09:23 headpi sudo[1711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:23 headpi volumio[1287]: info: touch_display: IframeKeyboardBridge extension installed successfully
Jul 30 18:09:23 headpi volumio[1287]: info: touch_display: systemctl daemon-reload succeeded.
Jul 30 18:09:23 headpi systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:23 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi sudo[1716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service
Jul 30 18:09:24 headpi sudo[1716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: No need to fix Spotify hosts
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:09:24 headpi volumio[1287]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}
Jul 30 18:09:25 headpi volumio[1287]: warn: [squeezelite_mc] No supported ALSA formats found for card 5
Jul 30 18:09:25 headpi volumio[1287]: warn: [squeezelite_mc] No ALSA formats returned for card 5
Jul 30 18:09:25 headpi volumio[1287]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"headpi","dsdFormat":null,"card":"5","mixerType":"undefined","mixer":""}
Jul 30 18:09:25 headpi systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2.
Jul 30 18:09:25 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 7.
Jul 30 18:09:25 headpi volumio[1287]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Jul 30 18:09:25 headpi sudo[1640]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:25 headpi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jul 30 18:09:25 headpi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jul 30 18:09:25 headpi sudo[1731]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Jul 30 18:09:25 headpi sudo[1731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:25 headpi sudo[1731]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:25 headpi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jul 30 18:09:25 headpi go-librespot[1729]: go-librespot daemon starting...
Jul 30 18:09:25 headpi systemd[1]: Starting musicservicesshield.service - Shield Volumio Music Services in the User CPU Set...
Jul 30 18:09:25 headpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:25 headpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:25 headpi sudo[1711]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:25 headpi systemd[1]: Started volumio-kiosk.service - Volumio Kiosk.
Jul 30 18:09:25 headpi systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Jul 30 18:09:25 headpi systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Jul 30 18:09:25 headpi sudo[1716]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:25 headpi volumio5-onboarding[1740]: time=2026-07-30T18:09:25.550-04:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
Jul 30 18:09:25 headpi upmpdcli[1735]: Could not open config: /tmp/upmpdcli.conf
Jul 30 18:09:25 headpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:09:25 headpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Jul 30 18:09:26 headpi startx[1778]: X.Org X Server 1.21.1.7
Jul 30 18:09:26 headpi startx[1778]: X Protocol Version 11, Revision 0
Jul 30 18:09:26 headpi startx[1778]: Current Operating System: Linux headpi 6.12.74-v7+ #1948 SMP Mon Mar 2 11:25:27 GMT 2026 armv7l
Jul 30 18:09:26 headpi startx[1778]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_hdmi=0 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=9caf6474-168f-4972-add4-ace36a467bc2 imgfile=/volumio_current.sqsh bootpart=UUID=807D-2966 datapart=UUID=bea3e05c-62cf-4b22-a58d-66213927f56a uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no
Jul 30 18:09:26 headpi startx[1778]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support)
Jul 30 18:09:26 headpi startx[1778]: Current version of pixman: 0.44.0
Jul 30 18:09:26 headpi startx[1778]: Before reporting problems, check http://wiki.x.org
Jul 30 18:09:26 headpi startx[1778]: to make sure that you have the latest version.
Jul 30 18:09:26 headpi startx[1778]: Markers: (--) probed, (**) from config file, (==) default setting,
Jul 30 18:09:26 headpi startx[1778]: (++) from command line, (!!) notice, (II) informational,
Jul 30 18:09:26 headpi startx[1778]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
Jul 30 18:09:26 headpi startx[1778]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Jul 30 18:09:26 2026
Jul 30 18:09:26 headpi startx[1778]: (==) Using config directory: "/etc/X11/xorg.conf.d"
Jul 30 18:09:26 headpi startx[1778]: (==) Using system config directory "/usr/share/X11/xorg.conf.d"
Jul 30 18:09:26 headpi go-librespot[1733]: time="2026-07-30T18:09:26-04:00" level=info msg="running go-librespot 0.7.1"
Jul 30 18:09:26 headpi go-librespot[1733]: time="2026-07-30T18:09:26-04:00" level=debug msg="app state loaded"
Jul 30 18:09:26 headpi go-librespot[1733]: time="2026-07-30T18:09:26-04:00" level=info msg="api server listening on 127.0.0.1:9879"
Jul 30 18:09:26 headpi volumio[1287]: error: MPD error: The expression evaluated to a falsy value:
Jul 30 18:09:26 headpi volumio[1287]: assert.ok(self.idling)
Jul 30 18:09:26 headpi volumio[1287]: error: The expression evaluated to a falsy value:
Jul 30 18:09:26 headpi volumio[1287]: assert.ok(self.idling)
Jul 30 18:09:27 headpi volumio[1287]: info: touch_display: systemctl disable getty@tty1.service succeeded.
Jul 30 18:09:27 headpi volumio[1287]: info: MPD running with PID1564
Jul 30 18:09:27 headpi volumio[1287]: ,establishing connection
Jul 30 18:09:27 headpi volumio[1287]: info: touch_display: Raspberry Pi Foundation touch screen detected.
Jul 30 18:09:27 headpi sudo[1793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf
Jul 30 18:09:27 headpi sudo[1793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:27 headpi sudo[1793]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:27 headpi bash[1788]: cset: --> shielding system active with
Jul 30 18:09:27 headpi bash[1788]: cset: "system" cpuset of CPUSPEC(1-3) with 165 tasks running
Jul 30 18:09:27 headpi bash[1788]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running
Jul 30 18:09:27 headpi volumio[1287]: error: updateQueue error: null
Jul 30 18:09:27 headpi sudo[1790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness
Jul 30 18:09:27 headpi sudo[1790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:27 headpi sudo[1790]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:27 headpi systemd[1]: Finished musicservicesshield.service - Shield Volumio Music Services in the User CPU Set.
Jul 30 18:09:27 headpi sudo[1796]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf
Jul 30 18:09:27 headpi sudo[1796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:27 headpi sudo[1796]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:27 headpi volumio[1287]: info: touch_display: systemctl start volumio-kiosk.service succeeded.
Jul 30 18:09:27 headpi volumio[1287]: info: touch_display: Volumio Kiosk started.
Jul 30 18:09:27 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:09:27 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:27 headpi volumio[1287]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Jul 30 18:09:27 headpi volumio[1287]: info: Starting Shairport Sync
Jul 30 18:09:27 headpi volumio[1287]: info: Starting Shairport Sync
Jul 30 18:09:27 headpi volumio[1287]: info: Starting Shairport Sync
Jul 30 18:09:27 headpi sudo[1811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jul 30 18:09:27 headpi sudo[1811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:27 headpi sudo[1806]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Jul 30 18:09:28 headpi sudo[1807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jul 30 18:09:28 headpi systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jul 30 18:09:28 headpi sudo[1806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:28 headpi systemd[1]: shairport-sync.service: Deactivated successfully.
Jul 30 18:09:28 headpi systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jul 30 18:09:28 headpi systemd[1]: shairport-sync.service: Consumed 2.160s CPU time.
Jul 30 18:09:28 headpi sudo[1807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:28 headpi systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jul 30 18:09:28 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3
Jul 30 18:09:28 headpi sudo[1811]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:28 headpi sudo[1806]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:28 headpi systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jul 30 18:09:28 headpi systemd[1]: shairport-sync.service: Deactivated successfully.
Jul 30 18:09:28 headpi systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jul 30 18:09:28 headpi volumio[1287]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set.
Jul 30 18:09:28 headpi volumio[1287]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set.
Jul 30 18:09:28 headpi volumio[1287]: info: touch_display: File permissions for backlight brightness control set.
Jul 30 18:09:28 headpi volumio[1287]: error: updateQueue error: null
Jul 30 18:09:28 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3
Jul 30 18:09:28 headpi volumio[1287]: info: Received Get System Info
Jul 30 18:09:28 headpi systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jul 30 18:09:28 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 30 18:09:28 headpi sudo[1807]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:28 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 30 18:09:28 headpi volumio[1287]: info: Discovery: Getting this device information
Jul 30 18:09:28 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:09:28 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:28 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 30 18:09:28 headpi sudo[1809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jul 30 18:09:28 headpi sudo[1809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:28 headpi volumio5-onboarding[1740]: time=2026-07-30T18:09:28.400-04:00 level=INFO msg="system info for f74b5f3e330b19be4c1370a35c810379" deviceName=headpi deviceVariant=volumio deviceModel= softwareVersion=4.119
Jul 30 18:09:28 headpi volumio[1287]: info: Shairport-Sync Started
Jul 30 18:09:28 headpi volumio[1287]: Error adding Membership: Error: addMembership EINVAL
Jul 30 18:09:28 headpi volumio[1287]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Jul 30 18:09:28 headpi volumio[1287]: info: touch_display: X display number found: 0
Jul 30 18:09:28 headpi volumio[1287]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0
Jul 30 18:09:28 headpi volumio[1287]: info: Shairport-Sync Started
Jul 30 18:09:28 headpi systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jul 30 18:09:28 headpi systemd[1]: shairport-sync.service: Deactivated successfully.
Jul 30 18:09:28 headpi systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jul 30 18:09:28 headpi systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jul 30 18:09:28 headpi sudo[1809]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:28 headpi sudo[1851]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Jul 30 18:09:28 headpi sudo[1851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:29 headpi sudo[1851]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:29 headpi volumio[1287]: info: [squeezelite_mc] Notification listener started
Jul 30 18:09:29 headpi volumio[1287]: info: [squeezelite_mc] Getting players connected to canpi (192.168.0.6)
Jul 30 18:09:29 headpi volumio[1287]: info: Shairport-Sync Started
Jul 30 18:09:30 headpi volumio[1287]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Jul 30 18:09:30 headpi volumio[1287]: info: touch_display: X display number found: 0
Jul 30 18:09:30 headpi sudo[1904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Jul 30 18:09:30 headpi sudo[1904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:30 headpi systemd[1]: Reloading.
Jul 30 18:09:31 headpi sudo[1619]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:31 headpi volumio[1287]: info: go-librespot daemon successfully initialized
Jul 30 18:09:32 headpi volumio[1287]: info: [squeezelite_mc] Players connected to canpi (192.168.0.6): [{"id":"cc:cc:a6:e8:22:45","uuid":null,"ip":"192.168.0.6","name":"SHIELD","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:22:b1:12:5f","uuid":null,"ip":"192.168.0.6","name":"Loft","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"2c:cf:67:a3:f9:8d","uuid":null,"ip":"192.168.0.204","name":"kitchenpi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"e4:5f:01:1a:6e:45","uuid":null,"ip":"192.168.0.223","name":"bellapi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:85:95:75:b3","uuid":null,"ip":"192.168.0.6","name":"Living Room","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"b8:27:eb:1e:a1:69","uuid":null,"ip":"192.168.0.240","name":"garagepi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"e4:5f:01:4f:64:ec","uuid":null,"ip":"192.168.0.40","name":"hipi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}}]
Jul 30 18:09:32 headpi volumio[1287]: info: [squeezelite_mc] 'client' notification received from canpi (192.168.0.6); type is 'connect'
Jul 30 18:09:32 headpi volumio[1287]: info: [squeezelite_mc] Getting players connected to canpi (192.168.0.6)
Jul 30 18:09:32 headpi systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal
Jul 30 18:09:32 headpi volumio[1287]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Jul 30 18:09:33 headpi volumio5-onboarding[1740]: time=2026-07-30T18:09:33.408-04:00 level=INFO msg="bootstrapping state" hasInternet=false
Jul 30 18:09:33 headpi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jul 30 18:09:33 headpi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jul 30 18:09:33 headpi sudo[1974]: volumio : PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh
Jul 30 18:09:33 headpi sudo[1974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:34 headpi sudo[1904]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:34 headpi volumio[1287]: info: Received Get System Info
Jul 30 18:09:34 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 30 18:09:34 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 30 18:09:34 headpi volumio[1287]: info: Discovery: Getting this device information
Jul 30 18:09:34 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:09:34 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:34 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 30 18:09:34 headpi volumio[1287]: info: [squeezelite_mc] Players connected to canpi (192.168.0.6): [{"id":"cc:cc:a6:e8:22:45","uuid":null,"ip":"192.168.0.6","name":"SHIELD","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:22:b1:12:5f","uuid":null,"ip":"192.168.0.6","name":"Loft","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"2c:cf:67:a3:f9:8d","uuid":null,"ip":"192.168.0.204","name":"kitchenpi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"e4:5f:01:1a:6e:45","uuid":null,"ip":"192.168.0.223","name":"bellapi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:85:95:75:b3","uuid":null,"ip":"192.168.0.6","name":"Living Room","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"b8:27:eb:1e:a1:69","uuid":null,"ip":"192.168.0.240","name":"garagepi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:84:10:07:52","uuid":null,"ip":"192.168.0.6","name":"Bedroom TV","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"e4:5f:01:4f:64:ec","uuid":null,"ip":"192.168.0.40","name":"hipi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}}]
Jul 30 18:09:34 headpi volumio[1287]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jul 30 18:09:34 headpi volumio[1287]: info: touch_display: Setting screensaver timeout to 0 seconds.
Jul 30 18:09:34 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jul 30 18:09:34 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jul 30 18:09:34 headpi volumio5-onboarding[1740]: time=2026-07-30T18:09:34.326-04:00 level=INFO msg="enabling local network discovery"
Jul 30 18:09:34 headpi volumio5-onboarding[1740]: time=2026-07-30T18:09:34.376-04:00 level=INFO msg="enabling BLE discovery"
Jul 30 18:09:34 headpi sudo[1998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jul 30 18:09:34 headpi sudo[1998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:34 headpi sudo[1998]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:35 headpi systemd[1]: Reloading.
Jul 30 18:09:35 headpi volumio[1287]: info: Initializing connection to go-librespot Websocket
Jul 30 18:09:35 headpi volumio[1287]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Jul 30 18:09:35 headpi volumio5-onboarding[1740]: time=2026-07-30T18:09:35.499-04:00 level=INFO msg="service successfully established" component=discovery/localnet
Jul 30 18:09:36 headpi sudo[2030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Jul 30 18:09:36 headpi sudo[2030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:36 headpi systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal
Jul 30 18:09:37 headpi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jul 30 18:09:37 headpi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jul 30 18:09:38 headpi sudo[1974]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:38 headpi volumio[1287]: info: succeeded
Jul 30 18:09:38 headpi systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jul 30 18:09:38 headpi kernel: process '/opt/squeezelite/squeezelite' started with executable stack
Jul 30 18:09:38 headpi systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:38 headpi sudo[2030]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:38 headpi systemd[1]: squeezelite.service: Deactivated successfully.
Jul 30 18:09:38 headpi systemd[1]: squeezelite.service: Scheduled restart job, restart counter is at 1.
Jul 30 18:09:38 headpi systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:38 headpi volumio[1287]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jul 30 18:09:38 headpi systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jul 30 18:09:38 headpi systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:38 headpi systemd[1]: squeezelite.service: Deactivated successfully.
Jul 30 18:09:38 headpi volumio[1287]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): TypeError: fetch failed
Jul 30 18:09:39 headpi ntpd[1036]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101
Jul 30 18:09:39 headpi ntpd[1036]: DNS: dns_check: DNS error: -11, System error
Jul 30 18:09:39 headpi ntpd[1036]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12
Jul 30 18:09:39 headpi sudo[2051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jul 30 18:09:39 headpi sudo[2051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:39 headpi systemd[1]: squeezelite.service: Scheduled restart job, restart counter is at 2.
Jul 30 18:09:39 headpi systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:39 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Failed to obtain lounge token with screen Id from stored MDX context (4pdr7jmu66jfrlrrbqf8t3dpv1):
Jul 30 18:09:39 headpi volumio[1287]: (ConnectionError) (YouTube Music) Connection error in getting lounge token
Jul 30 18:09:39 headpi volumio[1287]: Error info: {
Jul 30 18:09:39 headpi volumio[1287]: url: 'https://www.youtube.com/api/lounge/pairing/get_lounge_token_batch'
Jul 30 18:09:39 headpi volumio[1287]: }
Jul 30 18:09:39 headpi volumio[1287]: --->(TypeError) fetch failed
Jul 30 18:09:39 headpi volumio[1287]: Stack trace:
Jul 30 18:09:39 headpi volumio[1287]: ConnectionError: (YouTube Music) Connection error in getting lounge token
Jul 30 18:09:39 headpi volumio[1287]: at Session._Session_getLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:440:15)
Jul 30 18:09:39 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:09:39 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:09:39 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:09:39 headpi volumio[1287]: at async Session.begin (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:130:31)
Jul 30 18:09:39 headpi volumio[1287]: at async Promise.all (index 1)
Jul 30 18:09:39 headpi volumio[1287]: at async YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:114:13)
Jul 30 18:09:39 headpi volumio[1287]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/YouTubeCastReceiver.js:93:13)
Jul 30 18:09:39 headpi volumio[1287]: Going to generate fresh screen Id and try again...
Jul 30 18:09:39 headpi systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jul 30 18:09:39 headpi systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:39 headpi systemd[1]: squeezelite.service: Deactivated successfully.
Jul 30 18:09:39 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Failed to obtain lounge token with screen Id from stored MDX context (63faog955aup78sp9rbvm04qo3):
Jul 30 18:09:39 headpi volumio[1287]: (ConnectionError) (YouTube) Connection error in getting lounge token
Jul 30 18:09:39 headpi volumio[1287]: Error info: {
Jul 30 18:09:39 headpi volumio[1287]: url: 'https://www.youtube.com/api/lounge/pairing/get_lounge_token_batch'
Jul 30 18:09:39 headpi volumio[1287]: }
Jul 30 18:09:39 headpi volumio[1287]: --->(TypeError) fetch failed
Jul 30 18:09:39 headpi volumio[1287]: Stack trace:
Jul 30 18:09:39 headpi volumio[1287]: ConnectionError: (YouTube) Connection error in getting lounge token
Jul 30 18:09:39 headpi volumio[1287]: at Session._Session_getLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:440:15)
Jul 30 18:09:39 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:09:39 headpi volumio[1287]: at async Session.begin (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:130:31)
Jul 30 18:09:39 headpi volumio[1287]: at async Promise.all (index 0)
Jul 30 18:09:39 headpi volumio[1287]: at async YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:114:13)
Jul 30 18:09:39 headpi volumio[1287]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/YouTubeCastReceiver.js:93:13)
Jul 30 18:09:39 headpi volumio[1287]: Going to generate fresh screen Id and try again...
Jul 30 18:09:39 headpi systemd[1]: squeezelite.service: Scheduled restart job, restart counter is at 3.
Jul 30 18:09:39 headpi systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:39 headpi systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jul 30 18:09:39 headpi systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:39 headpi systemd[1]: squeezelite.service: Deactivated successfully.
Jul 30 18:09:39 headpi sudo[2051]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:39 headpi systemd[1]: squeezelite.service: Scheduled restart job, restart counter is at 4.
Jul 30 18:09:39 headpi systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:40 headpi systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jul 30 18:09:40 headpi systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:40 headpi systemd[1]: squeezelite.service: Deactivated successfully.
Jul 30 18:09:40 headpi systemd[1]: squeezelite.service: Scheduled restart job, restart counter is at 5.
Jul 30 18:09:40 headpi systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:40 headpi systemd[1]: squeezelite.service: Start request repeated too quickly.
Jul 30 18:09:40 headpi systemd[1]: squeezelite.service: Failed with result 'start-limit-hit'.
Jul 30 18:09:40 headpi systemd[1]: Failed to start squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jul 30 18:09:40 headpi volumio[1287]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jul 30 18:09:40 headpi sudo[2071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jul 30 18:09:40 headpi sudo[2071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jul 30 18:09:40 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 8.
Jul 30 18:09:40 headpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:40 headpi sudo[2071]: pam_unix(sudo:session): session closed for user root
Jul 30 18:09:40 headpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:41 headpi upmpdcli[2078]: Could not open config: /tmp/upmpdcli.conf
Jul 30 18:09:41 headpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:09:41 headpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Jul 30 18:09:45 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 30 18:09:45 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:09:45 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Jul 30 18:09:47 headpi volumio[1287]: info: [squeezelite_mc] 'client' notification received from canpi (192.168.0.6); type is 'disconnect'
Jul 30 18:09:47 headpi volumio[1287]: error: Plugin music_service squeezelite_mc failed to complete 'onStart' in a timely fashion
Jul 30 18:09:48 headpi volumio[1287]: error: Plugin music_service ytcr failed to complete 'onStart' in a timely fashion
Jul 30 18:09:48 headpi volumio[1287]: info: -------------------------------------------
Jul 30 18:09:48 headpi volumio[1287]: info: ----- MyVolumio plugins startup ----
Jul 30 18:09:48 headpi volumio[1287]: info: -------------------------------------------
Jul 30 18:09:48 headpi volumio[1287]: info: [MyVolumio PluginManager] Fetching plans data....
Jul 30 18:09:48 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 30 18:09:48 headpi volumio[1287]: info: Discovery: Getting this device information
Jul 30 18:09:48 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:09:48 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:48 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 30 18:09:49 headpi volumio[1287]: info: [squeezelite_mc] 'client' notification received from canpi (192.168.0.6); type is 'connect'
Jul 30 18:09:49 headpi volumio[1287]: info: [squeezelite_mc] Getting players connected to canpi (192.168.0.6)
Jul 30 18:09:49 headpi volumio[1287]: info: [squeezelite_mc] Players connected to canpi (192.168.0.6): [{"id":"cc:cc:a6:e8:22:45","uuid":null,"ip":"192.168.0.6","name":"SHIELD","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:22:b1:12:5f","uuid":null,"ip":"192.168.0.6","name":"Loft","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"2c:cf:67:a3:f9:8d","uuid":null,"ip":"192.168.0.204","name":"kitchenpi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"e4:5f:01:1a:6e:45","uuid":null,"ip":"192.168.0.223","name":"bellapi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:85:95:75:b3","uuid":null,"ip":"192.168.0.6","name":"Living Room","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"b8:27:eb:1e:a1:69","uuid":null,"ip":"192.168.0.240","name":"garagepi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"cc:cc:84:10:07:52","uuid":null,"ip":"192.168.0.6","name":"Bedroom TV","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}},{"id":"e4:5f:01:4f:64:ec","uuid":null,"ip":"192.168.0.40","name":"hipi","server":{"ip":"192.168.0.6","name":"canpi","ver":"9.1.1","uuid":"9bf0a2c9-66e8-44c9-9968-4ef6f63d753d","jsonPort":"9000","cliPort":"9090"}}]
Jul 30 18:09:49 headpi go-librespot[1733]: time="2026-07-30T18:09:49-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy"
Jul 30 18:09:49 headpi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:09:49 headpi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 30 18:09:50 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:09:50 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:09:50 headpi volumio[1287]: AID: null,
Jul 30 18:09:50 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:09:50 headpi volumio[1287]: payload: {}
Jul 30 18:09:50 headpi volumio[1287]: }
Jul 30 18:09:50 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:09:50 headpi volumio[1287]: Stack trace:
Jul 30 18:09:50 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:09:50 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:09:50 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:09:50 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:09:50 headpi volumio[1287]: at AsyncTaskQueue.push (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:39:23)
Jul 30 18:09:50 headpi volumio[1287]: at /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:345:67
Jul 30 18:09:50 headpi volumio[1287]: at new Promise ()
Jul 30 18:09:50 headpi volumio[1287]: at Session.sendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:344:16)
Jul 30 18:09:50 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:241:28)
Jul 30 18:09:50 headpi volumio[1287]: at Session.begin (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:209:26)
Jul 30 18:09:50 headpi volumio[1287]: error: [yt-cast-receiver] Failed to start receiver:
Jul 30 18:09:50 headpi volumio[1287]: (AppError) Failed to start YouTubeApp
Jul 30 18:09:50 headpi volumio[1287]: --->(SessionError) (YouTube Music) Failed to establish session
Jul 30 18:09:50 headpi volumio[1287]: ------>(ConnectionError) (YouTube Music) Connection error in generating screen Id
Jul 30 18:09:50 headpi volumio[1287]: Error info: {
Jul 30 18:09:50 headpi volumio[1287]: url: 'https://www.youtube.com/api/lounge/pairing/generate_screen_id'
Jul 30 18:09:50 headpi volumio[1287]: }
Jul 30 18:09:50 headpi volumio[1287]: --------->(TypeError) fetch failed
Jul 30 18:09:50 headpi volumio[1287]: Stack trace:
Jul 30 18:09:50 headpi volumio[1287]: AppError: Failed to start YouTubeApp
Jul 30 18:09:50 headpi volumio[1287]: at YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:131:19)
Jul 30 18:09:50 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:09:50 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:09:50 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:09:50 headpi volumio[1287]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/YouTubeCastReceiver.js:93:13)
Jul 30 18:09:50 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:09:50 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:09:50 headpi volumio[1287]: AID: null,
Jul 30 18:09:50 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:09:50 headpi volumio[1287]: payload: {}
Jul 30 18:09:50 headpi volumio[1287]: }
Jul 30 18:09:50 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:09:50 headpi volumio[1287]: Stack trace:
Jul 30 18:09:50 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:09:50 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:09:50 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:09:50 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:09:50 headpi volumio[1287]: at AsyncTaskQueue.push (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:39:23)
Jul 30 18:09:50 headpi volumio[1287]: at /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:345:67
Jul 30 18:09:50 headpi volumio[1287]: at new Promise ()
Jul 30 18:09:50 headpi volumio[1287]: at Session.sendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:344:16)
Jul 30 18:09:50 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:241:28)
Jul 30 18:09:50 headpi volumio[1287]: at /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:123:39
Jul 30 18:09:50 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:09:50 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:09:50 headpi volumio[1287]: AID: null,
Jul 30 18:09:50 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:09:50 headpi volumio[1287]: payload: {}
Jul 30 18:09:50 headpi volumio[1287]: }
Jul 30 18:09:50 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:09:50 headpi volumio[1287]: Stack trace:
Jul 30 18:09:50 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:09:50 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:09:50 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:09:50 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:09:50 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:09:50 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:09:50 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:09:50 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:09:50 headpi volumio[1287]: error: [ytcr] Failed to start plugin:
Jul 30 18:09:50 headpi volumio[1287]: (AppError) Failed to start YouTubeApp
Jul 30 18:09:50 headpi volumio[1287]: --->(SessionError) (YouTube Music) Failed to establish session
Jul 30 18:09:50 headpi volumio[1287]: ------>(ConnectionError) (YouTube Music) Connection error in generating screen Id
Jul 30 18:09:50 headpi volumio[1287]: Error info: {
Jul 30 18:09:50 headpi volumio[1287]: url: 'https://www.youtube.com/api/lounge/pairing/generate_screen_id'
Jul 30 18:09:50 headpi volumio[1287]: }
Jul 30 18:09:50 headpi volumio[1287]: --------->(TypeError) fetch failed
Jul 30 18:09:50 headpi volumio[1287]: Stack trace:
Jul 30 18:09:50 headpi volumio[1287]: AppError: Failed to start YouTubeApp
Jul 30 18:09:50 headpi volumio[1287]: at YouTubeApp.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:131:19)
Jul 30 18:09:50 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:09:50 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:09:50 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:09:50 headpi volumio[1287]: at async YouTubeCastReceiver.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/YouTubeCastReceiver.js:93:13)
Jul 30 18:09:50 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:09:50 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:09:50 headpi volumio[1287]: AID: null,
Jul 30 18:09:50 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:09:50 headpi volumio[1287]: payload: {}
Jul 30 18:09:50 headpi volumio[1287]: }
Jul 30 18:09:50 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:09:50 headpi volumio[1287]: Stack trace:
Jul 30 18:09:50 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:09:50 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:09:50 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:09:50 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:09:50 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:09:50 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:09:50 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:09:50 headpi volumio[1287]: at async /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:123:25
Jul 30 18:09:52 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4
Jul 30 18:09:52 headpi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Jul 30 18:09:52 headpi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jul 30 18:09:52 headpi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jul 30 18:09:53 headpi go-librespot[2184]: go-librespot daemon starting...
Jul 30 18:09:53 headpi go-librespot[2185]: time="2026-07-30T18:09:53-04:00" level=info msg="running go-librespot 0.7.1"
Jul 30 18:09:53 headpi go-librespot[2185]: time="2026-07-30T18:09:53-04:00" level=debug msg="app state loaded"
Jul 30 18:09:53 headpi go-librespot[2185]: time="2026-07-30T18:09:53-04:00" level=info msg="api server listening on 127.0.0.1:9879"
Jul 30 18:09:54 headpi volumio[1287]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined
Jul 30 18:09:54 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo
Jul 30 18:09:55 headpi volumio[1287]: info: Listing playlists
Jul 30 18:09:55 headpi volumio[1287]: info: CoreCommandRouter::volumioGetQueue
Jul 30 18:09:55 headpi volumio[1287]: info: CoreStateMachine::getQueue
Jul 30 18:09:55 headpi volumio[1287]: info: CorePlayQueue::getQueue
Jul 30 18:09:55 headpi volumio[1287]: info: CoreCommandRouter::volumioGetVisibleSources
Jul 30 18:09:55 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 30 18:09:55 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:09:55 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:09:55 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 30 18:09:55 headpi volumio[1287]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Keeping The Blade","artist":"Coheed and Cambria","album":"Good Apollo I'm Burning Star IV Volume One: From Fear Through The Eyes Of Madness","duration":"129","uri":"spotify:track:4Dc5crLrKYIIqf6sk0PvQm","service":""}
Jul 30 18:09:55 headpi volumio[1287]: info: [now-playing] LRCLIB getLyrics(): song: "Keeping The Blade" album: "Good Apollo I'm Burning Star IV Volume One: From Fear Through The Eyes Of Madness" artist: "Coheed and Cambria" duration: "129"
Jul 30 18:09:55 headpi volumio[1287]: info: [now-playing] LRCLIB getLyrics() API URL: https://lrclib.net/api/get?track_name=Keeping+The+Blade&artist_name=Coheed+and+Cambria&album_name=Good+Apollo+I%27m+Burning+Star+IV+Volume+One%3A+From+Fear+Through+The+Eyes+Of+Madness&duration=129
Jul 30 18:09:56 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 9.
Jul 30 18:09:56 headpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:56 headpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:09:56 headpi volumio[1287]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.119&uuid=f74b5f3e330b19be4c1370a35c810379" http://updates.volumio.org/downloader-v1/track-device
Jul 30 18:09:56 headpi volumio[1287]: % Total % Received % Xferd Average Speed Time Time Time Current
Jul 30 18:09:56 headpi volumio[1287]: Dload Upload Total Spent Left Speed
Jul 30 18:09:56 headpi volumio[1287]: [2.1K blob data]
Jul 30 18:09:56 headpi volumio[1287]: retrying in 5 seconds, trial 0
Jul 30 18:09:56 headpi volumio[1287]: info: Volumio Calling Home
Jul 30 18:09:56 headpi upmpdcli[2205]: Could not open config: /tmp/upmpdcli.conf
Jul 30 18:09:56 headpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:09:56 headpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:02 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:02 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:02 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:10:02 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:02 headpi volumio[1287]: AID: null,
Jul 30 18:10:02 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:02 headpi volumio[1287]: payload: {}
Jul 30 18:10:02 headpi volumio[1287]: }
Jul 30 18:10:02 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:02 headpi volumio[1287]: Stack trace:
Jul 30 18:10:02 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:02 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:02 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:02 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:02 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:02 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:02 headpi volumio[1287]: at async /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/YouTubeApp.js:123:25
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:02 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:02 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:02 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:10:02 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:02 headpi volumio[1287]: AID: null,
Jul 30 18:10:02 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:02 headpi volumio[1287]: payload: {}
Jul 30 18:10:02 headpi volumio[1287]: }
Jul 30 18:10:02 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:02 headpi volumio[1287]: Stack trace:
Jul 30 18:10:02 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:02 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:02 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:02 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:02 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:02 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:02 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:02 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:02 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:10:02 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:02 headpi volumio[1287]: AID: null,
Jul 30 18:10:02 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:02 headpi volumio[1287]: payload: {}
Jul 30 18:10:02 headpi volumio[1287]: }
Jul 30 18:10:02 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:02 headpi volumio[1287]: Stack trace:
Jul 30 18:10:02 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:02 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:02 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:02 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:02 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:02 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:02 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:02 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:02 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:10:02 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:02 headpi volumio[1287]: AID: null,
Jul 30 18:10:02 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:02 headpi volumio[1287]: payload: {}
Jul 30 18:10:02 headpi volumio[1287]: }
Jul 30 18:10:02 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:02 headpi volumio[1287]: Stack trace:
Jul 30 18:10:02 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:02 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:02 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:02 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:02 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:02 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:02 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:03 headpi volumio[1287]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): TypeError: fetch failed
Jul 30 18:10:03 headpi volumio[1287]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not fetch weather: fetch failed
Jul 30 18:10:03 headpi volumio[1287]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:124:25)
Jul 30 18:10:03 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:03 headpi volumio[1287]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:126:28)
Jul 30 18:10:04 headpi volumio[1287]: info: Discovery: adding 950868d9-c94c-47b7-9749-c9140e9de2cd
Jul 30 18:10:04 headpi volumio[1287]: info: Discovery: Found device kitchenpi
Jul 30 18:10:04 headpi volumio[1287]: info: Discovery: Connecting to remote: 192.168.0.204
Jul 30 18:10:04 headpi volumio[1287]: info: Discovery: adding b8f65b55-d881-41f3-9133-e34fb723d5b9
Jul 30 18:10:04 headpi volumio[1287]: info: Discovery: Found device hipi
Jul 30 18:10:04 headpi volumio[1287]: info: Discovery: Connecting to remote: 192.168.0.40
Jul 30 18:10:05 headpi volumio[1287]: info: Discovery: Connected to remote: 192.168.0.40
Jul 30 18:10:05 headpi volumio[1287]: info: Discovery: Connected to remote: 192.168.0.204
Jul 30 18:10:06 headpi volumio[1287]: error: [now-playing] Error fetching lyrics from LRCLIB (URL: https://lrclib.net/api/get?track_name=Keeping+The+Blade&artist_name=Coheed+and+Cambria&album_name=Good+Apollo+I%27m+Burning+Star+IV+Volume+One%3A+From+Fear+Through+The+Eyes+Of+Madness&duration=129): TypeError: fetch failed
Jul 30 18:10:06 headpi volumio[1287]: at Object.fetch (node:internal/deps/undici/undici:11576:11)
Jul 30 18:10:06 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:06 headpi volumio[1287]: at async apiGet (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:16:26)
Jul 30 18:10:06 headpi volumio[1287]: at async LRCLibAPI.getLyrics (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:33:24)
Jul 30 18:10:06 headpi volumio[1287]: at async DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:73:37)
Jul 30 18:10:06 headpi volumio[1287]: at async /data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:135:40
Jul 30 18:10:08 headpi volumio[1287]: error: MyVolumio Plugin failed to start in a timely fashion
Jul 30 18:10:08 headpi volumio[1287]: [Metrics] CommandRouter: 114s 469.34ms
Jul 30 18:10:08 headpi volumio[1287]: info: CoreCommandRouter::volumiosetStartupVolume
Jul 30 18:10:08 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 30 18:10:08 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 30 18:10:08 headpi volumio[1287]: info: CoreCommandRouter::Close All Modals sent
Jul 30 18:10:08 headpi volumio[1287]: info: CoreCommandRouter::Close All Modals sent
Jul 30 18:10:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Jul 30 18:10:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Jul 30 18:10:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: raat , onStop
Jul 30 18:10:09 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Jul 30 18:10:10 headpi volumio[1287]: info: Discovery: adding a9d922c1-1c58-4259-8405-e2bc7cc65cba
Jul 30 18:10:10 headpi volumio[1287]: info: Discovery: Found device headpi
Jul 30 18:10:10 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:10 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:10 headpi volumio[1287]: info: Discovery: this is already registered, a9d922c1-1c58-4259-8405-e2bc7cc65cba
Jul 30 18:10:10 headpi volumio[1287]: info: Discovery: Found device headpi
Jul 30 18:10:10 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:10 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:11 headpi volumio[1287]: info: Discovery: adding b42f7d45-d35a-49b6-bc8d-8a63806da5d3
Jul 30 18:10:11 headpi volumio[1287]: info: Discovery: Found device bellapi
Jul 30 18:10:11 headpi volumio[1287]: info: Discovery: Connecting to remote: 192.168.0.223
Jul 30 18:10:11 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Jul 30 18:10:11 headpi volumio[1287]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.40 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6
Jul 30 18:10:11 headpi volumio[1287]: info: Discovery: this is already registered, b42f7d45-d35a-49b6-bc8d-8a63806da5d3
Jul 30 18:10:11 headpi volumio[1287]: info: Discovery: Found device garagepi
Jul 30 18:10:11 headpi volumio[1287]: info: Discovery: Connecting to remote: 192.168.0.240
Jul 30 18:10:11 headpi go-librespot[2185]: time="2026-07-30T18:10:11-04:00" level=debug msg="new websocket client"
Jul 30 18:10:11 headpi volumio[1287]: info: Connection to go-librespot Websocket established
Jul 30 18:10:11 headpi volumio[1287]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.40 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7
Jul 30 18:10:11 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 10.
Jul 30 18:10:11 headpi volumio[1287]: info: Volumio called home
Jul 30 18:10:11 headpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:10:11 headpi volumio[1287]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.223 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Jul 30 18:10:11 headpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:10:12 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Jul 30 18:10:12 headpi upmpdcli[2237]: Could not open config: /tmp/upmpdcli.conf
Jul 30 18:10:12 headpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:10:12 headpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Jul 30 18:10:12 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10
Jul 30 18:10:12 headpi volumio[1287]: info: Discovery: Connected to remote: 192.168.0.240
Jul 30 18:10:12 headpi volumio[1287]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.240 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11
Jul 30 18:10:12 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Jul 30 18:10:12 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:12 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:13 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:13 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:13 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Jul 30 18:10:13 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:13 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:13 headpi volumio[1287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:13 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:13 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:13 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:10:13 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:13 headpi volumio[1287]: AID: null,
Jul 30 18:10:13 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:13 headpi volumio[1287]: payload: {}
Jul 30 18:10:13 headpi volumio[1287]: }
Jul 30 18:10:13 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:13 headpi volumio[1287]: Stack trace:
Jul 30 18:10:13 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:13 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:13 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:13 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:13 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:13 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:13 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:13 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:13 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:10:13 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:13 headpi volumio[1287]: AID: null,
Jul 30 18:10:13 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:13 headpi volumio[1287]: payload: {}
Jul 30 18:10:13 headpi volumio[1287]: }
Jul 30 18:10:13 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:13 headpi volumio[1287]: Stack trace:
Jul 30 18:10:13 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:13 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:13 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:13 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:13 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:13 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:13 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:13 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:13 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:10:13 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:13 headpi volumio[1287]: AID: null,
Jul 30 18:10:13 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:13 headpi volumio[1287]: payload: {}
Jul 30 18:10:13 headpi volumio[1287]: }
Jul 30 18:10:13 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:13 headpi volumio[1287]: Stack trace:
Jul 30 18:10:13 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:13 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:13 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:13 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:13 headpi volumio[1287]: at processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: at runNextTicks (node:internal/process/task_queues:64:3)
Jul 30 18:10:13 headpi volumio[1287]: at process.processImmediate (node:internal/timers:449:9)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:13 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:13 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:10:13 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:13 headpi volumio[1287]: AID: null,
Jul 30 18:10:13 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:13 headpi volumio[1287]: payload: {}
Jul 30 18:10:13 headpi volumio[1287]: }
Jul 30 18:10:13 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:13 headpi volumio[1287]: Stack trace:
Jul 30 18:10:13 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:13 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:13 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:13 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:13 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:13 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:13 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:13 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:13 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:15 headpi volumio[1287]: info: Getting Spotify volume
Jul 30 18:10:15 headpi volumio[1287]: info: BOOT COMPLETED
Jul 30 18:10:16 headpi volumio[1287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12
Jul 30 18:10:17 headpi volumio[1287]: info: CoreCommandRouter::volumioGetState
Jul 30 18:10:17 headpi volumio[1287]: info: CorePlayQueue::getTrack 0
Jul 30 18:10:18 headpi volumio[1287]: info: New Spotify access tokenBQCIs95TLJ...
Jul 30 18:10:18 headpi volumio[1287]: info: Spotify credentials grant success - running version from March 24, 2019
Jul 30 18:10:19 headpi volumio[1287]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.204 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13
Jul 30 18:10:19 headpi volumio[1287]: verbose: New Socket.io Connection to 192.168.0.58:3000 from 192.168.0.204 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14
Jul 30 18:10:21 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:21 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:21 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:21 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:21 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:21 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask:
Jul 30 18:10:21 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:21 headpi volumio[1287]: AID: null,
Jul 30 18:10:21 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:21 headpi volumio[1287]: payload: {}
Jul 30 18:10:21 headpi volumio[1287]: }
Jul 30 18:10:21 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:21 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:21 headpi volumio[1287]: Stack trace:
Jul 30 18:10:21 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:21 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:21 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:21 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:21 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:21 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:21 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:22 headpi go-librespot[2185]: time="2026-07-30T18:10:22-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": net/http: TLS handshake timeout"
Jul 30 18:10:22 headpi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:10:22 headpi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 30 18:10:22 headpi volumio[1287]: error: [yt-cast-receiver] Caught error refreshing lounge token:
Jul 30 18:10:22 headpi volumio[1287]: (TypeError) Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:22 headpi volumio[1287]: TypeError: Cannot read properties of undefined (reading 'removeAllListeners')
Jul 30 18:10:22 headpi volumio[1287]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:377:16)
Jul 30 18:10:22 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:22 headpi volumio[1287]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask:
Jul 30 18:10:22 headpi volumio[1287]: LoungeScreenDisconnected {
Jul 30 18:10:22 headpi volumio[1287]: AID: null,
Jul 30 18:10:22 headpi volumio[1287]: name: 'loungeScreenDisconnected',
Jul 30 18:10:22 headpi volumio[1287]: payload: {}
Jul 30 18:10:22 headpi volumio[1287]: }
Jul 30 18:10:22 headpi volumio[1287]: (IncompleteAPIDataError) Missing data required to construct query string from bind params
Jul 30 18:10:22 headpi volumio[1287]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] }
Jul 30 18:10:22 headpi volumio[1287]: Stack trace:
Jul 30 18:10:22 headpi volumio[1287]: IncompleteAPIDataError: Missing data required to construct query string from bind params
Jul 30 18:10:22 headpi volumio[1287]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/BindParams.js:120:19)
Jul 30 18:10:22 headpi volumio[1287]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:497:103)
Jul 30 18:10:22 headpi volumio[1287]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:558:71)
Jul 30 18:10:22 headpi volumio[1287]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/utils/AsyncTaskQueue.js:52:32)
Jul 30 18:10:22 headpi volumio[1287]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/Session.js:242:71)
Jul 30 18:10:22 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Jul 30 18:10:22 headpi volumio[1287]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 30 18:10:22 headpi volumio[1287]: Error: socket hang up
Jul 30 18:10:22 headpi volumio[1287]: at connResetException (node:internal/errors:720:14)
Jul 30 18:10:22 headpi volumio[1287]: at Socket.socketOnEnd (node:_http_client:519:23)
Jul 30 18:10:22 headpi volumio[1287]: at Socket.emit (node:events:526:35)
Jul 30 18:10:22 headpi volumio[1287]: at endReadableNT (node:internal/streams/readable:1376:12)
Jul 30 18:10:22 headpi volumio[1287]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Jul 30 18:10:22 headpi volumio[1287]: code: 'ECONNRESET',
Jul 30 18:10:22 headpi volumio[1287]: response: undefined
Jul 30 18:10:22 headpi volumio[1287]: }
Jul 30 18:10:22 headpi volumio[1287]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 30 18:10:25 headpi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Jul 30 18:10:25 headpi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jul 30 18:10:25 headpi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jul 30 18:10:25 headpi go-librespot[2279]: go-librespot daemon starting...
Jul 30 18:10:25 headpi go-librespot[2280]: time="2026-07-30T18:10:25-04:00" level=info msg="running go-librespot 0.7.1"
Jul 30 18:10:25 headpi go-librespot[2280]: time="2026-07-30T18:10:25-04:00" level=debug msg="app state loaded"
Jul 30 18:10:25 headpi go-librespot[2280]: time="2026-07-30T18:10:25-04:00" level=info msg="api server listening on 127.0.0.1:9879"
Jul 30 18:10:27 headpi systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11.
Jul 30 18:10:27 headpi systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:10:27 headpi systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 30 18:10:27 headpi upmpdcli[2288]: Could not open config: /tmp/upmpdcli.conf
Jul 30 18:10:27 headpi systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Jul 30 18:10:27 headpi systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Jul 30 18:10:30 headpi sudo[2291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-07-30 18:09'
Jul 30 18:10:30 headpi sudo[2291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026"
VOLUMIO_VERSION="4.119"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"