Mar 28 22:56:01 volumio bluealsa[1113]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_68_B3_A6_24_AE_0C, ...) Mar 28 22:56:02 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 28 22:56:05 volumio bluealsa[1113]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_74_CA_B6_EA_71_C7, ...) Mar 28 22:56:06 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:06 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:11 volumio bluealsa[1113]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_60_A9_37_5B_BE_34, ...) Mar 28 22:56:14 volumio go-librespot[1938]: time="2026-03-28T22:56:14+02:00" level=trace msg="sent dealer ping" Mar 28 22:56:35 volumio bluealsa[1113]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_68_B3_A6_24_AE_0C, ...) Mar 28 22:56:35 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 28 22:56:35 volumio volumio[1402]: info: CURURI: music-library Mar 28 22:56:35 volumio go-librespot[1938]: time="2026-03-28T22:56:35+02:00" level=trace msg="received accesspoint ping" Mar 28 22:56:35 volumio go-librespot[1938]: time="2026-03-28T22:56:35+02:00" level=trace msg="received dealer pong" Mar 28 22:56:35 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:35 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:35 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:56:36 volumio volumio[1402]: verbose: New Socket.io Connection to 10.8.1.103 from 10.8.1.219 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Mar 28 22:56:36 volumio volumio[1402]: verbose: New Socket.io Connection to 10.8.1.103 from 10.8.1.219 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:36 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:36 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 28 22:56:36 volumio volumio[1402]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 28 22:56:36 volumio volumio[1402]: info: Received Get System Info Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 22:56:36 volumio volumio[1402]: info: Discovery: Getting this device information Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:36 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:36 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:36 volumio volumio[1402]: info: Listing playlists Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::volumioGetQueue Mar 28 22:56:36 volumio volumio[1402]: info: CoreStateMachine::getQueue Mar 28 22:56:36 volumio volumio[1402]: info: CorePlayQueue::getQueue Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 22:56:36 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 28 22:56:36 volumio go-librespot[1938]: time="2026-03-28T22:56:36+02:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 10.8.1.103:52566->104.199.65.9:80: read: connection reset by peer" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="completed keyexchange" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="completed challenge" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=info msg="authenticated AP" username="31************************5i" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="re-established accesspoint connection" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=trace msg="received accesspoint ping" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 22:56:38 volumio volumio[1402]: info: Executing endpoint metavolumio Mar 28 22:56:38 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 22:56:38 volumio volumio[1402]: info: Executing endpoint metavolumio Mar 28 22:56:38 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 22:56:38 volumio go-librespot[1938]: time="2026-03-28T22:56:38+02:00" level=trace msg="received accesspoint pong ack" Mar 28 22:56:39 volumio bluealsa[1113]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_74_CA_B6_EA_71_C7, ...) Mar 28 22:56:44 volumio go-librespot[1938]: time="2026-03-28T22:56:44+02:00" level=trace msg="sent dealer ping" Mar 28 22:56:44 volumio go-librespot[1938]: time="2026-03-28T22:56:44+02:00" level=trace msg="received dealer pong" Mar 28 22:56:46 volumio bluealsa[1113]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_60_A9_37_5B_BE_34, ...) Mar 28 22:56:56 volumio volumio[1402]: info: CoreCommandRouter::volumioGetState Mar 28 22:56:56 volumio volumio[1402]: info: CorePlayQueue::getTrack 0 Mar 28 22:56:58 volumio volumio[1402]: info: Executing endpoint metavolumio Mar 28 22:56:58 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 22:56:58 volumio volumio[1402]: info: Executing endpoint metavolumio Mar 28 22:56:58 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 22:57:00 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 28 22:57:00 volumio volumio[1402]: info: CURURI: music-library Mar 28 22:57:00 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:57:01 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 28 22:57:01 volumio volumio[1402]: info: CURURI: music-library/NAS Mar 28 22:57:01 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:57:05 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 28 22:57:05 volumio volumio[1402]: info: CURURI: music-library/NAS/Media Mar 28 22:57:05 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:57:06 volumio volumio[1402]: error: Failed request for metavolumio API Mar 28 22:57:13 volumio volumio[1402]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 28 22:57:13 volumio volumio[1402]: info: CURURI: music-library/NAS/Media/JMJ Mar 28 22:57:13 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:57:14 volumio go-librespot[1938]: time="2026-03-28T22:57:14+02:00" level=trace msg="sent dealer ping" Mar 28 22:57:14 volumio go-librespot[1938]: time="2026-03-28T22:57:14+02:00" level=trace msg="received dealer pong" Mar 28 22:57:23 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:57:23 volumio volumio[1402]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 22:57:23 volumio volumio[1402]: info: CoreStateMachine::ClearQueue Mar 28 22:57:23 volumio volumio[1402]: info: CoreStateMachine::stop Mar 28 22:57:23 volumio volumio[1402]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 22:57:23 volumio volumio[1402]: info: CorePlayQueue::clearPlayQueue Mar 28 22:57:23 volumio volumio[1402]: info: CorePlayQueue::saveQueue Mar 28 22:57:23 volumio volumio[1402]: info: CoreCommandRouter::volumioPushQueue Mar 28 22:57:23 volumio volumio[1402]: info: CoreStateMachine::addQueueItems Mar 28 22:57:23 volumio volumio[1402]: info: CorePlayQueue::addQueueItems Mar 28 22:57:23 volumio volumio[1402]: info: Preload queue cleared Mar 28 22:57:23 volumio volumio[1402]: info: Adding Item to queue: music-library/NAS/Media/JMJ/1984 Zoolook Mar 28 22:57:23 volumio volumio[1402]: info: Exploding uri music-library/NAS/Media/JMJ/1984 Zoolook in service mpd Mar 28 22:57:23 volumio volumio[1402]: info: ALBUMART /albumart?cacheid=604&web=Jean%20Michel%20Jarre/Zoolook%20(Polydor%2C%20Disques%20Dreyfus%2C%2028MM%200413%2C%20Japan)/extralarge&path=%2Fmnt%2FNAS%2FMedia%2FJMJ%2F1984%20Zoolook%2FJean%20Michel%20Jarre%20-%20Zoolook.cue&metadata=false Mar 28 22:57:23 volumio volumio[1402]: info: URI /mnt/NAS/Media/JMJ/1984 Zoolook/Jean Michel Jarre - Zoolook.cue Mar 28 22:57:23 volumio volumio[1402]: info: ALBUMART /albumart?cacheid=604&web=Jean%20Michel%20Jarre/Zoolook%20(Polydor%2C%20Disques%20Dreyfus%2C%2028MM%200413%2C%20Japan)/extralarge&path=%2Fmnt%2FNAS%2FMedia%2FJMJ%2F1984%20Zoolook%2FJean%20Michel%20Jarre%20-%20Zoolook.cue&metadata=false Mar 28 22:57:23 volumio volumio[1402]: info: URI /mnt/NAS/Media/JMJ/1984 Zoolook/Jean Michel Jarre - Zoolook.cue Mar 28 22:57:23 volumio volumio[1402]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:57:23 volumio volumio[1402]: Error: Unable to resolve or reject the same promise twice Mar 28 22:57:23 volumio volumio[1402]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Mar 28 22:57:23 volumio volumio[1402]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Mar 28 22:57:23 volumio volumio[1402]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Mar 28 22:57:23 volumio volumio[1402]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Mar 28 22:57:23 volumio volumio[1402]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Mar 28 22:57:23 volumio volumio[1402]: at Socket.emit (node:events:514:28) Mar 28 22:57:23 volumio volumio[1402]: at addChunk (node:internal/streams/readable:343:12) Mar 28 22:57:23 volumio volumio[1402]: at readableAddChunk (node:internal/streams/readable:312:11) Mar 28 22:57:23 volumio volumio[1402]: at Readable.push (node:internal/streams/readable:253:10) Mar 28 22:57:23 volumio volumio[1402]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Mar 28 22:57:23 volumio volumio[1402]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:57:24 volumio sudo[5992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:56' Mar 28 22:57:24 volumio sudo[5992]: 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"