Apr 15 20:56:02 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:02.413+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=403.248648ms timeout=3s volume=55 Apr 15 20:56:02 volumio volumio[1176]: info: VolumeController::SetAlsaVolume55 Apr 15 20:56:02 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:02 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:02 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:02 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:02.469+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=41721 volume=55 Apr 15 20:56:02 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:02.469+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:02 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:02.882+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=401.281747ms timeout=3s volume=64 Apr 15 20:56:02 volumio volumio[1176]: info: VolumeController::SetAlsaVolume64 Apr 15 20:56:02 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:02 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:02 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:02 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:02.943+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=41972 volume=64 Apr 15 20:56:02 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:02.943+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:03 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:03.391+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=402.057785ms timeout=3s volume=69 Apr 15 20:56:03 volumio volumio[1176]: info: VolumeController::SetAlsaVolume69 Apr 15 20:56:03 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:03 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:03 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:03 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:03.443+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=42508 volume=69 Apr 15 20:56:03 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:03.443+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:03 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:03.801+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=402.948101ms timeout=3s volume=73 Apr 15 20:56:03 volumio volumio[1176]: info: VolumeController::SetAlsaVolume73 Apr 15 20:56:03 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:03 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:03 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:03 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:03.839+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=43019 volume=73 Apr 15 20:56:03 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:03.839+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:04 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:04.198+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=401.627082ms timeout=3s volume=78 Apr 15 20:56:04 volumio volumio[1176]: info: VolumeController::SetAlsaVolume78 Apr 15 20:56:04 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:04 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:04 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:04 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:04.229+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=43270 volume=78 Apr 15 20:56:04 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:04.229+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:04 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:04.622+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=402.034755ms timeout=3s volume=88 Apr 15 20:56:04 volumio volumio[1176]: info: VolumeController::SetAlsaVolume88 Apr 15 20:56:04 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:04 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:04 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:04 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:04.650+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=43793 volume=88 Apr 15 20:56:04 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:04.650+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.015+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=401.790944ms timeout=3s volume=92 Apr 15 20:56:05 volumio volumio[1176]: info: VolumeController::SetAlsaVolume92 Apr 15 20:56:05 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:05 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:05 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.050+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=44296 volume=92 Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.051+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.314+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=400.317773ms timeout=3s volume=97 Apr 15 20:56:05 volumio volumio[1176]: info: VolumeController::SetAlsaVolume97 Apr 15 20:56:05 volumio volumio[1176]: info: CoreStateMachine::pushState Apr 15 20:56:05 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 20:56:05 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.352+08:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" state=STATUS_PLAYING positionMs=44546 volume=97 Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.353+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.148:50014 @ 0xc000339200" id=http://10.0.0.9:8200/MediaItems/800.wav title=800.wav Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.411+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=400.120874ms timeout=3s volume=112 Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.411+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=400.120874ms timeout=3s volume=112 error="could not set volume to 112: volume must be between 0 and 100, got 112" Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.514+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=402.702511ms timeout=3s volume=106 Apr 15 20:56:05 volumio volumio5-onboarding[2083]: time=2026-04-15T20:56:05.515+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="10.0.0.148:50014 @ 0xc000339200" latency=402.702511ms timeout=3s volume=106 error="could not set volume to 106: volume must be between 0 and 100, got 106" Apr 15 20:56:31 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:56:31 volumio volumio[1176]: info: Preload queue cleared Apr 15 20:56:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:56:34 volumio volumio[1176]: info: Preload queue cleared Apr 15 20:56:45 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:56:45 volumio volumio[1176]: info: Preload queue cleared Apr 15 20:56:46 volumio volumio[1176]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Rihanna/Anti%20(Deluxe)/51667e8a-e4a3-47ed-8db5-9bd5b8a19549.png' Apr 15 20:56:46 volumio volumio[1176]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/The%20Weeknd/Beauty%20Behind%20The%20Madness/4953568c-2ec9-4425-af25-65b4d2e61535.jpg' Apr 15 20:56:47 volumio volumio[1176]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%80%89%E6%9C%A8%E9%BA%BB%E8%A1%A3/One%20Life/09236f06-6c96-47b3-a9fe-ea494e666de9.jpg' Apr 15 20:57:29 volumio volumio[1176]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E4%BA%8E%E6%96%87%E6%96%87/%E5%A5%89%E9%99%AA/3a21b6ed-c4ed-4181-8453-3c40c26d0b4f.jpg' Apr 15 20:57:48 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 15 20:57:49 volumio volumio[1176]: info: Preload queue cleared Apr 15 20:57:49 volumio volumio[1176]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@1$7$1B$0 Apr 15 20:57:49 volumio volumio[1176]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@1$7$1B$1 Apr 15 20:57:49 volumio volumio[1176]: info: Preloading song: upnp/http://10.0.0.9:8200/ctl/ContentDir@1$7$1B$2 Apr 15 20:57:49 volumio volumio[1176]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@1$7$1B$0 in service upnp_browser Apr 15 20:57:49 volumio volumio[1176]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@1$7$1B$1 in service upnp_browser Apr 15 20:57:49 volumio volumio[1176]: info: Exploding uri upnp/http://10.0.0.9:8200/ctl/ContentDir@1$7$1B$2 in service upnp_browser Apr 15 20:57:50 volumio volumio[1176]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 20:57:50 volumio volumio[1176]: Error: connect ETIMEDOUT 103.252.114.11:443 Apr 15 20:57:50 volumio volumio[1176]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 15 20:57:50 volumio volumio[1176]: errno: -110, Apr 15 20:57:50 volumio volumio[1176]: code: 'ETIMEDOUT', Apr 15 20:57:50 volumio volumio[1176]: syscall: 'connect', Apr 15 20:57:50 volumio volumio[1176]: address: '103.252.114.11', Apr 15 20:57:50 volumio volumio[1176]: port: 443 Apr 15 20:57:50 volumio volumio[1176]: } Apr 15 20:57:50 volumio volumio[1176]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 20:57:50 volumio sudo[3657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 20:56' Apr 15 20:57:50 volumio sudo[3657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"