Aug 26 22:02:12 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 26 22:02:14 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 26 22:02:14 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 26 22:02:19 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:19.936+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.045+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=http://pushupdates.volumio.org duration=106.415469ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.073+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=136.584955ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.171+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://www.googleapis.com duration=233.422645ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.213+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=276.206424ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.230+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://securetoken.googleapis.com duration=291.944157ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.270+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=331.65472ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.287+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://google.com duration=349.532023ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.327+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=388.624624ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.396+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://functions.volumio.cloud duration=458.057229ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.398+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://functions.volumio.cloud duration=459.677171ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.428+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=http://cddb.volumio.org duration=490.643379ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.462+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=https://database.volumio.cloud duration=523.418842ms Aug 26 22:02:20 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:20.498+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:54308 @ 0x2d24c30" latency=528.371452ms timeout=10s endpoint=http://plugins.volumio.org duration=559.151948ms Aug 26 22:02:21 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 22:02:21 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 22:02:21 volumio volumio[1203]: info: Discovery: Getting this device information Aug 26 22:02:21 volumio volumio[1203]: info: CoreCommandRouter::volumioGetState Aug 26 22:02:21 volumio volumio[1203]: info: CorePlayQueue::getTrack 2 Aug 26 22:02:21 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 22:02:21 volumio volumio[1203]: verbose: New Socket.io Connection to 192.168.1.243:3000 from 192.168.1.187 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12 Aug 26 22:02:21 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 22:02:21 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 22:02:22 volumio volumio[1203]: verbose: New Socket.io Connection to 192.168.1.243 from 192.168.1.187 UA: Mozilla/5.0 (Linux; Android 14; CPH2385 Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.83 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::volumioGetState Aug 26 22:02:23 volumio volumio[1203]: info: CorePlayQueue::getTrack 2 Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::volumioGetQueue Aug 26 22:02:23 volumio volumio[1203]: info: CoreStateMachine::getQueue Aug 26 22:02:23 volumio volumio[1203]: info: CorePlayQueue::getQueue Aug 26 22:02:23 volumio volumio[1203]: info: Listing playlists Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 22:02:23 volumio volumio[1203]: info: Received Get System Info Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 22:02:23 volumio volumio[1203]: info: Discovery: Getting this device information Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::volumioGetState Aug 26 22:02:23 volumio volumio[1203]: info: CorePlayQueue::getTrack 2 Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::volumioGetState Aug 26 22:02:23 volumio volumio[1203]: info: CorePlayQueue::getTrack 2 Aug 26 22:02:23 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:24 volumio volumio[1203]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 22:02:42 volumio volumio[1203]: info: Preload queue cleared Aug 26 22:02:42 volumio volumio[1203]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::ClearQueue Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::stop Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::stPlaybackTimer Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::updateTrackBlock Aug 26 22:02:42 volumio volumio[1203]: info: CorePlayQueue::getTrackBlock Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::pushState Aug 26 22:02:42 volumio volumio[1203]: info: CorePlayQueue::getTrack 2 Aug 26 22:02:42 volumio volumio[1203]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 22:02:42 volumio volumio[1203]: info: CoreCommandRouter::volumioPushState Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::serviceStop Aug 26 22:02:42 volumio volumio[1203]: info: CorePlayQueue::getTrack 2 Aug 26 22:02:42 volumio volumio[1203]: info: CoreCommandRouter::serviceStop Aug 26 22:02:42 volumio volumio[1203]: info: ControllerMpd::stop Aug 26 22:02:42 volumio volumio[1203]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 22:02:42 volumio volumio[1203]: info: CorePlayQueue::clearPlayQueue Aug 26 22:02:42 volumio volumio[1203]: info: CorePlayQueue::saveQueue Aug 26 22:02:42 volumio volumio[1203]: info: CoreCommandRouter::volumioPushQueue Aug 26 22:02:42 volumio volumio[1203]: info: CoreStateMachine::addQueueItems Aug 26 22:02:42 volumio volumio[1203]: info: CorePlayQueue::addQueueItems Aug 26 22:02:42 volumio volumio[1203]: info: Preload queue cleared Aug 26 22:02:42 volumio volumio[1203]: info: Adding Item to queue: music-library/USB/Volumio_hdd_Dick/Debussy, Claude; Leonard Bernstein, Orchestra dell'Accademia Nazionale di Santa Cecilia - Images, La Mer & Prélude à l'Après-Midi d'un Faune Aug 26 22:02:42 volumio volumio[1203]: info: Exploding uri music-library/USB/Volumio_hdd_Dick/Debussy, Claude; Leonard Bernstein, Orchestra dell'Accademia Nazionale di Santa Cecilia - Images, La Mer & Prélude à l'Après-Midi d'un Faune in service mpd Aug 26 22:02:42 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:42.937+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.187:54308 @ 0x2d24c30" state=STATUS_STOPPED positionMs=0 volume=100 Aug 26 22:02:42 volumio volumio5-onboarding[1633]: time=2026-08-26T22:02:42.938+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.187:54308 @ 0x2d24c30" id="mnt/USB/Volumio_hdd_Dick/Copland, Aaron; John Wilson, BBC PO - Orchestral Works, Vol. 3 - Symphonies [24-96]/03. Symphony No. 1 II. Scherzo. Molto allegro.flac" title="Symphony No. 1: II. Scherzo. Molto allegro" Aug 26 22:02:42 volumio volumio[1203]: info: FusionDsp - Volumio is not playing Aug 26 22:02:42 volumio volumio[1203]: info: FusionDsp - Clipped samples monitor stopped Aug 26 22:02:42 volumio volumio[1203]: info: Aug 26 22:02:42 volumio volumio[1203]: ---------------------------- MPD announces state update: player Aug 26 22:02:42 volumio volumio[1203]: info: ALBUMART /albumart?cacheid=199&web=Orchestra%20dell'Accademia%20Nazionale%20di%20Santa%20Cecilia/Debussy%3A%20Images%2C%20Pr%C3%A9lude%20%C3%A0%20l'apr%C3%A8s-midi%20d'un%20faune%2C%20La%20Mer/extralarge&path=%2Fmnt%2FUSB%2FVolumio_hdd_Dick%2FDebussy%2C%20Claude%3B%20Leonard%20Bernstein%2C%20Orchestra%20dell'Accademia%20Nazionale%20di%20Santa%20Cecilia%20-%20Images%2C%20La%20Mer%20%26%20Pr%C3%A9lude%20%C3%A0%20l'Apr%C3%A8s-Midi%20d'un%20Faune%2F%2BAdd%20cue%20CD%2044%20(correct).cue&metadata=false Aug 26 22:02:42 volumio volumio[1203]: info: URI /mnt/USB/Volumio_hdd_Dick/Debussy, Claude; Leonard Bernstein, Orchestra dell'Accademia Nazionale di Santa Cecilia - Images, La Mer & Prélude à l'Après-Midi d'un Faune/+Add cue CD 44 (correct).cue Aug 26 22:02:42 volumio volumio[1203]: info: ALBUMART /albumart?cacheid=199&web=Orchestra%20dell'Accademia%20Nazionale%20di%20Santa%20Cecilia/Debussy%3A%20Images%2C%20Pr%C3%A9lude%20%C3%A0%20l'apr%C3%A8s-midi%20d'un%20faune%2C%20La%20Mer/extralarge&path=%2Fmnt%2FUSB%2FVolumio_hdd_Dick%2FDebussy%2C%20Claude%3B%20Leonard%20Bernstein%2C%20Orchestra%20dell'Accademia%20Nazionale%20di%20Santa%20Cecilia%20-%20Images%2C%20La%20Mer%20%26%20Pr%C3%A9lude%20%C3%A0%20l'Apr%C3%A8s-Midi%20d'un%20Faune%2F%2BAdd%20cue%20CD%2044%20(correct).cue&metadata=false Aug 26 22:02:42 volumio volumio[1203]: info: URI /mnt/USB/Volumio_hdd_Dick/Debussy, Claude; Leonard Bernstein, Orchestra dell'Accademia Nazionale di Santa Cecilia - Images, La Mer & Prélude à l'Après-Midi d'un Faune/+Add cue CD 44 (correct).cue Aug 26 22:02:43 volumio volumio[1203]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:02:43 volumio volumio[1203]: Error: Unable to resolve or reject the same promise twice Aug 26 22:02:43 volumio volumio[1203]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Aug 26 22:02:43 volumio volumio[1203]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Aug 26 22:02:43 volumio volumio[1203]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Aug 26 22:02:43 volumio volumio[1203]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Aug 26 22:02:43 volumio volumio[1203]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Aug 26 22:02:43 volumio volumio[1203]: at Socket.emit (node:events:514:28) Aug 26 22:02:43 volumio volumio[1203]: at addChunk (node:internal/streams/readable:343:12) Aug 26 22:02:43 volumio volumio[1203]: at readableAddChunk (node:internal/streams/readable:312:11) Aug 26 22:02:43 volumio volumio[1203]: at Readable.push (node:internal/streams/readable:253:10) Aug 26 22:02:43 volumio volumio[1203]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Aug 26 22:02:43 volumio volumio[1203]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 22:02:43 volumio kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 4 ep 1 Aug 26 22:02:43 volumio kernel: xhci_hcd 0000:01:00.0: @000000040cd048c0 00000000 00000000 0e000000 04028001 Aug 26 22:02:43 volumio volumio[19663]: ERROR:aiohttp.server:Error handling request from 192.168.1.10 Aug 26 22:02:43 volumio volumio[19663]: Traceback (most recent call last): Aug 26 22:02:43 volumio volumio[19663]: File "aiohttp/web_protocol.py", line 517, in _handle_request Aug 26 22:02:43 volumio volumio[19663]: File "aiohttp/web_app.py", line 569, in _handle Aug 26 22:02:43 volumio volumio[19663]: File "backend/views.py", line 201, in get_param_json Aug 26 22:02:43 volumio volumio[19663]: File "camilladsp/volume.py", line 28, in all Aug 26 22:02:43 volumio volumio[19663]: File "camilladsp/camillaws.py", line 50, in query Aug 26 22:02:43 volumio volumio[19663]: OSError: Not connected to CamillaDSP Aug 26 22:02:44 volumio sudo[24843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 22:01' Aug 26 22:02:44 volumio sudo[24843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 22:02:44 volumio volumio[19663]: ERROR:aiohttp.server:Error handling request from 192.168.1.10 Aug 26 22:02:44 volumio volumio[19663]: Traceback (most recent call last): Aug 26 22:02:44 volumio volumio[19663]: File "aiohttp/web_protocol.py", line 517, in _handle_request Aug 26 22:02:44 volumio volumio[19663]: File "aiohttp/web_app.py", line 569, in _handle Aug 26 22:02:44 volumio volumio[19663]: File "backend/views.py", line 201, in get_param_json Aug 26 22:02:44 volumio volumio[19663]: File "camilladsp/volume.py", line 28, in all Aug 26 22:02:44 volumio volumio[19663]: File "camilladsp/camillaws.py", line 50, in query Aug 26 22:02:44 volumio volumio[19663]: OSError: Not connected to CamillaDSP 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"