Aug 31 19:35:25 volumio volumio5-onboarding[1682]: time=2026-08-31T19:35:25.783+05:30 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Aug 31 19:35:30 volumio volumio5-onboarding[1682]: time=2026-08-31T19:35:30.875+05:30 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 Aug 31 19:35:32 volumio dbus-daemon[776]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.18" (uid=0 pid=1682 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=855 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 31 19:35:43 volumio bluealsa[1016]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6F_C9_F9_4D_7B_14, ...) Aug 31 19:36:02 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 31 19:36:02 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 19:36:02 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 19:36:03 volumio bluealsa[1016]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5C_01_8E_F5_23_72, ...) Aug 31 19:36:22 volumio bluealsa[1016]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_6F_C9_F9_4D_7B_14, ...) Aug 31 19:36:33 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:33.923+05:30 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.046+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=123.381738ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.439+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://www.googleapis.com duration=513.98083ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.613+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=687.894295ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.743+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=http://pushupdates.volumio.org duration=818.086721ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.746+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=823.307924ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.754+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://securetoken.googleapis.com duration=829.123586ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.761+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://google.com duration=836.89843ms Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.934+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=1.00887149s Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.989+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://functions.volumio.cloud duration=1.062984513s Aug 31 19:36:34 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:34.989+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://functions.volumio.cloud duration=1.063268602s Aug 31 19:36:35 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:35.265+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=https://database.volumio.cloud duration=1.339864505s Aug 31 19:36:35 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:35.651+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=http://plugins.volumio.org duration=1.726202958s Aug 31 19:36:35 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:35.759+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-58.593146ms timeout=10s endpoint=http://cddb.volumio.org duration=1.833639493s Aug 31 19:36:35 volumio volumio[1224]: info: CoreCommandRouter::volumioRemoveQueueItem Aug 31 19:36:35 volumio volumio[1224]: info: CoreStateMachine::removeQueueItem Aug 31 19:36:35 volumio volumio[1224]: info: CoreStateMachine::stop Aug 31 19:36:35 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 19:36:35 volumio volumio[1224]: info: CorePlayQueue::removeQueueItem 0 Aug 31 19:36:35 volumio volumio[1224]: info: CorePlayQueue::saveQueue Aug 31 19:36:35 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Aug 31 19:36:36 volumio bluealsa[1016]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6C_21_40_20_31_F6, ...) Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.735+05:30 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.4:52750 @ 0x273bc80" latency=-60.426545ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.751+05:30 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.769+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=17.68674ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.859+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://www.googleapis.com duration=107.151058ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.880+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=http://pushupdates.volumio.org duration=128.168929ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.886+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=134.097219ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.899+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://google.com duration=147.864111ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.900+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=148.710509ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.991+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://functions.volumio.cloud duration=239.309648ms Aug 31 19:36:38 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:38.993+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://functions.volumio.cloud duration=241.573329ms Aug 31 19:36:39 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:39.010+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://database.volumio.cloud duration=258.378208ms Aug 31 19:36:39 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:39.023+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=271.808585ms Aug 31 19:36:39 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:39.037+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=https://securetoken.googleapis.com duration=285.99262ms Aug 31 19:36:39 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:39.299+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=http://plugins.volumio.org duration=547.591554ms Aug 31 19:36:39 volumio sudo[3989]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 19:36:39 volumio sudo[3989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 19:36:39 volumio sudo[3989]: pam_unix(sudo:session): session closed for user root Aug 31 19:36:39 volumio sudo[3991]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 19:36:39 volumio sudo[3991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 19:36:39 volumio sudo[3991]: pam_unix(sudo:session): session closed for user root Aug 31 19:36:39 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:39.521+05:30 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Aug 31 19:36:39 volumio volumio[1224]: verbose: New Socket.io Connection to 192.168.1.8 from 192.168.1.4 UA: Mozilla/5.0 (Linux; Android 17; Pixel 8 Build/CP2A.260805.005; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 31 19:36:39 volumio dbus-daemon[776]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.18" (uid=0 pid=1682 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=855 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 31 19:36:39 volumio sudo[3995]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 19:36:39 volumio sudo[3995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 19:36:39 volumio sudo[3995]: pam_unix(sudo:session): session closed for user root Aug 31 19:36:39 volumio sudo[3997]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 19:36:39 volumio sudo[3997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 19:36:39 volumio sudo[3997]: pam_unix(sudo:session): session closed for user root Aug 31 19:36:39 volumio volumio[1224]: verbose: New Socket.io Connection to 192.168.1.8 from 192.168.1.4 UA: Mozilla/5.0 (Linux; Android 17; Pixel 8 Build/CP2A.260805.005; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Aug 31 19:36:39 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 31 19:36:39 volumio volumio[1224]: info: Received Get System Info Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 19:36:39 volumio volumio[1224]: info: Discovery: Getting this device information Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Aug 31 19:36:39 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Aug 31 19:36:39 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Aug 31 19:36:39 volumio volumio[1224]: info: Listing playlists Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 19:36:39 volumio volumio[1224]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 19:36:40 volumio volumio5-onboarding[1682]: time=2026-08-31T19:36:40.093+05:30 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:52750 @ 0x273bc80" latency=-65.857716ms timeout=10s endpoint=http://cddb.volumio.org duration=1.341879828s Aug 31 19:36:40 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 19:36:41 volumio volumio[1224]: info: Received Get System Info Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 19:36:41 volumio volumio[1224]: info: Discovery: Getting this device information Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Aug 31 19:36:41 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 19:36:41 volumio volumio[1224]: info: CoreCommandRouter::volumioGetQueue Aug 31 19:36:41 volumio volumio[1224]: info: CoreStateMachine::getQueue Aug 31 19:36:41 volumio volumio[1224]: info: CorePlayQueue::getQueue Aug 31 19:36:43 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 19:36:43 volumio volumio[1224]: info: Received Get System Info Aug 31 19:36:43 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 19:36:43 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 19:36:43 volumio volumio[1224]: info: Discovery: Getting this device information Aug 31 19:36:43 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Aug 31 19:36:43 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Aug 31 19:36:43 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 19:36:46 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 19:36:46 volumio volumio[1224]: info: CURURI: music-library Aug 31 19:36:46 volumio volumio[1224]: info: Preload queue cleared Aug 31 19:36:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 19:36:47 volumio volumio[1224]: info: CURURI: music-library/USB Aug 31 19:36:47 volumio volumio[1224]: info: Preload queue cleared Aug 31 19:36:48 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 19:36:48 volumio volumio[1224]: info: CURURI: music-library/USB/Music_Lib Aug 31 19:36:48 volumio volumio[1224]: info: Preload queue cleared Aug 31 19:36:49 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 19:36:49 volumio volumio[1224]: info: CURURI: music-library/USB/Music_Lib/Flac Aug 31 19:36:49 volumio volumio[1224]: info: Preload queue cleared Aug 31 19:36:49 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 19:36:58 volumio volumio[1224]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 31 19:36:58 volumio volumio[1224]: info: Received Get System Version Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 19:36:58 volumio volumio[1224]: info: Received Get System Info Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 19:36:58 volumio volumio[1224]: info: Discovery: Getting this device information Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Aug 31 19:36:58 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 19:36:58 volumio volumio[1224]: info: CoreCommandRouter::volumioAddQueueItems Aug 31 19:36:58 volumio volumio[1224]: info: CoreStateMachine::addQueueItems Aug 31 19:36:58 volumio volumio[1224]: info: CorePlayQueue::addQueueItems Aug 31 19:36:58 volumio volumio[1224]: info: Preload queue cleared Aug 31 19:36:58 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac] Aug 31 19:36:58 volumio volumio[1224]: info: Exploding uri music-library/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac] in service mpd Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Florence%20And%20The%20Machine/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F01%20Florence%20And%20The%20Machine%20-%20Spectrum%20Say%20My%20Name%20%5BCalvin%20Harris%20Remix%20Radio%20Edit%5D.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/01 Florence And The Machine - Spectrum Say My Name [Calvin Harris Remix Radio Edit].flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Roll%20Deep/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F02%20Roll%20Deep%20-%20Good%20Times.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/02 Roll Deep - Good Times.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=The%20Black%20Eyed%20Peas/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F03%20The%20Black%20Eyed%20Peas%20-%20I%20Gotta%20Feeling.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/03 The Black Eyed Peas - I Gotta Feeling.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Pixie%20Lott/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F04%20Pixie%20Lott%20-%20Boys%20And%20Girls.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/04 Pixie Lott - Boys And Girls.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Duffy/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F05%20Duffy%20-%20Mercy.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/05 Duffy - Mercy.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=The%20Pussycat%20Dolls/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F06%20The%20Pussycat%20Dolls%20-%20Don't%20Cha.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/06 The Pussycat Dolls - Don't Cha.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Scissor%20Sisters/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F07%20Scissor%20Sisters%20-%20I%20Don't%20Feel%20Like%20Dancing.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/07 Scissor Sisters - I Don't Feel Like Dancing.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Kleerup%20-%20Robyn/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F08%20Kleerup%20-%20Robyn%20-%20Every%20Heartbeat.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/08 Kleerup - Robyn - Every Heartbeat.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Cheryl%20Cole/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F09%20Cheryl%20Cole%20-%20Fight%20For%20This%20Love.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/09 Cheryl Cole - Fight For This Love.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=John%20Newman/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F10%20John%20Newman%20-%20Love%20Me%20Again.flac&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/10 John Newman - Love Me Again.flac Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Florence%20And%20The%20Machine/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F101%20Number%201%20Hits%20%5BCD-1%5D.cue&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/101 Number 1 Hits [CD-1].cue Aug 31 19:36:58 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=107&web=Roll%20Deep/101%20Number%201%20Hits%20%5BCD-1%5D/extralarge&path=%2Fmnt%2FUSB%2FMusic_Lib%2FFlac%2F101%20Number%201%20Hits%20-%20101%20Hits%20On%205%20CDs%202017%20%5BFlac%5D%2F101%20Number%201%20Hits%20On%205%20CDs%2F101%20Number%201%20Hits%20%5BCD-1%5D%2F101%20Number%201%20Hits%20%5BCD-1%5D.cue&metadata=false Aug 31 19:36:58 volumio volumio[1224]: info: URI /mnt/USB/Music_Lib/Flac/101 Number 1 Hits - 101 Hits On 5 CDs 2017 [Flac]/101 Number 1 Hits On 5 CDs/101 Number 1 Hits [CD-1]/101 Number 1 Hits [CD-1].cue Aug 31 19:36:58 volumio volumio[1224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 19:36:58 volumio volumio[1224]: Error: Unable to resolve or reject the same promise twice Aug 31 19:36:58 volumio volumio[1224]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Aug 31 19:36:58 volumio volumio[1224]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Aug 31 19:36:58 volumio volumio[1224]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Aug 31 19:36:58 volumio volumio[1224]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Aug 31 19:36:58 volumio volumio[1224]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Aug 31 19:36:58 volumio volumio[1224]: at Socket.emit (node:events:514:28) Aug 31 19:36:58 volumio volumio[1224]: at addChunk (node:internal/streams/readable:343:12) Aug 31 19:36:58 volumio volumio[1224]: at readableAddChunk (node:internal/streams/readable:312:11) Aug 31 19:36:58 volumio volumio[1224]: at Readable.push (node:internal/streams/readable:253:10) Aug 31 19:36:58 volumio volumio[1224]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Aug 31 19:36:58 volumio volumio[1224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 19:36:58 volumio sudo[4056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 19:35' Aug 31 19:36:58 volumio sudo[4056]: 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"