Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.468+08:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.123.217:47768 Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.487+08:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=16.33891389s timeout=20s Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.487+08:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.489+08:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s Oct 17 15:45:06 volumio volumio[1081]: info: Received Get System Info Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 15:45:06 volumio volumio[1081]: info: Discovery: Getting this device information Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:06 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.496+08:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" name=Volumio Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.498+08:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" language=zh Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.514+08:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" timezone=Asia/Shanghai Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.516+08:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" available=true connected=true macAddress=70:71:bc:64:8e:cf ip4Address=192.168.123.12/24 ip6Address= Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.518+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.519+08:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" setupComplete=true Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 17 15:45:06 volumio volumio[1081]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 1 -D 7 Oct 17 15:45:06 volumio volumio[1081]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 17 15:45:06 volumio volumio[1081]: {"cmd":"/usr/local/bin/alsacap -C 1 -D 7","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 1 -D 7\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Oct 17 15:45:06 volumio volumio[1081]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 1 -D 3 Oct 17 15:45:06 volumio volumio[1081]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 17 15:45:06 volumio volumio[1081]: {"cmd":"/usr/local/bin/alsacap -C 1 -D 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 1 -D 3\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Oct 17 15:45:06 volumio volumio[1081]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 1 Oct 17 15:45:06 volumio volumio[1081]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 17 15:45:06 volumio volumio[1081]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 1","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 1\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Oct 17 15:45:06 volumio volumio[1081]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 0 Oct 17 15:45:06 volumio volumio[1081]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 17 15:45:06 volumio volumio[1081]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 0","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 0\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Oct 17 15:45:06 volumio volumio[1081]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Oct 17 15:45:06 volumio volumio[1081]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 17 15:45:06 volumio volumio[1081]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Oct 17 15:45:06 volumio volumio[1081]: amixer -c 5 info | grep "Audio Advantage MicroII" Oct 17 15:45:06 volumio volumio[1081]: Card sysdefault:5 'MicroII'/'C-Media INC. Audio Advantage MicroII at usb-0000:00:1d.2-1, full speed' Oct 17 15:45:06 volumio volumio[1081]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Oct 17 15:45:06 volumio volumio[1081]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 17 15:45:06 volumio volumio[1081]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Oct 17 15:45:06 volumio volumio[1081]: amixer -c 5 info | grep "Audio Advantage MicroII" Oct 17 15:45:06 volumio volumio[1081]: Card sysdefault:5 'MicroII'/'C-Media INC. Audio Advantage MicroII at usb-0000:00:1d.2-1, full speed' Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.750+08:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" selectedOutputId=5 Oct 17 15:45:06 volumio volumio[1081]: verbose: New Socket.io Connection to 192.168.123.12 from 192.168.123.217 UA: Mozilla/5.0 (Linux; Android 13; M2102J2SC Build/TKQ1.221114.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.79 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 17 15:45:06 volumio volumio[1081]: info: Received Get System Info Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 15:45:06 volumio volumio[1081]: info: Discovery: Getting this device information Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:06 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.773+08:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" currentVersion=4.119 latestVersion=4.119 Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.773+08:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" status=UPDATE_STATUS_NONE progress=0 Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.774+08:00 level=INFO msg="emitting user changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" userId= Oct 17 15:45:06 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:06.774+08:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.123.217:47768 @ 0xc0003a42a0" providers=3 Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetVisibleSources Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:06 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 17 15:45:06 volumio volumio[1081]: info: Received Get System Info Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 15:45:06 volumio volumio[1081]: info: Discovery: Getting this device information Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:06 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:06 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:06 volumio volumio[1081]: info: Listing playlists Oct 17 15:45:06 volumio volumio[1081]: info: CoreCommandRouter::volumioGetQueue Oct 17 15:45:06 volumio volumio[1081]: info: CoreStateMachine::getQueue Oct 17 15:45:06 volumio volumio[1081]: info: CorePlayQueue::getQueue Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.263+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=774.070779ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.398+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://securetoken.googleapis.com duration=907.473548ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.409+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=http://pushupdates.volumio.org duration=910.688787ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.437+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=943.767868ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.440+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://www.googleapis.com duration=948.885757ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.456+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://functions.volumio.cloud duration=958.264643ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.468+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://functions.volumio.cloud duration=975.012136ms Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.493+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=1.003367384s Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.544+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=1.055022801s Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 17 15:45:07 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:07.637+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://database.volumio.cloud duration=1.14099471s Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 15:45:07 volumio volumio[1081]: info: Discovery: Getting this device information Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:07 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 15:45:07 volumio volumio[1081]: verbose: New Socket.io Connection to 192.168.123.12:3000 from 192.168.123.217 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 17 15:45:07 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 17 15:45:08 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:08.079+08:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=http://cddb.volumio.org duration=1.585204477s error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 17 15:45:08 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:08.299+08:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=https://google.com duration=1.804671338s Oct 17 15:45:08 volumio volumio[1081]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 15:45:11 volumio volumio[1081]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 15:45:16 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:16.489+08:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=1.012258358s timeout=10s endpoint=http://plugins.volumio.org duration=9.993506267s error="Head \"http://plugins.volumio.workers.dev/\": context deadline exceeded" Oct 17 15:45:17 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:17.850+08:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.123.217:47768 error="read tcp 192.168.123.12:7331->192.168.123.217:47768: read: connection reset by peer" Oct 17 15:45:17 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:17.850+08:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.123.217:47768 Oct 17 15:45:17 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:17.850+08:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.123.217:47768 Oct 17 15:45:18 volumio volumio[1081]: error: Cannot download Available plugins list: Error: ETIMEDOUT Oct 17 15:45:18 volumio volumio[1081]: error: Cannot download Available plugins list: Error: ETIMEDOUT Oct 17 15:45:26 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:26.489+08:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.123.217:47768 @ 0xc0003a42a0" latency=16.33891389s timeout=20s error="failed to get available plugins: could not get available plugins: context deadline exceeded" Oct 17 15:45:26 volumio volumio5-onboarding[1500]: time=2026-10-17T15:45:26.489+08:00 level=ERROR msg="failed to send response" component=server dst=" @ 0xc0003a42a0" id=1955661573 status=STATUS_UNKNOWN error="no addresses to write to" Oct 17 15:45:33 volumio volumio[1081]: info: [yt-cast-receiver] Connecting sender through DIAL... Oct 17 15:45:36 volumio volumio[1081]: info: [yt-cast-receiver] (YouTube) Sender connected: XIAOMI M2102J2SC (user: Richard) Oct 17 15:45:36 volumio volumio[1081]: info: [ytcr] ***** Sender connected ***** Oct 17 15:45:36 volumio volumio[1081]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 15:45:50 volumio volumio[1081]: info: [yt-cast-receiver] Player.resume() Oct 17 15:45:50 volumio volumio[1081]: info: [yt-cast-receiver] Player.play(): OSgHU1tHVAM @ 0s Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:50 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:50 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioStop Oct 17 15:45:50 volumio volumio[1081]: info: CoreStateMachine::stop Oct 17 15:45:50 volumio volumio[1081]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:50 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:45:50 volumio volumio[1081]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:45:50 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:45:50 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:45:50 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:45:50 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:50 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:50 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:50 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:50 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:50 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:51 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:51 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:51 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:51 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:51 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:51 volumio volumio[1081]: { level: 65, muted: false } Oct 17 15:45:51 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:51 volumio volumio[1081]: { level: 62, muted: false } Oct 17 15:45:51 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:51 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:51 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:51 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:52 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:52 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:52 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:52 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:52 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:52 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:52 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:52 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:45:53 volumio volumio[1081]: info: [yt-cast-receiver] Player.setVolume(): Oct 17 15:45:53 volumio volumio[1081]: { level: 59, muted: false } Oct 17 15:46:03 volumio volumio[1081]: info: [yt-cast-receiver] Player.stop() Oct 17 15:46:03 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:46:03 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:46:03 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:46:03 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:46:03 volumio volumio[1081]: info: [yt-cast-receiver] Player.play(): OSgHU1tHVAM @ 0s Oct 17 15:46:03 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:46:03 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:46:09 volumio volumio[1081]: info: [ytcr] Innertube support service: Start service with Deno: deno 2.9.6 (stable, release, x86_64-unknown-linux-gnu) Oct 17 15:46:22 volumio volumio[1081]: info: [ytcr] Innertube support service: result: {"status":"started","server":{"address":"127.0.0.1","port":43855}} Oct 17 15:46:22 volumio volumio[1081]: info: [ytcr] Innertube support service running at http://127.0.0.1:43855 Oct 17 15:46:28 volumio volumio[1081]: error: [ytcr] Innertube support service: libEGL warning: failed to open /dev/dri/renderD128: Permission denied Oct 17 15:46:29 volumio volumio[1081]: info: [ytcr] Obtained session PO token using visitorData (expires in 43199 seconds) Oct 17 15:46:29 volumio volumio[1081]: info: [ytcr] Going to refresh session PO token in 43099 seconds Oct 17 15:46:29 volumio volumio[1081]: info: [ytcr] Obtained PO token for video #OSgHU1tHVAM: MlyFMzYlXWVgxIV27BTx7tANnOTEvIzy-KRCv_MlwBxk3icg5s5DIH9A9kM8DETb-oWXDQG1HCcCwptTzWoIXfCzD8_BA7kl6RbiUsoIcSMX5ea7b2IiyVsWSQ6DjQ== Oct 17 15:46:29 volumio volumio[1081]: info: CoreCommandRouter::volumioGetState Oct 17 15:46:29 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:46:29 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:46:29 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:46:29 volumio volumio[1081]: info: [ytcr] Obtained PO token for video #OSgHU1tHVAM: Mly8_i1hJYNPf7y791CJCP-2pSnf-PQU1x97cuhhuPpLZR7t_Yo7xlD7z44nSDw91T6uwBrxZMEteaKe1i5wu98INgLaR8HDxq3bn9FMCcU4q_Lx1htABdcLXf-b1g== Oct 17 15:46:31 volumio volumio[1081]: info: [ytcr] (OSgHU1tHVAM) fetching player data using ANDROID_VR client... Oct 17 15:46:31 volumio nmbd[1163]: [2026/10/17 15:46:31.726559, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 17 15:46:31 volumio nmbd[1163]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.123.12 for name WORKGROUP<1d>. Oct 17 15:46:31 volumio nmbd[1163]: This response was from IP 192.168.123.1, reporting an IP address of 192.168.123.1. Oct 17 15:46:32 volumio volumio[1081]: info: [ytcr] (黄奇帆往事：六朝元老、政坛不倒翁为何在退休十年后落马？) validating stream URL "https://rr2---sn-qja5mc-5j.googlevideo.com/videoplayback?expire=1792244791&ei=1yfTas2JMuyZsfIPnpimyQo&ip=185.186.146.137&id=o-ANQAOsXh3R_uZTyG2yibhWi1kWxnSJeVbxqvZfm9yAMk&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=1332&met=1792223191%2C&mh=f5&mm=18%2C29&mn=sn-qja5mc-5j%2Csn-qja5m5-5h&ms=aub%2Crdu&mv=m&mvi=2&pl=23&rms=aub%2Caub&initcwndbps=819750&siu=1&bui=AWzQHwrFR9m2I0UOaj2dUMBAqjdQVzsaSqplHU-ufwenu9jK_lsRISSnkCIcFZjxoedjCvWN2A&vprv=1&svpuc=1&mime=audio%2Fwebm&rqh=1&gir=yes&clen=36284538&dur=2734.321&lmt=1792121754817984&mt=1792222915&fvip=3&epbp=1&keepalive=yes&fexp=51565116%2C52227521&c=ANDROID_VR&txp=3308224&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cvprv%2Csvpuc%2Cmime%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AE0s2JYwRAIgR-a9LenbMZ99Htv_S3uin0Vuei4sPkJdwy2YJAvMYZwCIHQhbEVLIhBMi0IweqlUQdhZ0JHBKtibCqtkUjHIoLTR&lsparams=cps%2Cmet%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRgIhAPp4q6_Lygemqd4_B5ZfS-QFfOCEDNqIDVkZAbLGrcZvAiEA1K2sWrvg0tmcOjEl6HNETYDGkVoPfB7wYhkEmKAGKJU%3D&pot=Mly8_i1hJYNPf7y791CJCP-2pSnf-PQU1x97cuhhuPpLZR7t_Yo7xlD7z44nSDw91T6uwBrxZMEteaKe1i5wu98INgLaR8HDxq3bn9FMCcU4q_Lx1htABdcLXf-b1g%3D%3D"... Oct 17 15:46:32 volumio volumio[1081]: info: [ytcr] (黄奇帆往事：六朝元老、政坛不倒翁为何在退休十年后落马？) stream validated in 0.791s. Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:32 volumio volumio[1081]: verbose: ControllerMpd::sendMpdCommand status Oct 17 15:46:32 volumio volumio[1081]: info: sendMpdCommand status took 5 milliseconds Oct 17 15:46:32 volumio volumio[1081]: verbose: ControllerMpd::parseState Oct 17 15:46:32 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:46:32 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:46:32 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:46:32 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 15:46:32 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:46:35 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:35 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:35 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:35 volumio volumio[1081]: verbose: ControllerMpd::sendMpdCommand status Oct 17 15:46:35 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:35 volumio volumio[1081]: verbose: ControllerMpd::sendMpdCommand status Oct 17 15:46:35 volumio volumio[1081]: info: sendMpdCommand status took 4 milliseconds Oct 17 15:46:35 volumio volumio[1081]: verbose: ControllerMpd::parseState Oct 17 15:46:35 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:46:35 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:46:35 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:46:35 volumio volumio[1081]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 15:46:35 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:46:35 volumio volumio[1081]: info: sendMpdCommand status took 14 milliseconds Oct 17 15:46:35 volumio volumio[1081]: verbose: ControllerMpd::parseState Oct 17 15:46:35 volumio volumio[1081]: info: CorePlayQueue::getTrack 0 Oct 17 15:46:35 volumio volumio[1081]: info: CoreCommandRouter::servicePushState Oct 17 15:46:35 volumio volumio[1081]: info: CoreStateMachine::pushState Oct 17 15:46:35 volumio volumio[1081]: info: CoreCommandRouter::volumioPushState Oct 17 15:46:35 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:35 volumio volumio[1081]: info: Ignoring MPD Status Update Oct 17 15:46:35 volumio volumio[1081]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Oct 17 15:46:35 volumio volumio[1081]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 15:46:35 volumio volumio[1081]: TypeError: Cannot read properties of undefined (reading 'indexOf') Oct 17 15:46:35 volumio volumio[1081]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Oct 17 15:46:35 volumio volumio[1081]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Oct 17 15:46:35 volumio volumio[1081]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Oct 17 15:46:35 volumio volumio[1081]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Oct 17 15:46:35 volumio volumio[1081]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Oct 17 15:46:35 volumio volumio[1081]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Oct 17 15:46:35 volumio volumio[1081]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Oct 17 15:46:35 volumio volumio[1081]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Oct 17 15:46:35 volumio volumio[1081]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Oct 17 15:46:35 volumio volumio[1081]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Oct 17 15:46:35 volumio volumio[1081]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Oct 17 15:46:35 volumio volumio[1081]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Oct 17 15:46:35 volumio volumio[1081]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Oct 17 15:46:35 volumio volumio[1081]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Oct 17 15:46:35 volumio volumio[1081]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Oct 17 15:46:35 volumio volumio[1081]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Oct 17 15:46:35 volumio volumio[1081]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 15:46:36 volumio sudo[11374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-17 15:45' Oct 17 15:46:36 volumio sudo[11374]: 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"