Mar 28 20:36:00 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:36:02 car-pc go-librespot[4689]: time="2026-03-28T20:36:02+01:00" level=trace msg="sent dealer ping" Mar 28 20:36:02 car-pc go-librespot[4689]: time="2026-03-28T20:36:02+01:00" level=trace msg="received dealer pong" Mar 28 20:36:04 car-pc bluealsa[994]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_62_41_5D_EF_B9_68, ...) Mar 28 20:36:04 car-pc bluealsa[994]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_45_D8_F8_B2_D9_8C, ...) Mar 28 20:36:06 car-pc volumio[4414]: info: CALLMETHOD: music_service ytmusic configSaveDisclaimer [object Object] Mar 28 20:36:06 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: ytmusic , configSaveDisclaimer Mar 28 20:36:06 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:36:10 car-pc volumio[4414]: info: [ytmusic] Innertube support service: Deno not installed or otherwise failed to start: Command failed: npx --no-install --yes deno --version Mar 28 20:36:10 car-pc volumio[4414]: info: [ytmusic] Innertube support service: Start service with Node Mar 28 20:36:11 car-pc bluealsa[994]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_4A_48_87_65_4A_94, ...) Mar 28 20:36:12 car-pc volumio[4414]: info: [ytmusic] Innertube support service: result: {"status":"started","server":{"address":"127.0.0.1","port":46073}} Mar 28 20:36:12 car-pc volumio[4414]: info: [ytmusic] Innertube support service running at http://127.0.0.1:46073 Mar 28 20:36:12 car-pc volumio[4414]: info: CALLMETHOD: music_service ytmusic showDisclaimer undefined Mar 28 20:36:12 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: ytmusic , showDisclaimer Mar 28 20:36:16 car-pc volumio[4414]: [YOUTUBEJS][Player]: Failed to extract signature decipher function. Mar 28 20:36:16 car-pc volumio[4414]: [YOUTUBEJS][Player]: Failed to extract n decipher function. Mar 28 20:36:18 car-pc volumio[4414]: info: [ytmusic] Obtained session PO token using visitorData (expires in 43199 seconds) Mar 28 20:36:18 car-pc bluealsa[994]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_69_BF_65_89_5E_15, ...) Mar 28 20:36:21 car-pc volumio[4414]: [YOUTUBEJS][Player]: Failed to extract signature decipher function. Mar 28 20:36:21 car-pc volumio[4414]: [YOUTUBEJS][Player]: Failed to extract n decipher function. Mar 28 20:36:21 car-pc volumio[4414]: info: [ytmusic] Going to refresh session PO token in 43099 seconds Mar 28 20:36:21 car-pc volumio[4414]: info: CoreCommandRouter::volumioPlay Mar 28 20:36:21 car-pc volumio[4414]: info: CoreStateMachine::play index undefined Mar 28 20:36:21 car-pc volumio[4414]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 20:36:21 car-pc volumio[4414]: info: CorePlayQueue::getTrack 7 Mar 28 20:36:21 car-pc volumio[4414]: info: CoreStateMachine::startPlaybackTimer Mar 28 20:36:21 car-pc volumio[4414]: info: CorePlayQueue::getTrack 7 Mar 28 20:36:21 car-pc volumio[4414]: info: [1774726581511] ControllerSpotify::clearAddPlayTrack Mar 28 20:36:21 car-pc volumio[4414]: info: Sending Spotify command with payload to local API: /player/play Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=debug msg="resolved context of track" uri="spotify:track:7mSydMVoNUM2N3UzZvmeoC" Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7mSydMVoNUM2N3UzZvmeoC" Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:7mSydMVoNUM2N3UzZvmeoC" Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=trace msg="emitting websocket event: will_play" Mar 28 20:36:21 car-pc volumio[4414]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:7mSydMVoNUM2N3UzZvmeoC","uri":"spotify:track:7mSydMVoNUM2N3UzZvmeoC","play_origin":"go-librespot"}} Mar 28 20:36:21 car-pc bluealsa[994]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_4D_D3_A5_E7_70_AB, ...) Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=debug msg="selected format OGG_VORBIS_320 (893e1bfce91a3894cb2c6bbfa40694b74a9283b5)" uri="spotify:track:7mSydMVoNUM2N3UzZvmeoC" Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=debug msg="requested aes key for file 893e1bfce91a3894cb2c6bbfa40694b74a9283b5, gid: 5r2UHmpAlmT3zx8nfUVYS0" Mar 28 20:36:21 car-pc go-librespot[4689]: time="2026-03-28T20:36:21+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:7mSydMVoNUM2N3UzZvmeoC: failed retrieving audio key: failed retrieving aes key with code 1" Mar 28 20:36:21 car-pc volumio[4414]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Mar 28 20:36:27 car-pc volumio5-onboarding[1530]: time=2026-03-28T20:36:27.466+01:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.0.8:50610 error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 28 20:36:27 car-pc volumio5-onboarding[1530]: time=2026-03-28T20:36:27.466+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.0.8:50610 Mar 28 20:36:27 car-pc volumio5-onboarding[1530]: time=2026-03-28T20:36:27.467+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.0.8:50610 Mar 28 20:36:30 car-pc bluealsa[994]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_79_4A_3C_94_69_17, ...) Mar 28 20:36:32 car-pc go-librespot[4689]: time="2026-03-28T20:36:32+01:00" level=trace msg="sent dealer ping" Mar 28 20:36:32 car-pc go-librespot[4689]: time="2026-03-28T20:36:32+01:00" level=trace msg="received dealer pong" Mar 28 20:36:42 car-pc bluealsa[994]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_4A_48_87_65_4A_94, ...) Mar 28 20:36:53 car-pc bluealsa[994]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_4D_D3_A5_E7_70_AB, ...) Mar 28 20:36:57 car-pc volumio[4414]: info: CALLMETHOD: music_service ytmusic acceptDisclaimer Mar 28 20:36:57 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: ytmusic , acceptDisclaimer Mar 28 20:36:57 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:02 car-pc go-librespot[4689]: time="2026-03-28T20:37:02+01:00" level=trace msg="received accesspoint ping" Mar 28 20:37:02 car-pc go-librespot[4689]: time="2026-03-28T20:37:02+01:00" level=trace msg="received accesspoint pong ack" Mar 28 20:37:02 car-pc go-librespot[4689]: time="2026-03-28T20:37:02+01:00" level=trace msg="sent dealer ping" Mar 28 20:37:02 car-pc go-librespot[4689]: time="2026-03-28T20:37:02+01:00" level=trace msg="received dealer pong" Mar 28 20:37:13 car-pc volumio[4414]: info: CoreCommandRouter::volumioGetState Mar 28 20:37:13 car-pc volumio[4414]: info: CorePlayQueue::getTrack 7 Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:16 car-pc volumio[4414]: info: Retrieving Cloud Streaming UI Mar 28 20:37:16 car-pc volumio[4414]: info: Getting Tidal Cloud Configuration Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:16 car-pc volumio[4414]: info: Getting Qobuz Cloud Configuration Mar 28 20:37:16 car-pc volumio[4414]: info: Asking plugin for UI Config Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:16 car-pc volumio[4414]: info: Getting Spotify Cloud Configuration Mar 28 20:37:16 car-pc volumio[4414]: info: Asking plugin for UI Config Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:16 car-pc volumio[4414]: info: Saving Spotify Acccount Mar 28 20:37:16 car-pc volumio[4414]: info: Got Tidal Cloud Configuration Mar 28 20:37:16 car-pc volumio[4414]: info: Got it Mar 28 20:37:16 car-pc volumio[4414]: info: Got it Mar 28 20:37:16 car-pc volumio[4414]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 20:37:16 car-pc volumio[4414]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::volumioGetBrowseSources Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::volumioGetBrowseSources Mar 28 20:37:16 car-pc volumio[4414]: info: CoreCommandRouter::volumioGetBrowseSources Mar 28 20:37:17 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 28 20:37:18 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 28 20:37:21 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 28 20:37:23 car-pc volumio[4414]: info: Disabling MyMusic plugin upnp Mar 28 20:37:23 car-pc sudo[8136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Mar 28 20:37:23 car-pc sudo[8136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 20:37:23 car-pc systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Mar 28 20:37:24 car-pc volumio[4414]: info: Enabling MyMusic plugin upnp Mar 28 20:37:24 car-pc volumio[4414]: info: Enabling plugin upnp Mar 28 20:37:24 car-pc volumio[4414]: info: Loading plugin "upnp"... Mar 28 20:37:24 car-pc volumio[4414]: info: [1774726644436] Starting Upmpd Daemon Mar 28 20:37:24 car-pc volumio[4414]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 20:37:24 car-pc volumio[4414]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 20:37:24 car-pc volumio[4414]: Error: listen EADDRINUSE: address already in use :::6599 Mar 28 20:37:24 car-pc volumio[4414]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Mar 28 20:37:24 car-pc volumio[4414]: at listenInCluster (node:net:1920:12) Mar 28 20:37:24 car-pc volumio[4414]: at Server.listen (node:net:2008:7) Mar 28 20:37:24 car-pc volumio[4414]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Mar 28 20:37:24 car-pc volumio[4414]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Mar 28 20:37:24 car-pc volumio[4414]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Mar 28 20:37:24 car-pc volumio[4414]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 28 20:37:24 car-pc volumio[4414]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Mar 28 20:37:24 car-pc volumio[4414]: code: 'EADDRINUSE', Mar 28 20:37:24 car-pc volumio[4414]: errno: -98, Mar 28 20:37:24 car-pc volumio[4414]: syscall: 'listen', Mar 28 20:37:24 car-pc volumio[4414]: address: '::', Mar 28 20:37:24 car-pc volumio[4414]: port: 6599 Mar 28 20:37:24 car-pc volumio[4414]: } Mar 28 20:37:24 car-pc volumio[4414]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 20:37:24 car-pc sudo[8153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 20:36' Mar 28 20:37:24 car-pc sudo[8153]: 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"