Aug 31 09:14:05 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:14:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:14:05 keuken volumio[8690]: info: Listing playlists Aug 31 09:14:05 keuken volumio[8690]: info: Listing playlists Aug 31 09:14:15 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:14:15 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:14:25 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:14:25 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:14:25 keuken volumio[8690]: info: Listing playlists Aug 31 09:14:25 keuken volumio[8690]: info: Listing playlists Aug 31 09:14:33 keuken systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 31 09:14:35 keuken systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 09:14:35 keuken systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 09:14:35 keuken systemd[1]: setdatetime-helper.service: Consumed 1.055s CPU time. Aug 31 09:14:35 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:14:35 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:14:45 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:14:45 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:14:45 keuken volumio[8690]: info: Listing playlists Aug 31 09:14:45 keuken volumio[8690]: info: Listing playlists Aug 31 09:14:55 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:14:55 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.231+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.2.222:63519 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.320+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.002768ms platform=PLATFORM_IOS version=6.260807.0 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.320+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.222:63519 @ 0x2e7a030" latency=-103.53553ms timeout=20s Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.320+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" Aug 31 09:15:01 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:01 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:01 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.325+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" name=Keuken Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.326+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" language=nl Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.329+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" timezone=Europe/Amsterdam Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.331+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" available=true connected=true macAddress=b8:27:eb:b2:d8:f6 ip4Address=192.168.2.158/24 ip6Address= Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.333+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.333+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" setupComplete=true Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.334+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.222:63519 @ 0x2e7a030" latency=-103.512344ms timeout=20s Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.334+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 09:15:01 keuken volumio[8690]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 31 09:15:01 keuken volumio[8690]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 31 09:15:01 keuken volumio[8690]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 31 09:15:01 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:01 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:01 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.453+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" name=Keuken Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.455+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" language=nl Aug 31 09:15:01 keuken volumio[8690]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Aug 31 09:15:01 keuken volumio[8690]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 09:15:01 keuken volumio[8690]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\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)"} Aug 31 09:15:01 keuken volumio[8690]: amixer -c 2 info | grep "vc4-hdmi" Aug 31 09:15:01 keuken volumio[8690]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Aug 31 09:15:01 keuken volumio[8690]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 09:15:01 keuken volumio[8690]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 09:15:01 keuken volumio[8690]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 31 09:15:01 keuken volumio[8690]: amixer -c 3 info | grep "HiFiBerry Digi" Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.512+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" timezone=Europe/Amsterdam Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.515+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" available=true connected=true macAddress=b8:27:eb:b2:d8:f6 ip4Address=192.168.2.158/24 ip6Address= Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.518+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 31 09:15:01 keuken volumio[8690]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 09:15:01 keuken volumio[8690]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 09:15:01 keuken volumio[8690]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 31 09:15:01 keuken volumio[8690]: amixer -c 3 info | grep "snd_rpi_hifiberry_digi" Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.520+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" setupComplete=true Aug 31 09:15:01 keuken volumio[8690]: Card sysdefault:3 'sndrpihifiberry'/'snd_rpi_hifiberry_digi' Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.553+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" selectedOutputId=3 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.553+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" selectedOutputId=3 Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 09:15:01 keuken volumio[8690]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 31 09:15:01 keuken volumio[8690]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 31 09:15:01 keuken volumio[8690]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 31 09:15:01 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:01 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:01 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:01 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:01 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:01 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:01 keuken volumio[8690]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Aug 31 09:15:01 keuken volumio[8690]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 09:15:01 keuken volumio[8690]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\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)"} Aug 31 09:15:01 keuken volumio[8690]: amixer -c 2 info | grep "vc4-hdmi" Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.673+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" currentVersion=4.119 latestVersion=4.119 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.673+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" currentVersion=4.119 latestVersion=4.119 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.673+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" status=UPDATE_STATUS_NONE progress=0 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.673+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" status=UPDATE_STATUS_NONE progress=0 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.673+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" userId= Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.674+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" userId= Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.674+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" providers=3 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.674+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" providers=3 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.674+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" plugins=70 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.675+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" plugins=70 Aug 31 09:15:01 keuken volumio[8690]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Aug 31 09:15:01 keuken volumio[8690]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 09:15:01 keuken volumio[8690]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 09:15:01 keuken volumio[8690]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 31 09:15:01 keuken volumio[8690]: amixer -c 3 info | grep "HiFiBerry Digi" Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:01 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:01 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:01 keuken volumio[8690]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 3 Aug 31 09:15:01 keuken volumio[8690]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 31 09:15:01 keuken volumio[8690]: {"cmd":"/usr/local/bin/alsacap -C 3","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 3\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 31 09:15:01 keuken volumio[8690]: amixer -c 3 info | grep "snd_rpi_hifiberry_digi" Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.729+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_STOPPED positionMs=254 volume=46 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.730+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1" Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.730+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_STOPPED positionMs=254 volume=46 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.730+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1" Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.730+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_STOPPED positionMs=254 volume=46 Aug 31 09:15:01 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:01.731+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1" Aug 31 09:15:01 keuken volumio[8690]: Card sysdefault:3 'sndrpihifiberry'/'snd_rpi_hifiberry_digi' Aug 31 09:15:02 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:02.670+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.2.222:63519 @ 0x2e7a030" latency=-105.219965ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 31 09:15:02 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:02.682+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s Aug 31 09:15:02 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:02.878+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://www.googleapis.com duration=193.718981ms Aug 31 09:15:02 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:02 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:02 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:02 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:02 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:02 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:02 keuken volumio[8690]: verbose: New Socket.io Connection to 192.168.2.158:3000 from 192.168.2.222 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Aug 31 09:15:02 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 09:15:02 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 09:15:03 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:03.199+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://database.volumio.cloud duration=514.199861ms Aug 31 09:15:03 keuken sudo[3539]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 09:15:03 keuken sudo[3539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 09:15:03 keuken sudo[3539]: pam_unix(sudo:session): session closed for user root Aug 31 09:15:03 keuken sudo[3541]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 09:15:03 keuken sudo[3541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 09:15:03 keuken sudo[3541]: pam_unix(sudo:session): session closed for user root Aug 31 09:15:03 keuken volumio[8690]: verbose: New Socket.io Connection to 192.168.2.158 from 192.168.2.222 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Aug 31 09:15:03 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 09:15:03 keuken sudo[3545]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 09:15:03 keuken sudo[3545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 09:15:03 keuken sudo[3545]: pam_unix(sudo:session): session closed for user root Aug 31 09:15:03 keuken sudo[3547]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 09:15:03 keuken sudo[3547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 09:15:03 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 09:15:03 keuken sudo[3547]: pam_unix(sudo:session): session closed for user root Aug 31 09:15:03 keuken volumio[8690]: verbose: New Socket.io Connection to 192.168.2.158 from 192.168.2.222 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:04 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 31 09:15:04 keuken volumio[8690]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 31 09:15:04 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:04 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:04 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:04 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:04 keuken volumio[8690]: info: Listing playlists Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 09:15:04 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPlay Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::play index undefined Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 09:15:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::startPlaybackTimer Aug 31 09:15:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 09:15:05 keuken volumio[8690]: info: [1788160505070] ControllerWebradio::clearAddPlayTrack Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand stop took 1 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces system playlist update Aug 31 09:15:05 keuken volumio[8690]: info: Ignoring MPD Status Update Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand clear took 4 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand load "http://icecast.omroep.nl/radio1-bb-mp3" Aug 31 09:15:05 keuken volumio[8690]: error: updateQueue error: null Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 10ms Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand add "http://icecast.omroep.nl/radio1-bb-mp3" Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand add "http://icecast.omroep.nl/radio1-bb-mp3" took 0 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand play Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces system playlist update Aug 31 09:15:05 keuken volumio[8690]: info: Ignoring MPD Status Update Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand play took 3 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 3ms Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces state update: player Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 15 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces state update: player Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 18 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces system playlist update Aug 31 09:15:05 keuken volumio[8690]: info: Ignoring MPD Status Update Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces state update: player Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 7 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces system playlist update Aug 31 09:15:05 keuken volumio[8690]: info: Ignoring MPD Status Update Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: info: Aug 31 09:15:05 keuken volumio[8690]: ---------------------------- MPD announces state update: player Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 9 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 8 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 6 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 7ms Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 4 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::servicePushState Aug 31 09:15:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:05 keuken volumio[8690]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"NPO Radio 1 - NOS Radio 1 Journaal - NOS","artist":"NPO Radio1","album":null,"uri":"http://icecast.omroep.nl/radio1-bb-mp3","trackType":""} Aug 31 09:15:05 keuken volumio[8690]: verbose: CURRENT POSITION 0 Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState stateService play Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState currentStatus stop Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 32ms Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 9 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 7 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 8ms Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand status took 6 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::servicePushState Aug 31 09:15:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:05 keuken volumio[8690]: verbose: STATE SERVICE {"status":"play","position":0,"seek":993,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"NPO Radio 1 - NOS Radio 1 Journaal - NOS","artist":"NPO Radio1","album":null,"uri":"http://icecast.omroep.nl/radio1-bb-mp3","trackType":""} Aug 31 09:15:05 keuken volumio[8690]: verbose: CURRENT POSITION 0 Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState stateService play Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState currentStatus play Aug 31 09:15:05 keuken volumio[8690]: info: Received an update from plugin. extracting info from payload Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::servicePushState Aug 31 09:15:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:05 keuken volumio[8690]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1235,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"NPO Radio 1 - NOS Radio 1 Journaal - NOS","artist":"NPO Radio1","album":null,"uri":"http://icecast.omroep.nl/radio1-bb-mp3","trackType":""} Aug 31 09:15:05 keuken volumio[8690]: verbose: CURRENT POSITION 0 Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState stateService play Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState currentStatus play Aug 31 09:15:05 keuken volumio[8690]: info: Received an update from plugin. extracting info from payload Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.239+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=0 volume=46 Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.240+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.242+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=0 volume=46 Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.243+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.245+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=0 volume=46 Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.246+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=0 volume=46 Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.246+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.246+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 84ms Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 78ms Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 68 milliseconds Aug 31 09:15:05 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 68 milliseconds Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:05 keuken volumio[8690]: info: ControllerMpd::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::servicePushState Aug 31 09:15:05 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:05 keuken volumio[8690]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1235,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"NPO Radio 1 - NOS Radio 1 Journaal - NOS","artist":"NPO Radio1","album":null,"uri":"http://icecast.omroep.nl/radio1-bb-mp3","trackType":""} Aug 31 09:15:05 keuken volumio[8690]: verbose: CURRENT POSITION 0 Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState stateService play Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::syncState currentStatus play Aug 31 09:15:05 keuken volumio[8690]: info: Received an update from plugin. extracting info from payload Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:05 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:05 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.281+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=0 volume=46 Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.282+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=0 volume=46 Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.282+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:05 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:05.283+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:05 keuken volumio[8690]: info: ------------------------------ 102ms Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:05 keuken volumio[8690]: info: Listing playlists Aug 31 09:15:05 keuken volumio[8690]: info: Listing playlists Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 09:15:05 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:05 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:05 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:06 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 09:15:06 keuken volumio[8690]: info: Received Get System Info Aug 31 09:15:06 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 09:15:06 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 09:15:06 keuken volumio[8690]: info: Discovery: Getting this device information Aug 31 09:15:06 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:06 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 09:15:07 keuken volumio[8690]: info: CoreCommandRouter::volumioGetQueue Aug 31 09:15:07 keuken volumio[8690]: info: CoreStateMachine::getQueue Aug 31 09:15:07 keuken volumio[8690]: info: CorePlayQueue::getQueue Aug 31 09:15:07 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:07.732+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=http://pushupdates.volumio.org duration=5.048846863s Aug 31 09:15:07 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:07.797+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=5.11444291s Aug 31 09:15:07 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:07.912+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://google.com duration=5.22760287s Aug 31 09:15:07 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:07.921+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://securetoken.googleapis.com duration=5.2360355s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.002+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://functions.volumio.cloud duration=5.318411234s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.013+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://functions.volumio.cloud duration=5.328668962s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.017+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=5.332056661s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.021+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=5.336521803s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.023+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=5.340330489s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.036+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=http://cddb.volumio.org duration=5.352658732s Aug 31 09:15:08 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:08.262+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.222:63519 @ 0x2e7a030" latency=-104.449242ms timeout=10s endpoint=http://plugins.volumio.org duration=5.578531467s Aug 31 09:15:10 keuken volumio[8690]: info: Aug 31 09:15:10 keuken volumio[8690]: ---------------------------- Client requests Volume 30 Aug 31 09:15:10 keuken volumio[8690]: info: VolumeController::SetAlsaVolume30 Aug 31 09:15:10 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:10 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 09:15:10 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:10 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:10 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:10 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:10.879+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_PLAYING positionMs=5780 volume=30 Aug 31 09:15:10 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:10.879+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1 - NOS Radio 1 Journaal - NOS" Aug 31 09:15:10 keuken volumio[8690]: info: Setting Spotify Volume from Volumio: 30 Aug 31 09:15:10 keuken volumio[8690]: info: CoreCommandRouter::volumioGetState Aug 31 09:15:12 keuken volumio[8690]: info: Sending Spotify command with payload to local API: /player/volume Aug 31 09:15:13 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 31 09:15:14 keuken volumio[8690]: info: Preload queue cleared Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::ClearQueue Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::stop Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::stPlaybackTimer Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::updateTrackBlock Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::getTrackBlock Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::pushState Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::volumioPushState Aug 31 09:15:14 keuken volumio[8690]: info: MRS: Pushing multiroomSync output update for this device Aug 31 09:15:14 keuken volumio[8690]: info: MRS: Pushing multiroomSync output Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::serviceStop Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::serviceStop Aug 31 09:15:14 keuken volumio[8690]: info: [1788160514932] ControllerWebradio::stop Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::clearPlayQueue Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::saveQueue Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::volumioPushQueue Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::addQueueItems Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::addQueueItems Aug 31 09:15:14 keuken volumio[8690]: info: Preload queue cleared Aug 31 09:15:14 keuken volumio[8690]: info: Adding Item to queue: http://stream.radioparadise.com/mellow-flacm Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Aug 31 09:15:14 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:14.943+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" state=STATUS_STOPPED positionMs=0 volume=30 Aug 31 09:15:14 keuken volumio5-onboarding[1357]: time=2026-08-31T09:15:14.944+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.222:63519 @ 0x2e7a030" id=http://icecast.omroep.nl/radio1-bb-mp3 title="NPO Radio 1" Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::volumioPushQueue Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::saveQueue Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::updateTrackBlock Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::getTrackBlock Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::volumioPlay Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::play index 0 Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::stop Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::play index undefined Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:14 keuken volumio[8690]: info: CoreStateMachine::startPlaybackTimer Aug 31 09:15:14 keuken volumio[8690]: info: CorePlayQueue::getTrack 0 Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 09:15:14 keuken volumio[8690]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 09:15:14 keuken volumio[8690]: info: [1788160514956] ControllerWebradio::clearAddPlayTrack Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 09:15:14 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:14 keuken volumio[8690]: info: Aug 31 09:15:14 keuken volumio[8690]: ---------------------------- MPD announces state update: player Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand stop took 33 milliseconds Aug 31 09:15:14 keuken volumio[8690]: info: ControllerMpd::getState Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand status Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand stop took 10 milliseconds Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 09:15:14 keuken volumio[8690]: info: Aug 31 09:15:14 keuken volumio[8690]: ---------------------------- MPD announces system playlist update Aug 31 09:15:14 keuken volumio[8690]: info: Ignoring MPD Status Update Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand status took 6 milliseconds Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand status took 5 milliseconds Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand clear took 5 milliseconds Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::parseState Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::sendMpdCommand load "http://stream.radioparadise.com/mellow-flacm" Aug 31 09:15:14 keuken volumio[8690]: error: updateQueue error: null Aug 31 09:15:14 keuken volumio[8690]: info: ------------------------------ 4ms Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 09:15:14 keuken volumio[8690]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:14 keuken volumio[8690]: verbose: ControllerMpd::parseTrackInfo Aug 31 09:15:14 keuken volumio[8690]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 09:15:14 keuken volumio[8690]: info: ------------------------------ 11ms Aug 31 09:15:14 keuken volumio[8690]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 09:15:14 keuken volumio[8690]: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 09:15:14 keuken volumio[8690]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) Aug 31 09:15:14 keuken volumio[8690]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 31 09:15:14 keuken volumio[8690]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 31 09:15:14 keuken volumio[8690]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 09:15:15 keuken sudo[3606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 09:14' Aug 31 09:15:15 keuken sudo[3606]: 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"