-- Logs begin at Sun 2025-06-22 23:26:17 EEST, end at Wed 2025-06-25 19:16:23 EEST. -- Jun 25 19:15:01 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:01 volumio volumio[1152]: info: CURURI: music-library Jun 25 19:15:01 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:02 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 25 19:15:02 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:02 volumio volumio[1152]: info: CURURI: music-library/USB Jun 25 19:15:02 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:04 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:04 volumio volumio[1152]: info: CURURI: music-library/USB/My_Book Jun 25 19:15:04 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:07 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:15:14 volumio volumio-remote-updater[643]: [2025-06-25 19:15:14] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Jun 25 19:15:18 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:15:19 volumio volumio-remote-updater[643]: [2025-06-25 19:15:19] [connect] Successful connection Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:22 volumio volumio[1152]: info: CURURI: music-library/USB/My_Book/Music Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 25 19:15:22 volumio volumio[1152]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 25 19:15:22 volumio volumio[1152]: info: Received Get System Version Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 25 19:15:22 volumio volumio[1152]: info: Received Get System Info Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 25 19:15:22 volumio volumio[1152]: info: Discovery: Getting this device information Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:22 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 25 19:15:22 volumio volumio-remote-updater[643]: [2025-06-25 19:15:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1750868119 101 Jun 25 19:15:22 volumio volumio[1152]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Jun 25 19:15:22 volumio volumio[1152]: verbose: New Socket.io Connection to 192.168.2.10 from 192.168.2.5 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:139.0) Gecko/20100101 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 4 Jun 25 19:15:23 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 25 19:15:23 volumio volumio[1152]: verbose: New Socket.io Connection to 192.168.2.10 from 192.168.2.4 UA: Mozilla/5.0 (Android 10; Mobile; rv:139.0) Gecko/139.0 Firefox/139.0 Engine version: 3 Transport: polling Total Clients: 5 Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetVisibleSources Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 25 19:15:23 volumio volumio[1152]: info: Received Get System Info Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 25 19:15:23 volumio volumio[1152]: info: Discovery: Getting this device information Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: Listing playlists Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetVisibleSources Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 25 19:15:23 volumio volumio[1152]: info: Received Get System Info Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 25 19:15:23 volumio volumio[1152]: info: Discovery: Getting this device information Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:23 volumio volumio[1152]: info: Listing playlists Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::volumioGetQueue Jun 25 19:15:23 volumio volumio[1152]: info: CoreStateMachine::getQueue Jun 25 19:15:23 volumio volumio[1152]: info: CorePlayQueue::getQueue Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 25 19:15:23 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 25 19:15:24 volumio volumio[1152]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 25 19:15:24 volumio volumio[1152]: info: CoreCommandRouter::volumioGetState Jun 25 19:15:24 volumio volumio[1152]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 25 19:15:27 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:27 volumio volumio[1152]: info: CURURI: music-library/USB/My_Book/Music Jun 25 19:15:27 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:29 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:15:29 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:29 volumio volumio[1152]: info: CURURI: music-library/USB/My_Book/Music/DSD Jun 25 19:15:29 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:35 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:35 volumio volumio[1152]: info: CURURI: music-library/USB/My_Book/Music/FLAC Jun 25 19:15:35 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:37 volumio volumio[1152]: info: VolumeController::SetAlsaVolume+ Jun 25 19:15:37 volumio volumio[1152]: info: CoreStateMachine::pushState Jun 25 19:15:37 volumio volumio[1152]: info: CoreCommandRouter::volumioPushState Jun 25 19:15:38 volumio volumio[1152]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 25 19:15:38 volumio volumio[1152]: info: VolumeController::SetAlsaVolume+ Jun 25 19:15:38 volumio volumio[1152]: info: CoreStateMachine::pushState Jun 25 19:15:38 volumio volumio[1152]: info: CoreCommandRouter::volumioPushState Jun 25 19:15:38 volumio volumio[1152]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 25 19:15:40 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:15:51 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:15:57 volumio volumio[1152]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jun 25 19:15:57 volumio volumio[1152]: info: CURURI: music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac] Jun 25 19:15:57 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:15:57 volumio volumio[1152]: info: Preloading song: music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/01-narcotango-narcotango-csa.flac Jun 25 19:15:57 volumio volumio[1152]: info: Preloading song: music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/00-narcotango-narcotango_(carlos_libedinsky)-2002-csa.m3u Jun 25 19:15:57 volumio volumio[1152]: info: Exploding uri music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/01-narcotango-narcotango-csa.flac in service mpd Jun 25 19:15:57 volumio volumio[1152]: info: ALBUMART /albumart?cacheid=715&web=narcotango/narcotango/extralarge&path=%2Fmnt%2FUSB%2FMy_Book%2FMusic%2FFLAC%2FCarlos%20Libedinsky%20-%20Narcotango%20%5Bflac%5D%2F01-narcotango-narcotango-csa.flac&metadata=false Jun 25 19:15:57 volumio volumio[1152]: info: URI /mnt/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/01-narcotango-narcotango-csa.flac Jun 25 19:15:57 volumio volumio[1152]: info: Exploding uri music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/00-narcotango-narcotango_(carlos_libedinsky)-2002-csa.m3u in service mpd Jun 25 19:16:02 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:16:13 volumio wpa_supplicant[887]: wlan0: Failed to initiate sched scan Jun 25 19:16:23 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:16:23 volumio volumio[1152]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 25 19:16:23 volumio volumio[1152]: info: CoreStateMachine::ClearQueue Jun 25 19:16:23 volumio volumio[1152]: info: CoreStateMachine::stop Jun 25 19:16:23 volumio volumio[1152]: info: CoreStateMachine::serviceStop Jun 25 19:16:23 volumio volumio[1152]: info: CoreCommandRouter::serviceStop Jun 25 19:16:23 volumio volumio[1152]: info: Spotify Stop Jun 25 19:16:23 volumio volumio[1152]: SPOTIFY: SPOTIFY STOP Jun 25 19:16:23 volumio volumio[1152]: SPOTIFY: {"status":"pause","title":"It's Too Late","artist":"Carole King","album":"Tapestry","albumart":"https://i.scdn.co/image/ab67616d00001e0223350feac07f56d8b96f33d5","uri":"spotify:track:12q3V8ShACq2PSWINMc2rC","trackType":"spotify","codec":"ogg","seek":153000,"duration":233,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Jun 25 19:16:23 volumio volumio[1152]: info: Sending Spotify command to local API: /player/pause Jun 25 19:16:23 volumio volumio[1152]: info: CorePlayQueue::clearPlayQueue Jun 25 19:16:23 volumio volumio[1152]: info: CorePlayQueue::saveQueue Jun 25 19:16:23 volumio volumio[1152]: info: CoreCommandRouter::volumioPushQueue Jun 25 19:16:23 volumio volumio[1152]: info: CoreStateMachine::addQueueItems Jun 25 19:16:23 volumio volumio[1152]: info: CorePlayQueue::addQueueItems Jun 25 19:16:23 volumio volumio[1152]: info: Preload queue cleared Jun 25 19:16:23 volumio volumio[1152]: info: Adding Item to queue: music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac] Jun 25 19:16:23 volumio volumio[1152]: info: Exploding uri music-library/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac] in service mpd Jun 25 19:16:23 volumio volumio[1152]: info: ALBUMART /albumart?cacheid=715&web=Narcotango/Narcotango%20(Carlos%20Libedinsky)/extralarge&path=%2Fmnt%2FUSB%2FMy_Book%2FMusic%2FFLAC%2FCarlos%20Libedinsky%20-%20Narcotango%20%5Bflac%5D%2F01-narcotango-narcotango-csa.cue&metadata=false Jun 25 19:16:23 volumio volumio[1152]: info: URI /mnt/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/01-narcotango-narcotango-csa.cue Jun 25 19:16:23 volumio volumio[1152]: info: ALBUMART /albumart?cacheid=715&web=Narcotango/Narcotango%20(Carlos%20Libedinsky)/extralarge&path=%2Fmnt%2FUSB%2FMy_Book%2FMusic%2FFLAC%2FCarlos%20Libedinsky%20-%20Narcotango%20%5Bflac%5D%2F01-narcotango-narcotango-csa.cue&metadata=false Jun 25 19:16:23 volumio volumio[1152]: info: URI /mnt/USB/My_Book/Music/FLAC/Carlos Libedinsky - Narcotango [flac]/01-narcotango-narcotango-csa.cue Jun 25 19:16:23 volumio volumio[1152]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 25 19:16:23 volumio volumio[1152]: Error: Unable to resolve or reject the same promise twice Jun 25 19:16:23 volumio volumio[1152]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jun 25 19:16:23 volumio volumio[1152]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 Jun 25 19:16:23 volumio volumio[1152]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Jun 25 19:16:23 volumio volumio[1152]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Jun 25 19:16:23 volumio volumio[1152]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Jun 25 19:16:23 volumio volumio[1152]: at Socket.emit (events.js:315:20) Jun 25 19:16:23 volumio volumio[1152]: at addChunk (internal/streams/readable.js:309:12) Jun 25 19:16:23 volumio volumio[1152]: at readableAddChunk (internal/streams/readable.js:280:11) Jun 25 19:16:23 volumio volumio[1152]: at Socket.Readable.push (internal/streams/readable.js:223:10) Jun 25 19:16:23 volumio volumio[1152]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Jun 25 19:16:23 volumio volumio[1152]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 25 19:16:23 volumio sudo[7062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-25 19:15 Jun 25 19:16:23 volumio sudo[7062]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"