Mar 26 15:17:02 volumioluigi volumio[1335]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Mar 26 15:17:02 volumioluigi volumio[1335]: error: MyVolumio Plugin failed to authenticate in a timely fashion Mar 26 15:17:02 volumioluigi volumio[1335]: info: Completed starting MyVolumio Plugin Mar 26 15:17:02 volumioluigi volumio[1335]: [Metrics] CommandRouter: 153s 668.24ms Mar 26 15:17:02 volumioluigi volumio[1335]: info: CoreCommandRouter::volumiosetStartupVolume Mar 26 15:17:02 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:17:02 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:02 volumioluigi volumio[1335]: info: CoreCommandRouter::Close All Modals sent Mar 26 15:17:03 volumioluigi volumio[1335]: info: CoreCommandRouter::Close All Modals sent Mar 26 15:17:04 volumioluigi volumio[1335]: info: Setting Geolocation for MyVolumio to eu6 Mar 26 15:17:04 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:04 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:04 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:04 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 26 15:17:04 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 15:17:04 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 26 15:17:05 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 15:17:05 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 15:17:05 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:05 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:05 volumioluigi volumio[1335]: info: Updating MyVolumio device info Mar 26 15:17:05 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:05 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:05 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:17:05 volumioluigi volumio[1335]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 26 15:17:06 volumioluigi volumio[1335]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 26 15:17:10 volumioluigi volumio[1335]: info: BOOT COMPLETED Mar 26 15:17:10 volumioluigi volumio5-onboarding[2168]: time=2026-03-26T15:17:10.305+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4d6EOHJWBUOnPGV6ISWYFaHGoac2 tokenExpiry=2026-03-26T16:17:10.305+01:00 Mar 26 15:17:13 volumioluigi volumio[1335]: info: Received Get System Info Mar 26 15:17:13 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:17:13 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:17:13 volumioluigi volumio[1335]: info: Discovery: Getting this device information Mar 26 15:17:13 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:13 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:13 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:17:13 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 15:17:13 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 15:17:13 volumioluigi volumio5-onboarding[2168]: time=2026-03-26T15:17:13.323+01:00 level=INFO msg="enabling local network discovery" Mar 26 15:17:13 volumioluigi volumio5-onboarding[2168]: time=2026-03-26T15:17:13.484+01:00 level=INFO msg="enabling BLE discovery" Mar 26 15:17:13 volumioluigi volumio[1335]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Mar 26 15:17:14 volumioluigi volumio5-onboarding[2168]: time=2026-03-26T15:17:14.546+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 26 15:17:18 volumioluigi upmpdcli[2303]: writing RSA key Mar 26 15:17:28 volumioluigi volumio[1335]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Mar 26 15:17:31 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetVisibleSources Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:32 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 26 15:17:32 volumioluigi volumio[1335]: info: Received Get System Info Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:17:32 volumioluigi volumio[1335]: info: Discovery: Getting this device information Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:32 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:32 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:32 volumioluigi volumio[1335]: info: Listing playlists Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 15:17:32 volumioluigi volumio[1335]: info: Received Get System Info Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:17:32 volumioluigi volumio[1335]: info: Discovery: Getting this device information Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:32 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:32 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:17:33 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 26 15:17:34 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 15:17:35 volumioluigi volumio[1335]: info: Received Get System Info Mar 26 15:17:35 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:17:35 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:17:35 volumioluigi volumio[1335]: info: Discovery: Getting this device information Mar 26 15:17:35 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:35 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:35 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:17:35 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 26 15:17:38 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 26 15:17:40 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 15:17:40 volumioluigi volumio[1335]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 26 15:17:40 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 26 15:17:40 volumioluigi volumio[1335]: info: Received Get System Version Mar 26 15:17:41 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 15:17:41 volumioluigi volumio[1335]: info: Received Get System Info Mar 26 15:17:41 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:17:41 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:17:41 volumioluigi volumio[1335]: info: Discovery: Getting this device information Mar 26 15:17:41 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioGetState Mar 26 15:17:41 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:17:41 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:18:09 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioPlay Mar 26 15:18:09 volumioluigi volumio[1335]: info: CoreStateMachine::play index undefined Mar 26 15:18:09 volumioluigi volumio[1335]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 15:18:09 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:18:14 volumioluigi volumio[1335]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 26 15:18:15 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioNext Mar 26 15:18:15 volumioluigi volumio[1335]: info: CoreStateMachine::next Mar 26 15:18:15 volumioluigi volumio[1335]: info: CoreStateMachine::stop Mar 26 15:18:15 volumioluigi volumio[1335]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 15:18:15 volumioluigi volumio[1335]: info: CoreStateMachine::play index undefined Mar 26 15:18:15 volumioluigi volumio[1335]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 15:18:15 volumioluigi volumio[1335]: info: CorePlayQueue::getTrack 0 Mar 26 15:18:21 volumioluigi volumio[1335]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 26 15:18:25 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 15:18:25 volumioluigi volumio[1335]: info: CURURI: music-library Mar 26 15:18:25 volumioluigi volumio[1335]: info: Preload queue cleared Mar 26 15:18:26 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 15:18:26 volumioluigi volumio[1335]: info: CURURI: music-library/USB Mar 26 15:18:27 volumioluigi volumio[1335]: info: Preload queue cleared Mar 26 15:18:28 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 15:18:28 volumioluigi volumio[1335]: info: CURURI: music-library/USB/Nuovo_1TB_Fumetti Mar 26 15:18:28 volumioluigi volumio[1335]: info: Preload queue cleared Mar 26 15:18:30 volumioluigi volumio[1335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 15:18:30 volumioluigi volumio[1335]: info: CURURI: music-library/USB/Nuovo_1TB_Fumetti/Cream - Discography Mar 26 15:18:30 volumioluigi volumio[1335]: info: Preload queue cleared Mar 26 15:18:32 volumioluigi volumio[1335]: info: Preload queue cleared Mar 26 15:18:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 26 15:18:32 volumioluigi volumio[1335]: info: CoreStateMachine::ClearQueue Mar 26 15:18:32 volumioluigi volumio[1335]: info: CoreStateMachine::stop Mar 26 15:18:32 volumioluigi volumio[1335]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 15:18:32 volumioluigi volumio[1335]: info: CorePlayQueue::clearPlayQueue Mar 26 15:18:32 volumioluigi volumio[1335]: info: CorePlayQueue::saveQueue Mar 26 15:18:32 volumioluigi volumio[1335]: info: CoreCommandRouter::volumioPushQueue Mar 26 15:18:32 volumioluigi volumio[1335]: info: CoreStateMachine::addQueueItems Mar 26 15:18:32 volumioluigi volumio[1335]: info: CorePlayQueue::addQueueItems Mar 26 15:18:32 volumioluigi volumio[1335]: info: Preload queue cleared Mar 26 15:18:32 volumioluigi volumio[1335]: info: Adding Item to queue: music-library/USB/Nuovo_1TB_Fumetti/Cream - Discography/1967 - Disraeli Gears Mar 26 15:18:32 volumioluigi volumio[1335]: info: Exploding uri music-library/USB/Nuovo_1TB_Fumetti/Cream - Discography/1967 - Disraeli Gears in service mpd Mar 26 15:18:32 volumioluigi volumio[1335]: info: ALBUMART /albumart?cacheid=681&web=Cream/Disraeli%20Gears/extralarge&path=%2Fmnt%2FUSB%2FNuovo_1TB_Fumetti%2FCream%20-%20Discography%2F1967%20-%20Disraeli%20Gears%2FCream%20-%20Disraeli%20Gears.cue&metadata=false Mar 26 15:18:32 volumioluigi volumio[1335]: info: URI /mnt/USB/Nuovo_1TB_Fumetti/Cream - Discography/1967 - Disraeli Gears/Cream - Disraeli Gears.cue Mar 26 15:18:32 volumioluigi volumio[1335]: info: ALBUMART /albumart?cacheid=681&web=Cream/Disraeli%20Gears/extralarge&path=%2Fmnt%2FUSB%2FNuovo_1TB_Fumetti%2FCream%20-%20Discography%2F1967%20-%20Disraeli%20Gears%2FCream%20-%20Disraeli%20Gears.cue&metadata=false Mar 26 15:18:32 volumioluigi volumio[1335]: info: URI /mnt/USB/Nuovo_1TB_Fumetti/Cream - Discography/1967 - Disraeli Gears/Cream - Disraeli Gears.cue Mar 26 15:18:32 volumioluigi volumio[1335]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 15:18:32 volumioluigi volumio[1335]: Error: Unable to resolve or reject the same promise twice Mar 26 15:18:32 volumioluigi volumio[1335]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Mar 26 15:18:32 volumioluigi volumio[1335]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Mar 26 15:18:32 volumioluigi volumio[1335]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Mar 26 15:18:32 volumioluigi volumio[1335]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Mar 26 15:18:32 volumioluigi volumio[1335]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Mar 26 15:18:32 volumioluigi volumio[1335]: at Socket.emit (node:events:514:28) Mar 26 15:18:32 volumioluigi volumio[1335]: at addChunk (node:internal/streams/readable:343:12) Mar 26 15:18:32 volumioluigi volumio[1335]: at readableAddChunk (node:internal/streams/readable:312:11) Mar 26 15:18:32 volumioluigi volumio[1335]: at Readable.push (node:internal/streams/readable:253:10) Mar 26 15:18:32 volumioluigi volumio[1335]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Mar 26 15:18:32 volumioluigi volumio[1335]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 15:18:38 volumioluigi sudo[2464]: volumio : unable to resolve host volumioluigi: System error Mar 26 15:18:38 volumioluigi sudo[2464]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 15:17' Mar 26 15:18:38 volumioluigi sudo[2464]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"