May 28 14:47:06 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 14:47:06 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 14:47:06 volumio volumio[1077]: info: Discovery: Getting this device information May 28 14:47:06 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState May 28 14:47:06 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 May 28 14:47:06 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 14:47:25 volumio go-librespot[1403]: time="2025-05-28T14:47:25+09:00" level=trace msg="sent dealer ping" May 28 14:47:25 volumio go-librespot[1403]: time="2025-05-28T14:47:25+09:00" level=trace msg="received dealer pong" May 28 14:47:35 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 14:47:35 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 14:47:35 volumio volumio[1077]: info: Discovery: Getting this device information May 28 14:47:35 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState May 28 14:47:35 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 May 28 14:47:35 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 14:47:36 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 28 14:47:36 volumio dbus-daemon[563]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.34' (uid=0 pid=2545 comm="timedatectl show --property=NTPSynchronized --valu") May 28 14:47:36 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 28 14:47:36 volumio dbus-daemon[563]: [system] Successfully activated service 'org.freedesktop.timedate1' May 28 14:47:36 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 28 14:47:36 volumio setdatetime-helper.sh[2544]: Time is not synchronized. Attempting to sync... May 28 14:47:36 volumio sudo[2555]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Wed, 28 May 2025 05:47:37 GMT#015' May 28 14:47:36 volumio sudo[2555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 14:47:37 volumio setdatetime-helper.sh[2556]: Wed May 28 14:47:37 JST 2025 May 28 14:47:37 volumio sudo[2555]: pam_unix(sudo:session): session closed for user root May 28 14:47:37 volumio setdatetime-helper.sh[2544]: Time synchronized successfully. May 28 14:47:37 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 28 14:47:37 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 28 14:47:43 volumio ntpd[755]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 28 14:47:43 volumio ntpd[755]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 28 14:47:43 volumio ntpd[755]: DNS: Pool skipping: 202.181.103.212 May 28 14:47:43 volumio ntpd[755]: DNS: Pool taking: 162.159.200.123 May 28 14:47:43 volumio ntpd[755]: DNS: Pool skipping: 45.76.211.39 May 28 14:47:43 volumio ntpd[755]: DNS: Pool skipping: 160.16.113.133 May 28 14:47:43 volumio ntpd[755]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 May 28 14:47:55 volumio go-librespot[1403]: time="2025-05-28T14:47:55+09:00" level=trace msg="received accesspoint ping" May 28 14:47:55 volumio go-librespot[1403]: time="2025-05-28T14:47:55+09:00" level=trace msg="received accesspoint pong ack" May 28 14:47:55 volumio go-librespot[1403]: time="2025-05-28T14:47:55+09:00" level=trace msg="sent dealer ping" May 28 14:47:55 volumio go-librespot[1403]: time="2025-05-28T14:47:55+09:00" level=trace msg="received dealer pong" May 28 14:48:06 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 14:48:06 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 14:48:06 volumio volumio[1077]: info: Discovery: Getting this device information May 28 14:48:06 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState May 28 14:48:06 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 May 28 14:48:06 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 14:48:06 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 28 14:48:25 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 28 14:48:25 volumio volumio[1077]: info: CURURI: music-library/USB/781D-B169/Inoyamaland May 28 14:48:25 volumio volumio[1077]: info: Preload queue cleared May 28 14:48:25 volumio go-librespot[1403]: time="2025-05-28T14:48:25+09:00" level=trace msg="sent dealer ping" May 28 14:48:25 volumio go-librespot[1403]: time="2025-05-28T14:48:25+09:00" level=trace msg="received dealer pong" May 28 14:48:28 volumio volumio[1077]: info: CoreCommandRouter::volumioAddQueueItems May 28 14:48:28 volumio volumio[1077]: info: CoreStateMachine::addQueueItems May 28 14:48:28 volumio volumio[1077]: info: CorePlayQueue::addQueueItems May 28 14:48:28 volumio volumio[1077]: info: Preload queue cleared May 28 14:48:28 volumio volumio[1077]: info: Adding Item to queue: music-library/USB/781D-B169/Inoyamaland/Trans Kunang May 28 14:48:28 volumio volumio[1077]: info: Exploding uri music-library/USB/781D-B169/Inoyamaland/Trans Kunang in service mpd May 28 14:48:28 volumio volumio[1077]: info: ALBUMART /albumart?cacheid=528&web=INOYAMALAND/Trans%20Kunang/extralarge&path=%2Fmnt%2FUSB%2F781D-B169%2FInoyamaland%2FTrans%20Kunang%2FINOYAMALAND%20-%20Trans%20Kunang.cue&metadata=false May 28 14:48:28 volumio volumio[1077]: info: URI /mnt/USB/781D-B169/Inoyamaland/Trans Kunang/INOYAMALAND - Trans Kunang.cue May 28 14:48:28 volumio volumio[1077]: info: ALBUMART /albumart?cacheid=528&web=INOYAMALAND/Trans%20Kunang/extralarge&path=%2Fmnt%2FUSB%2F781D-B169%2FInoyamaland%2FTrans%20Kunang%2FINOYAMALAND%20-%20Trans%20Kunang.cue&metadata=false May 28 14:48:28 volumio volumio[1077]: info: URI /mnt/USB/781D-B169/Inoyamaland/Trans Kunang/INOYAMALAND - Trans Kunang.cue May 28 14:48:28 volumio volumio[1077]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 14:48:28 volumio volumio[1077]: Error: Unable to resolve or reject the same promise twice May 28 14:48:28 volumio volumio[1077]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 28 14:48:28 volumio volumio[1077]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 May 28 14:48:28 volumio volumio[1077]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 28 14:48:28 volumio volumio[1077]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 28 14:48:28 volumio volumio[1077]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 28 14:48:28 volumio volumio[1077]: at Socket.emit (node:events:514:28) May 28 14:48:28 volumio volumio[1077]: at addChunk (node:internal/streams/readable:343:12) May 28 14:48:28 volumio volumio[1077]: at readableAddChunk (node:internal/streams/readable:312:11) May 28 14:48:28 volumio volumio[1077]: at Readable.push (node:internal/streams/readable:253:10) May 28 14:48:28 volumio volumio[1077]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) May 28 14:48:28 volumio volumio[1077]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 14:48:30 volumio sudo[2762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-28 14:47' May 28 14:48:30 volumio sudo[2762]: 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="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025" VOLUMIO_VERSION="0.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"