Oct 16 12:24:03 volumio bluealsa[1000]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_6B_26_2F_A8_AB_57, ...) Oct 16 12:24:19 volumio bluealsa[1000]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6B_26_2F_A8_AB_57, ...) Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.352+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.116:55787 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.367+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.116:55787 @ 0x25884b0" latency=8.400594ms timeout=20s Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.367+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" Oct 16 12:24:20 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:20 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:20 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.370+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" name=Volumio Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.371+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" language=pl Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.372+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" timezone=Europe/Warsaw Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.373+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" available=true connected=true macAddress=98:fe:54:21:5c:43 ip4Address=192.168.0.135/24 ip6Address= Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.374+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.375+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" setupComplete=true Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 12:24:20 volumio volumio[1224]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 16 12:24:20 volumio volumio[1224]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.419+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s Oct 16 12:24:20 volumio volumio[1224]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Oct 16 12:24:20 volumio volumio[1224]: amixer -c 2 info | grep "vc4-hdmi-0" Oct 16 12:24:20 volumio volumio[1224]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Oct 16 12:24:20 volumio volumio[1224]: amixer -c 3 info | grep "vc4-hdmi-1" Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.477+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=http://pushupdates.volumio.org duration=57.734176ms Oct 16 12:24:20 volumio volumio[1224]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Oct 16 12:24:20 volumio volumio[1224]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 16 12:24:20 volumio volumio[1224]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 16 12:24:20 volumio volumio[1224]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\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 16 12:24:20 volumio volumio[1224]: amixer -c 4 info | grep "Allo DigiOne" Oct 16 12:24:20 volumio volumio[1224]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 16 12:24:20 volumio volumio[1224]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 16 12:24:20 volumio volumio[1224]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\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 16 12:24:20 volumio volumio[1224]: amixer -c 4 info | grep "snd_allo_digione" Oct 16 12:24:20 volumio volumio[1224]: Card sysdefault:4 'sndallodigione'/'snd_allo_digione' Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.605+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" selectedOutputId=4 Oct 16 12:24:20 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:20 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:20 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.639+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" currentVersion=4.119 latestVersion=4.119 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.639+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.0.116:55787 @ 0x25884b0" status=UPDATE_STATUS_NONE progress=0 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.640+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" userId=61kSyoaOZSgRI06ceZy3d0NhY272 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.640+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" providers=9 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.640+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" plugins=78 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.641+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=221.846835ms Oct 16 12:24:20 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:20 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.643+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" state=STATUS_PLAYING positionMs=35301 volume=100 Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.644+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" id="mnt/USB/6A42-3373/Trio Joubran - Majaz[FLAC - LOSSLESS]/02. Roubbama.flac" title=Roubbama Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.656+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=http://cddb.volumio.org duration=235.18854ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.722+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=301.572999ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.741+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://functions.volumio.cloud duration=320.995049ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.749+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=328.420019ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.750+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://www.googleapis.com duration=331.136863ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.754+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://securetoken.googleapis.com duration=334.14672ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.779+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=360.277382ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.780+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://functions.volumio.cloud duration=359.758168ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.842+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=http://plugins.volumio.org duration=422.189395ms Oct 16 12:24:20 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:20.985+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://database.volumio.cloud duration=564.998258ms Oct 16 12:24:21 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:21.041+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55787 @ 0x25884b0" latency=12.96202ms timeout=10s endpoint=https://google.com duration=622.574511ms Oct 16 12:24:24 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:24.623+02:00 level=INFO msg="new address was allocated" component=ble/conn old=5 new=6 Oct 16 12:24:24 volumio dbus-daemon[736]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.23" (uid=0 pid=1876 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=836 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Oct 16 12:24:31 volumio dbus-daemon[736]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.23" (uid=0 pid=1876 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=836 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Oct 16 12:24:33 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:33.691+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=1 index=0 tries=11 Oct 16 12:24:41 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:41.228+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.0.116:55787 error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 16 12:24:41 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:41.228+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.0.116:55787 Oct 16 12:24:41 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:41.228+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.0.116:55787 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.567+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.116:55796 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.650+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.116:55796 @ 0x22633b0" latency=23.952477ms timeout=20s Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.650+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.650+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s Oct 16 12:24:47 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:47 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:47 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.653+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" name=Volumio Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.654+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" language=pl Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.658+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" timezone=Europe/Warsaw Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.659+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" available=true connected=true macAddress=98:fe:54:21:5c:43 ip4Address=192.168.0.135/24 ip6Address= Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.660+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.660+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" setupComplete=true Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.669+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=18.977205ms Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.669+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=http://pushupdates.volumio.org duration=19.374457ms Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 12:24:47 volumio volumio[1224]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.691+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=40.699587ms Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.696+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=45.745299ms Oct 16 12:24:47 volumio volumio[1224]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 16 12:24:47 volumio volumio[1224]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Oct 16 12:24:47 volumio volumio[1224]: amixer -c 2 info | grep "vc4-hdmi-0" Oct 16 12:24:47 volumio volumio[1224]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Oct 16 12:24:47 volumio volumio[1224]: amixer -c 3 info | grep "vc4-hdmi-1" Oct 16 12:24:47 volumio volumio[1224]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.758+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=http://cddb.volumio.org duration=107.457113ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.762+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://www.googleapis.com duration=112.605954ms Oct 16 12:24:47 volumio volumio[1224]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 16 12:24:47 volumio volumio[1224]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 16 12:24:47 volumio volumio[1224]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\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 16 12:24:47 volumio volumio[1224]: amixer -c 4 info | grep "snd_allo_digione" Oct 16 12:24:47 volumio volumio[1224]: Card sysdefault:4 'sndallodigione'/'snd_allo_digione' Oct 16 12:24:47 volumio volumio[1224]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 16 12:24:47 volumio volumio[1224]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 16 12:24:47 volumio volumio[1224]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\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 16 12:24:47 volumio volumio[1224]: amixer -c 4 info | grep "Allo DigiOne" Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.792+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=141.530716ms Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.800+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" selectedOutputId=4 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.805+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://securetoken.googleapis.com duration=154.60763ms Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.806+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://functions.volumio.cloud duration=155.606336ms Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.807+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://functions.volumio.cloud duration=156.429804ms Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.810+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://database.volumio.cloud duration=159.939431ms Oct 16 12:24:47 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.813+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=http://plugins.volumio.org duration=162.727292ms Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:47 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:47 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.816+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" currentVersion=4.119 latestVersion=4.119 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.816+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.0.116:55796 @ 0x22633b0" status=UPDATE_STATUS_NONE progress=0 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.816+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" userId=61kSyoaOZSgRI06ceZy3d0NhY272 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.817+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" providers=9 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.817+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" plugins=78 Oct 16 12:24:47 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:47 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.821+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" state=STATUS_PLAYING positionMs=62577 volume=100 Oct 16 12:24:47 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:47.821+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55796 @ 0x22633b0" id="mnt/USB/6A42-3373/Trio Joubran - Majaz[FLAC - LOSSLESS]/02. Roubbama.flac" title=Roubbama Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.005+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=16.184177ms timeout=10s endpoint=https://google.com duration=354.817062ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.316+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.339+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=22.72668ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.340+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=http://pushupdates.volumio.org duration=22.1788ms Oct 16 12:24:48 volumio volumio[1224]: verbose: New Socket.io Connection to 192.168.0.135 from 192.168.0.116 UA: Mozilla/5.0 (iPad; CPU OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 5 Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.359+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=41.975621ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.366+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=48.929432ms Oct 16 12:24:48 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:48 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:48 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 12:24:48 volumio volumio[1224]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 12:24:48 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 12:24:48 volumio volumio[1224]: info: Listing playlists Oct 16 12:24:48 volumio volumio[1224]: info: CoreCommandRouter::volumioGetQueue Oct 16 12:24:48 volumio volumio[1224]: info: CoreStateMachine::getQueue Oct 16 12:24:48 volumio volumio[1224]: info: CorePlayQueue::getQueue Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.401+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=http://cddb.volumio.org duration=83.837355ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.430+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://www.googleapis.com duration=113.008096ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.461+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=144.039934ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.472+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://securetoken.googleapis.com duration=155.615761ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.473+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://functions.volumio.cloud duration=155.888257ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.474+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://functions.volumio.cloud duration=156.679151ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.476+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://database.volumio.cloud duration=158.238181ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.484+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=http://plugins.volumio.org duration=166.016571ms Oct 16 12:24:48 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:48.670+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55796 @ 0x22633b0" latency=19.722197ms timeout=10s endpoint=https://google.com duration=353.026183ms Oct 16 12:24:51 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:51 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:51 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:51 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:51 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:51 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:51 volumio volumio[1224]: verbose: New Socket.io Connection to 192.168.0.135:3000 from 192.168.0.116 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Oct 16 12:24:51 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 12:24:51 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.200+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.0.116:55796 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.200+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.0.116:55796 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.208+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.116:55906 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.332+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.116:55906 @ 0x24936e0" latency=6.93508ms timeout=20s Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.332+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" Oct 16 12:24:53 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:53 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:53 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.335+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" name=Volumio Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.336+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" language=pl Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.339+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" timezone=Europe/Warsaw Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.340+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" available=true connected=true macAddress=98:fe:54:21:5c:43 ip4Address=192.168.0.135/24 ip6Address= Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.342+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.343+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" setupComplete=true Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 12:24:53 volumio volumio[1224]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 16 12:24:53 volumio volumio[1224]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 16 12:24:53 volumio volumio[1224]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Oct 16 12:24:53 volumio volumio[1224]: amixer -c 2 info | grep "vc4-hdmi-0" Oct 16 12:24:53 volumio volumio[1224]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Oct 16 12:24:53 volumio volumio[1224]: amixer -c 3 info | grep "vc4-hdmi-1" Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.428+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s Oct 16 12:24:53 volumio volumio[1224]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.448+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=http://pushupdates.volumio.org duration=19.206146ms Oct 16 12:24:53 volumio volumio[1224]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 16 12:24:53 volumio volumio[1224]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 16 12:24:53 volumio volumio[1224]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\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 16 12:24:53 volumio volumio[1224]: amixer -c 4 info | grep "Allo DigiOne" Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.450+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=21.356091ms Oct 16 12:24:53 volumio volumio[1224]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Oct 16 12:24:53 volumio volumio[1224]: /bin/sh: 1: /usr/local/bin/alsacap: not found Oct 16 12:24:53 volumio volumio[1224]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\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 16 12:24:53 volumio volumio[1224]: amixer -c 4 info | grep "snd_allo_digione" Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.471+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=42.215876ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.476+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=47.143184ms Oct 16 12:24:53 volumio volumio[1224]: Card sysdefault:4 'sndallodigione'/'snd_allo_digione' Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.489+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" selectedOutputId=4 Oct 16 12:24:53 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:53 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:53 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.503+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" currentVersion=4.119 latestVersion=4.119 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.504+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.0.116:55906 @ 0x24936e0" status=UPDATE_STATUS_NONE progress=0 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.504+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" userId=61kSyoaOZSgRI06ceZy3d0NhY272 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.505+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" providers=9 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.505+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" plugins=78 Oct 16 12:24:53 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:53 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.509+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=68083 volume=100 Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.509+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Trio Joubran - Majaz[FLAC - LOSSLESS]/02. Roubbama.flac" title=Roubbama Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.512+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=http://cddb.volumio.org duration=83.589785ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.542+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://www.googleapis.com duration=113.642658ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.574+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=144.790051ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.578+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://securetoken.googleapis.com duration=149.528991ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.579+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://functions.volumio.cloud duration=150.538753ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.580+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://functions.volumio.cloud duration=150.770471ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.587+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://database.volumio.cloud duration=157.94476ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.598+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=http://plugins.volumio.org duration=168.872857ms Oct 16 12:24:53 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:53.784+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=75.614963ms timeout=10s endpoint=https://google.com duration=355.199018ms Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.850+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.0.116:55906 @ 0x24936e0" latency=705.813079ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.872+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.895+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=http://pushupdates.volumio.org duration=22.925398ms Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.897+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=24.612186ms Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.917+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=44.226029ms Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.922+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=49.560921ms Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.955+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=http://cddb.volumio.org duration=82.856445ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 12:24:54 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:54.988+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://www.googleapis.com duration=115.678958ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.026+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=153.398131ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.028+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://securetoken.googleapis.com duration=155.237823ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.029+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://functions.volumio.cloud duration=156.538764ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.030+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://database.volumio.cloud duration=157.239142ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.035+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://functions.volumio.cloud duration=162.788457ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.039+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=http://plugins.volumio.org duration=166.624172ms Oct 16 12:24:55 volumio volumio5-onboarding[1876]: time=2026-10-16T12:24:55.229+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.116:55906 @ 0x24936e0" latency=6.216619ms timeout=10s endpoint=https://google.com duration=356.855397ms Oct 16 12:24:55 volumio sudo[12503]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 12:24:55 volumio sudo[12503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 12:24:55 volumio sudo[12503]: pam_unix(sudo:session): session closed for user root Oct 16 12:24:55 volumio sudo[12505]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 12:24:55 volumio sudo[12505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 12:24:55 volumio sudo[12505]: pam_unix(sudo:session): session closed for user root Oct 16 12:24:55 volumio volumio[1224]: verbose: New Socket.io Connection to 192.168.0.135 from 192.168.0.116 UA: Mozilla/5.0 (iPad; CPU OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 5 Oct 16 12:24:56 volumio sudo[12511]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 12:24:56 volumio sudo[12511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 12:24:56 volumio sudo[12513]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 12:24:56 volumio sudo[12511]: pam_unix(sudo:session): session closed for user root Oct 16 12:24:56 volumio sudo[12513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 12:24:56 volumio sudo[12513]: pam_unix(sudo:session): session closed for user root Oct 16 12:24:56 volumio volumio[1224]: verbose: New Socket.io Connection to 192.168.0.135 from 192.168.0.116 UA: Mozilla/5.0 (iPad; CPU OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:56 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 12:24:56 volumio volumio[1224]: info: Listing playlists Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 12:24:56 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 12:24:58 volumio volumio[1224]: info: Received Get System Info Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:24:58 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:24:58 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 12:24:58 volumio volumio[1224]: info: CURURI: artists:// Oct 16 12:24:58 volumio volumio[1224]: info: CoreCommandRouter::volumioGetQueue Oct 16 12:24:58 volumio volumio[1224]: info: CoreStateMachine::getQueue Oct 16 12:24:58 volumio volumio[1224]: info: CorePlayQueue::getQueue Oct 16 12:24:58 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:24:59 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 12:24:59 volumio volumio[1224]: info: CURURI: music-library Oct 16 12:24:59 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:00 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 12:25:00 volumio volumio[1224]: info: Received Get System Info Oct 16 12:25:00 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:25:00 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:25:00 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:25:00 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:25:00 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:25:00 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:25:01 volumio bluealsa[1000]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_6B_26_2F_A8_AB_57, ...) Oct 16 12:25:02 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 12:25:02 volumio volumio[1224]: info: CURURI: music-library/USB Oct 16 12:25:02 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:03 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 12:25:03 volumio volumio[1224]: info: CURURI: music-library/USB/6A42-3373 Oct 16 12:25:03 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:03 volumio bluealsa[1000]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6B_26_2F_A8_AB_57, ...) Oct 16 12:25:09 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 12:25:09 volumio volumio[1224]: info: CURURI: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC) Oct 16 12:25:09 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/02 - Tet Kole.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/03 - Tonbe Leve.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/04 - Tou Sel Me.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/05 - Intro Sonje Joj.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/06 - Sonje Joj.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/07 - S'en Souvenir Pour Devenir.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/08 - Karube.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/09 - Zetliyo.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/10 - Mesi La Fanmi Part 1.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/11 - Mesi La Fanmi Part 2.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/12 - Mesi La Fanmi Part 3.flac Oct 16 12:25:09 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/13 - La Habana Kreyol.flac Oct 16 12:25:09 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac in service mpd Oct 16 12:25:09 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F01%20-%20Experience%20One.flac&metadata=false Oct 16 12:25:09 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac Oct 16 12:25:09 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/02 - Tet Kole.flac in service mpd Oct 16 12:25:09 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F02%20-%20Tet%20Kole.flac&metadata=false Oct 16 12:25:09 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/02 - Tet Kole.flac Oct 16 12:25:09 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/03 - Tonbe Leve.flac in service mpd Oct 16 12:25:09 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F03%20-%20Tonbe%20Leve.flac&metadata=false Oct 16 12:25:09 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/03 - Tonbe Leve.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/04 - Tou Sel Me.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F04%20-%20Tou%20Sel%20Me.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/04 - Tou Sel Me.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/05 - Intro Sonje Joj.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F05%20-%20Intro%20Sonje%20Joj.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/05 - Intro Sonje Joj.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/06 - Sonje Joj.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F06%20-%20Sonje%20Joj.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/06 - Sonje Joj.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/07 - S'en Souvenir Pour Devenir.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F07%20-%20S'en%20Souvenir%20Pour%20Devenir.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/07 - S'en Souvenir Pour Devenir.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/08 - Karube.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F08%20-%20Karube.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/08 - Karube.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/09 - Zetliyo.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F09%20-%20Zetliyo.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/09 - Zetliyo.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/10 - Mesi La Fanmi Part 1.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F10%20-%20Mesi%20La%20Fanmi%20Part%201.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/10 - Mesi La Fanmi Part 1.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/11 - Mesi La Fanmi Part 2.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F11%20-%20Mesi%20La%20Fanmi%20Part%202.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/11 - Mesi La Fanmi Part 2.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/12 - Mesi La Fanmi Part 3.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F12%20-%20Mesi%20La%20Fanmi%20Part%203.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/12 - Mesi La Fanmi Part 3.flac Oct 16 12:25:10 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/13 - La Habana Kreyol.flac in service mpd Oct 16 12:25:10 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=Arnaud%20Dolmen%20Quartet/Tonbe%20Love/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FArnaud%20Dolmen%20Quartet%20-%20Tonbe%20Leve%20(2017)%20(FLAC)%2F13%20-%20La%20Habana%20Kreyol.flac&metadata=false Oct 16 12:25:10 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/13 - La Habana Kreyol.flac Oct 16 12:25:11 volumio volumio[1224]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Gregoire%20Maret/08844529-7444-47e4-a335-cb163a742e76.jpg' Oct 16 12:25:11 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::ClearQueue Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::stop Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::stPlaybackTimer Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::updateTrackBlock Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrackBlock Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::serviceStop Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 1 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::serviceStop Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::stop Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::clearPlayQueue Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::saveQueue Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::addQueueItems Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::addQueueItems Oct 16 12:25:11 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.540+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55787 @ 0x25884b0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.540+02:00 level=ERROR msg="failed to send event" component=server dst="192.168.0.116:55787 @ 0x25884b0" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="no WebSocket connection found for address: 192.168.0.116:55787" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.540+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.540+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Trio Joubran - Majaz[FLAC - LOSSLESS]/02. Roubbama.flac" title=Roubbama Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::saveQueue Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::updateTrackBlock Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrackBlock Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPlay Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::play index 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::addQueueItems Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::addQueueItems Oct 16 12:25:11 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/02 - Tet Kole.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/02 - Tet Kole.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/03 - Tonbe Leve.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/03 - Tonbe Leve.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/04 - Tou Sel Me.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/04 - Tou Sel Me.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/05 - Intro Sonje Joj.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/05 - Intro Sonje Joj.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/06 - Sonje Joj.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/06 - Sonje Joj.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/07 - S'en Souvenir Pour Devenir.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/07 - S'en Souvenir Pour Devenir.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/08 - Karube.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/08 - Karube.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/09 - Zetliyo.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/09 - Zetliyo.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/10 - Mesi La Fanmi Part 1.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/10 - Mesi La Fanmi Part 1.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/11 - Mesi La Fanmi Part 2.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/11 - Mesi La Fanmi Part 2.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/12 - Mesi La Fanmi Part 3.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/12 - Mesi La Fanmi Part 3.flac Oct 16 12:25:11 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/13 - La Habana Kreyol.flac Oct 16 12:25:11 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/13 - La Habana Kreyol.flac Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::stop Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::saveQueue Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::play index undefined Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::updateTrackBlock Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrackBlock Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::startPlaybackTimer Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::clearAddPlayTracks USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand stop took 24 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand stop took 6 milliseconds Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand clear Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:11 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 11 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand clear took 12 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 12 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 11 milliseconds Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand add "USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService stop Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: No code Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService stop Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: No code Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.594+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.594+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.595+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.595+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.602+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.602+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.602+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.602+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.603+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.603+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.603+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.603+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 46ms Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 46ms Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:11 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:11 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:11 volumio volumio[1224]: error: updateQueue error: null Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:11 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 40ms Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 38 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand add "USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" took 38 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 4ms Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 3ms Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand play Oct 16 12:25:11 volumio volumio[1224]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 55ms Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:11 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:11 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 25ms Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand play took 23 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 22ms Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 22ms Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 6 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 5 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 4 milliseconds Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: Oct 16 12:25:11 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 7 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 4 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand status took 3 milliseconds Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":319,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"576 Kbps","isStreaming":false,"title":"Experience One","artist":"Arnaud Dolmen Quartet","album":"Tonbe Love","uri":"USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac","trackType":"flac"} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":319,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"576 Kbps","isStreaming":false,"title":"Experience One","artist":"Arnaud Dolmen Quartet","album":"Tonbe Love","uri":"USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac","trackType":"flac"} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:11 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":319,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"576 Kbps","isStreaming":false,"title":"Experience One","artist":"Arnaud Dolmen Quartet","album":"Tonbe Love","uri":"USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac","trackType":"flac"} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:11 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 29ms Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.675+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.676+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.678+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.679+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.679+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.679+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.680+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.680+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 48ms Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 47ms Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 16 12:25:11 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":319,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"576 Kbps","isStreaming":false,"title":"Experience One","artist":"Arnaud Dolmen Quartet","album":"Tonbe Love","uri":"USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac","trackType":"flac"} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:11 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":319,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"576 Kbps","isStreaming":false,"title":"Experience One","artist":"Arnaud Dolmen Quartet","album":"Tonbe Love","uri":"USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac","trackType":"flac"} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:11 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":319,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"576 Kbps","isStreaming":false,"title":"Experience One","artist":"Arnaud Dolmen Quartet","album":"Tonbe Love","uri":"USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac","trackType":"flac"} Oct 16 12:25:11 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:11 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:11 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:11 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.715+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.716+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.716+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.716+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.718+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:11 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:11.718+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 83ms Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 80ms Oct 16 12:25:11 volumio volumio[1224]: info: ------------------------------ 79ms Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 12:25:14 volumio volumio[1224]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 16 12:25:14 volumio volumio[1224]: info: Received Get System Version Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 12:25:14 volumio volumio[1224]: info: Received Get System Info Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 12:25:14 volumio volumio[1224]: info: Discovery: Getting this device information Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::volumioGetState Oct 16 12:25:14 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:14 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 12:25:26 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 12:25:26 volumio volumio[1224]: info: CURURI: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987 Oct 16 12:25:26 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/02. Misty.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/03. Our Love Is Here To Stay.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/04. My Foolish Heart.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/05. Bridge Over Troubled Water.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/06. When You Smile.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/07. Mr. Wonderful.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/08. Feel Like Makin' Love.flac Oct 16 12:25:26 volumio volumio[1224]: info: Preloading song: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/09. The Lady Is a Tramp.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F01.%20Wrap%20Your%20Troubles%20In%20Dreams.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/02. Misty.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F02.%20Misty.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/02. Misty.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/03. Our Love Is Here To Stay.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F03.%20Our%20Love%20Is%20Here%20To%20Stay.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/03. Our Love Is Here To Stay.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/04. My Foolish Heart.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F04.%20My%20Foolish%20Heart.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/04. My Foolish Heart.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/05. Bridge Over Troubled Water.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F05.%20Bridge%20Over%20Troubled%20Water.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/05. Bridge Over Troubled Water.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/06. When You Smile.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F06.%20When%20You%20Smile.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/06. When You Smile.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/07. Mr. Wonderful.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F07.%20Mr.%20Wonderful.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/07. Mr. Wonderful.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/08. Feel Like Makin' Love.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F08.%20Feel%20Like%20Makin'%20Love.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/08. Feel Like Makin' Love.flac Oct 16 12:25:26 volumio volumio[1224]: info: Exploding uri music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/09. The Lady Is a Tramp.flac in service mpd Oct 16 12:25:26 volumio volumio[1224]: info: ALBUMART /albumart?cacheid=45&web=%E7%B4%B0%E5%B7%9D%E7%B6%BE%E5%AD%90/Mr.%20Wonderful/extralarge&path=%2Fmnt%2FUSB%2F6A42-3373%2FAyako%20Hosokawa%20-%20Mr.%20Wonderful%20%201987%2F09.%20The%20Lady%20Is%20a%20Tramp.flac&metadata=false Oct 16 12:25:26 volumio volumio[1224]: info: URI /mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/09. The Lady Is a Tramp.flac Oct 16 12:25:27 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::ClearQueue Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::stop Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::stPlaybackTimer Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::updateTrackBlock Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrackBlock Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::serviceStop Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::serviceStop Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::stop Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::clearPlayQueue Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::saveQueue Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::addQueueItems Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::addQueueItems Oct 16 12:25:27 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.519+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.519+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Arnaud Dolmen Quartet - Tonbe Leve (2017) (FLAC)/01 - Experience One.flac" title="Experience One" Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::saveQueue Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::updateTrackBlock Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrackBlock Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPlay Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::play index 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::addQueueItems Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::addQueueItems Oct 16 12:25:27 volumio volumio[1224]: info: Preload queue cleared Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/02. Misty.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/02. Misty.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/03. Our Love Is Here To Stay.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/03. Our Love Is Here To Stay.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/04. My Foolish Heart.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/04. My Foolish Heart.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/05. Bridge Over Troubled Water.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/05. Bridge Over Troubled Water.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/06. When You Smile.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/06. When You Smile.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/07. Mr. Wonderful.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/07. Mr. Wonderful.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/08. Feel Like Makin' Love.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/08. Feel Like Makin' Love.flac Oct 16 12:25:27 volumio volumio[1224]: info: Adding Item to queue: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/09. The Lady Is a Tramp.flac Oct 16 12:25:27 volumio volumio[1224]: info: Using cached record of: music-library/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/09. The Lady Is a Tramp.flac Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::stop Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushQueue Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::saveQueue Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::play index undefined Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::updateTrackBlock Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrackBlock Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::startPlaybackTimer Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::clearAddPlayTracks USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand stop took 40 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand stop took 8 milliseconds Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand clear Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:27 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 3 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand clear took 2 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 3 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 2 milliseconds Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand add "USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService stop Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: No code Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService stop Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: No code Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.580+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.580+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.581+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.581+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.582+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.582+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.583+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.584+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.584+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.585+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.585+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.586+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 37ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 37ms Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:27 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:27 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:27 volumio volumio[1224]: error: updateQueue error: null Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:27 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 40ms Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand add "USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" took 39 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 4ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 3ms Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand play Oct 16 12:25:27 volumio volumio[1224]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 45ms Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:27 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces system playlist update Oct 16 12:25:27 volumio volumio[1224]: info: Ignoring MPD Status Update Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 13ms Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand play took 11 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 11ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 10ms Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 2 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: Oct 16 12:25:27 volumio volumio[1224]: ---------------------------- MPD announces state update: player Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::getState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 6 milliseconds Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 7 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 6 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 5 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand status took 5 milliseconds Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseState Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":213,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Wrap Your Troubles In Dreams","artist":"細川綾子","album":"Mr. Wonderful","uri":"USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac","trackType":"flac"} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 13ms Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 16 12:25:27 volumio volumio[1224]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: verbose: ControllerMpd::parseTrackInfo Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":213,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"464 Kbps","isStreaming":false,"title":"Wrap Your Troubles In Dreams","artist":"細川綾子","album":"Mr. Wonderful","uri":"USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac","trackType":"flac"} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:27 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":213,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"577 Kbps","isStreaming":false,"title":"Wrap Your Troubles In Dreams","artist":"細川綾子","album":"Mr. Wonderful","uri":"USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac","trackType":"flac"} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:27 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":213,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"529 Kbps","isStreaming":false,"title":"Wrap Your Troubles In Dreams","artist":"細川綾子","album":"Mr. Wonderful","uri":"USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac","trackType":"flac"} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:27 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":213,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"529 Kbps","isStreaming":false,"title":"Wrap Your Troubles In Dreams","artist":"細川綾子","album":"Mr. Wonderful","uri":"USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac","trackType":"flac"} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:27 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: ControllerMpd::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::servicePushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":213,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"529 Kbps","isStreaming":false,"title":"Wrap Your Troubles In Dreams","artist":"細川綾子","album":"Mr. Wonderful","uri":"USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac","trackType":"flac"} Oct 16 12:25:27 volumio volumio[1224]: verbose: CURRENT POSITION 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState stateService play Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::syncState currentStatus play Oct 16 12:25:27 volumio volumio[1224]: info: Received an update from plugin. extracting info from payload Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio[1224]: info: CoreStateMachine::pushState Oct 16 12:25:27 volumio volumio[1224]: info: CorePlayQueue::getTrack 0 Oct 16 12:25:27 volumio volumio[1224]: info: CoreCommandRouter::volumioPushState Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.662+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.662+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.663+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.664+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.665+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.665+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.666+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.667+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.667+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.667+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.669+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.669+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.670+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.670+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.671+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.671+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.672+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.672+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.673+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" state=STATUS_PLAYING positionMs=871 volume=100 Oct 16 12:25:27 volumio volumio5-onboarding[1876]: time=2026-10-16T12:25:27.673+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.116:55906 @ 0x24936e0" id="mnt/USB/6A42-3373/Ayako Hosokawa - Mr. Wonderful 1987/01. Wrap Your Troubles In Dreams.flac" title="Wrap Your Troubles In Dreams" Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 69ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 69ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 69ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 68ms Oct 16 12:25:27 volumio volumio[1224]: info: ------------------------------ 67ms Oct 16 12:25:31 volumio volumio[1224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 12:25:31 volumio volumio[1224]: TypeError: Cannot read properties of null (reading 'slice') Oct 16 12:25:31 volumio volumio[1224]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Oct 16 12:25:31 volumio volumio[1224]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Oct 16 12:25:31 volumio volumio[1224]: at Object.onceWrapper (node:events:629:26) Oct 16 12:25:31 volumio volumio[1224]: at ClientRequest.emit (node:events:514:28) Oct 16 12:25:31 volumio volumio[1224]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Oct 16 12:25:31 volumio volumio[1224]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Oct 16 12:25:31 volumio volumio[1224]: at TLSSocket.socketOnData (node:_http_client:535:22) Oct 16 12:25:31 volumio volumio[1224]: at TLSSocket.emit (node:events:514:28) Oct 16 12:25:31 volumio volumio[1224]: at addChunk (node:internal/streams/readable:343:12) Oct 16 12:25:31 volumio volumio[1224]: at readableAddChunk (node:internal/streams/readable:316:9) Oct 16 12:25:31 volumio volumio[1224]: at Readable.push (node:internal/streams/readable:253:10) Oct 16 12:25:31 volumio volumio[1224]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Oct 16 12:25:31 volumio volumio[1224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 12:25:32 volumio sudo[12678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 12:24' Oct 16 12:25:32 volumio sudo[12678]: 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"