May 25 02:45:00 volumio volumio[2025]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/500GB_SSD May 25 02:45:01 volumio volumio[2025]: info: Scanning removed location : "USB/500GB_SSD" May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: MPD Database updated - AlbumList cache refreshed May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: MPD Database updated - AlbumList cache refreshed May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:01 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.367-04:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.86.99:60703 May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.544-04:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.86.99:60703 @ 0xc00007e870" latency=2.381696ms timeout=10s May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.544-04:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.544-04:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.86.99:60703 @ 0xc00007e870" latency=3.404993ms platform=PLATFORM_IOS version=5.260413.0 May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 25 02:45:27 volumio volumio[2025]: info: Received Get System Info May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:27 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.549-04:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" name=Volumio May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.550-04:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" language=en May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.551-04:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" timezone=US/Eastern May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.552-04:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" available=true connected=false macAddress= ip4Address= ip6Address= May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.557-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" available=true connected=true macAddress=28:cf:e9:0b:fd:b9 ip4Address=192.168.86.45/24 ip6Address= ssid=Nest May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.558-04:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" setupComplete=true May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 25 02:45:27 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 1 May 25 02:45:27 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:27 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 1","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 1\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:27 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 0 May 25 02:45:27 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:27 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 0","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 0\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:27 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 May 25 02:45:27 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:27 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:27 volumio volumio[2025]: amixer -c 5 info | grep "SMSL USB AUDIO" May 25 02:45:27 volumio volumio[2025]: Card sysdefault:5 'AUDIO'/'SMSL SMSL USB AUDIO at usb-0000:00:14.0-4, high speed' May 25 02:45:27 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 May 25 02:45:27 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:27 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:27 volumio volumio[2025]: amixer -c 5 info | grep "SMSL USB AUDIO" May 25 02:45:27 volumio volumio[2025]: Card sysdefault:5 'AUDIO'/'SMSL SMSL USB AUDIO at usb-0000:00:14.0-4, high speed' May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.611-04:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" selectedOutputId=5 May 25 02:45:27 volumio volumio[2025]: info: Received Get System Info May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:27 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:27 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.634-04:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" currentVersion=4.119 latestVersion=4.119 May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.635-04:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" status=UPDATE_STATUS_NONE progress=0 May 25 02:45:27 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:27.780-04:00 level=INFO msg="refreshed Firebase token" component=volumio/firebase expiry=2026-05-25T03:45:27.780-04:00 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.043-04:00 level=INFO msg="emitting user changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" userId=CMv0DZRL3USwSUyDb5SlYlvynJe2 May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.616-04:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.616-04:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.616-04:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.616-04:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory" May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.616-04:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" providers=9 May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.660-04:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.86.99:60703 @ 0xc00007e870" latency=-2.95246ms platform=PLATFORM_IOS version=5.260413.0 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.662-04:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.86.99:60703 @ 0xc00007e870" latency=-1.976082ms timeout=10s May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.662-04:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" May 25 02:45:30 volumio volumio[2025]: info: Received Get System Info May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:30 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.663-04:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" name=Volumio May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.663-04:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" language=en May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.664-04:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" timezone=US/Eastern May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.664-04:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" available=true connected=false macAddress= ip4Address= ip6Address= May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.670-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" available=true connected=true macAddress=28:cf:e9:0b:fd:b9 ip4Address=192.168.86.45/24 ip6Address= ssid=Nest May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.670-04:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" setupComplete=true May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 25 02:45:30 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 1 May 25 02:45:30 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:30 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 1","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 1\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:30 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 0 May 25 02:45:30 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:30 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 0","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 0\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:30 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 May 25 02:45:30 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:30 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:30 volumio volumio[2025]: amixer -c 5 info | grep "SMSL USB AUDIO" May 25 02:45:30 volumio volumio[2025]: Card sysdefault:5 'AUDIO'/'SMSL SMSL USB AUDIO at usb-0000:00:14.0-4, high speed' May 25 02:45:30 volumio volumio[2025]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 May 25 02:45:30 volumio volumio[2025]: /bin/sh: 1: /usr/local/bin/alsacap: not found May 25 02:45:30 volumio volumio[2025]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} May 25 02:45:30 volumio volumio[2025]: amixer -c 5 info | grep "SMSL USB AUDIO" May 25 02:45:30 volumio volumio[2025]: Card sysdefault:5 'AUDIO'/'SMSL SMSL USB AUDIO at usb-0000:00:14.0-4, high speed' May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.716-04:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" selectedOutputId=5 May 25 02:45:30 volumio volumio[2025]: info: Received Get System Info May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:30 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.762-04:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" currentVersion=4.119 latestVersion=4.119 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.762-04:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" status=UPDATE_STATUS_NONE progress=0 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.762-04:00 level=INFO msg="emitting user changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" userId=CMv0DZRL3USwSUyDb5SlYlvynJe2 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.762-04:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" providers=9 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.930-04:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" plugins=48 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.930-04:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" plugins=48 May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:30 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.934-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" state=STATUS_PAUSED positionMs=40937 volume=100 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.934-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" id= title=Masques May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.934-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" state=STATUS_PAUSED positionMs=40937 volume=100 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.934-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" id= title=Masques May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.934-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" state=STATUS_PAUSED positionMs=40937 volume=100 May 25 02:45:30 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:30.934-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.86.99:60703 @ 0xc00007e870" id= title=Masques May 25 02:45:31 volumio volumio5-onboarding[2137]: time=2026-05-25T02:45:31.062-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.86.99:60703 @ 0xc00007e870" latency=-2.007796ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE May 25 02:45:31 volumio volumio[2025]: info: [squeezelite_mc] Proxy request for Kenneth's Mac mini, URL: http://192.168.86.174:9000/music/current/cover.jpg?player=28%3Acf%3Ae9%3A0b%3Afd%3Ab9&ms=1779671449177 May 25 02:45:33 volumio sudo[65991]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 25 02:45:33 volumio sudo[65991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 02:45:33 volumio sudo[65991]: pam_unix(sudo:session): session closed for user root May 25 02:45:33 volumio sudo[65993]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 25 02:45:33 volumio sudo[65993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 02:45:33 volumio sudo[65993]: pam_unix(sudo:session): session closed for user root May 25 02:45:33 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:33 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:33 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:33 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:33 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:33 volumio volumio[2025]: verbose: New Socket.io Connection to 192.168.86.45:3000 from 192.168.86.99 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 May 25 02:45:33 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 25 02:45:33 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 25 02:45:33 volumio volumio[2025]: verbose: New Socket.io Connection to 192.168.86.45 from 192.168.86.99 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 6 May 25 02:45:33 volumio bluealsa[1055]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_71_24_84_A1_DE_2A, ...) May 25 02:45:33 volumio rfkill[65999]: unblock set for type bluetooth May 25 02:45:34 volumio sudo[66002]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 25 02:45:34 volumio sudo[66002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 02:45:34 volumio sudo[66004]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 25 02:45:34 volumio sudo[66004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 02:45:34 volumio sudo[66002]: pam_unix(sudo:session): session closed for user root May 25 02:45:34 volumio sudo[66004]: pam_unix(sudo:session): session closed for user root May 25 02:45:34 volumio volumio[2025]: verbose: New Socket.io Connection to 192.168.86.45 from 192.168.86.99 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 7 May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::volumioGetVisibleSources May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 25 02:45:34 volumio volumio[2025]: info: Received Get System Info May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:34 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:34 volumio volumio[2025]: info: Listing playlists May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 25 02:45:34 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 25 02:45:35 volumio volumio[2025]: info: [squeezelite_mc] Proxy request for Kenneth's Mac mini, URL: http://192.168.86.174:9000/music/current/cover.jpg?player=28%3Acf%3Ae9%3A0b%3Afd%3Ab9&ms=1779671449177 May 25 02:45:35 volumio volumio[2025]: error: [squeezelite_mc] Proxy: invalid URL (http%3A%2F%2F192.168.86.174%3A9000%2Fmusic%2Fcurrent%2Fcover.jpg%3Fplayer%3D28%253Acf%253Ae9%253A0b%253Afd%253Ab9%26ms%3D1779671449177) May 25 02:45:35 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:35 volumio rfkill[66010]: unblock set for type bluetooth May 25 02:45:36 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 02:45:36 volumio volumio[2025]: info: Received Get System Info May 25 02:45:36 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:36 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:36 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:36 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:36 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:36 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 25 02:45:37 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 02:45:37 volumio volumio[2025]: info: Received Get System Info May 25 02:45:37 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:37 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:37 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:37 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:37 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:40 volumio rfkill[66032]: unblock set for type bluetooth May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 02:45:42 volumio volumio[2025]: info: Retrieving Cloud Streaming UI May 25 02:45:42 volumio volumio[2025]: info: Getting Tidal Cloud Configuration May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 02:45:42 volumio volumio[2025]: info: Getting Qobuz Cloud Configuration May 25 02:45:42 volumio volumio[2025]: info: Asking plugin for UI Config May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 02:45:42 volumio volumio[2025]: info: Getting Spotify Cloud Configuration May 25 02:45:42 volumio volumio[2025]: info: Asking plugin for UI Config May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 02:45:42 volumio volumio[2025]: info: Saving Spotify Acccount May 25 02:45:42 volumio volumio[2025]: info: Got Tidal Cloud Configuration May 25 02:45:42 volumio volumio[2025]: info: Got it May 25 02:45:42 volumio volumio[2025]: info: Got it May 25 02:45:42 volumio volumio[2025]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 02:45:42 volumio volumio[2025]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::volumioGetBrowseSources May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::volumioGetBrowseSources May 25 02:45:42 volumio volumio[2025]: info: CoreCommandRouter::volumioGetBrowseSources May 25 02:45:43 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:45:43 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 25 02:45:44 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 25 02:45:46 volumio rfkill[66043]: unblock set for type bluetooth May 25 02:45:47 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:45:48 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb May 25 02:45:48 volumio volumio[2025]: verbose: ControllerMpd::sendMpdCommand rescan May 25 02:45:48 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:48 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:48 volumio volumio[2025]: info: sendMpdCommand rescan took 2 milliseconds May 25 02:45:48 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:48 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:49 volumio rfkill[66064]: unblock set for type bluetooth May 25 02:45:51 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:45:51 volumio rfkill[66068]: unblock set for type bluetooth May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 25 02:45:53 volumio volumio[2025]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 25 02:45:53 volumio volumio[2025]: info: Received Get System Version May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 25 02:45:53 volumio volumio[2025]: info: Received Get System Info May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 02:45:53 volumio volumio[2025]: info: Discovery: Getting this device information May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:45:53 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 02:45:55 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:45:55 volumio rfkill[66074]: unblock set for type bluetooth May 25 02:45:55 volumio volumio[2025]: info: MPD Database updated - AlbumList cache refreshed May 25 02:45:55 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:55 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:55 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:55 volumio volumio[2025]: info: MPD Database updated - AlbumList cache refreshed May 25 02:45:55 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:55 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:55 volumio volumio[2025]: info: Ignoring MPD Status Update May 25 02:45:57 volumio rfkill[66091]: unblock set for type bluetooth May 25 02:45:59 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:46:02 volumio rfkill[66104]: unblock set for type bluetooth May 25 02:46:03 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:46:07 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:46:08 volumio rfkill[66126]: unblock set for type bluetooth May 25 02:46:11 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:46:15 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 25 02:46:17 volumio rfkill[66142]: unblock set for type bluetooth May 25 02:46:19 volumio volumio[2025]: info: CoreCommandRouter::volumioGetState May 25 02:46:22 volumio volumio[2025]: info: CoreCommandRouter::volumioGetQueue May 25 02:46:22 volumio volumio[2025]: info: CoreStateMachine::getQueue May 25 02:46:22 volumio volumio[2025]: info: CorePlayQueue::getQueue May 25 02:46:23 volumio volumio[2025]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 25 02:46:23 volumio volumio[2025]: info: CURURI: artists:// May 25 02:46:23 volumio volumio[2025]: info: Preload queue cleared May 25 02:46:48 volumio bluealsa[1055]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_71_24_84_A1_DE_2A, ...) May 25 02:46:51 volumio volumio[2025]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 02:46:51 volumio volumio[2025]: TypeError: Cannot read properties of null (reading 'slice') May 25 02:46:51 volumio volumio[2025]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) May 25 02:46:51 volumio volumio[2025]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) May 25 02:46:51 volumio volumio[2025]: at Object.onceWrapper (node:events:629:26) May 25 02:46:51 volumio volumio[2025]: at ClientRequest.emit (node:events:514:28) May 25 02:46:51 volumio volumio[2025]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) May 25 02:46:51 volumio volumio[2025]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) May 25 02:46:51 volumio volumio[2025]: at TLSSocket.socketOnData (node:_http_client:535:22) May 25 02:46:51 volumio volumio[2025]: at TLSSocket.emit (node:events:514:28) May 25 02:46:51 volumio volumio[2025]: at addChunk (node:internal/streams/readable:343:12) May 25 02:46:51 volumio volumio[2025]: at readableAddChunk (node:internal/streams/readable:316:9) May 25 02:46:51 volumio volumio[2025]: at Readable.push (node:internal/streams/readable:253:10) May 25 02:46:51 volumio volumio[2025]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) May 25 02:46:51 volumio volumio[2025]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 02:46:51 volumio sudo[66259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-25 02:45' May 25 02:46:51 volumio sudo[66259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"