Aug 27 18:59:03 volumio bluealsa[1014]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_78_A3_35_4A_7C_CD, ...) Aug 27 18:59:04 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:04.976+02:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Aug 27 18:59:05 volumio dbus-daemon[742]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.20" (uid=0 pid=1842 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=842 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 27 18:59:05 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:05.918+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="00:00:00:00:00:00%01 @ 0x174aa50" latency=810.697902ms platform=PLATFORM_ANDROID version=6.260807.0 Aug 27 18:59:05 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 27 18:59:05 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.104+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="00:00:00:00:00:00%01 @ 0x174aa50" latency=182.236964ms timeout=20s Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.104+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" Aug 27 18:59:06 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:06 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:06 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.204+02:00 level=INFO msg="emitting device name changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" name=Volumio Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.299+02:00 level=INFO msg="emitting device language changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" language=en Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.396+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" timezone=Europe/Brussels Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.491+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" available=true connected=true macAddress=e4:5f:01:62:07:34 ip4Address=192.168.150.6/24 ip6Address= Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.600+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.100.200:59590 Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.638+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="00:00:00:00:00:00%01 @ 0x174aa50" latency=152.498594ms platform=PLATFORM_ANDROID version=6.260807.0 Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.706+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.100.200:59590 @ 0x15dbd70" latency=40.400781ms timeout=20s Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.706+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" Aug 27 18:59:06 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:06 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:06 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.710+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" name=Volumio Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.710+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" language=en Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.718+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" timezone=Europe/Brussels Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.719+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" available=true connected=true macAddress=e4:5f:01:62:07:34 ip4Address=192.168.150.6/24 ip6Address= Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.720+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.720+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" setupComplete=true Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.738+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 18:59:06 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 18:59:06 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:06.930+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" setupComplete=true Aug 27 18:59:06 volumio volumio[1235]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 27 18:59:07 volumio volumio[1235]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 27 18:59:07 volumio volumio[1235]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 27 18:59:07 volumio volumio[1235]: amixer -c 2 info | grep "vc4-hdmi-0" Aug 27 18:59:07 volumio volumio[1235]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Aug 27 18:59:07 volumio volumio[1235]: amixer -c 3 info | grep "vc4-hdmi-1" Aug 27 18:59:07 volumio volumio[1235]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Aug 27 18:59:07 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 27 18:59:07 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 27 18:59:07 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 18:59:07 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 18:59:07 volumio volumio[1235]: amixer -c 0 info | grep "bcm2835 ALSA" Aug 27 18:59:07 volumio volumio[1235]: amixer -c 1 info | grep "bcm2835 Headphones" Aug 27 18:59:07 volumio volumio[1235]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Aug 27 18:59:07 volumio volumio[1235]: amixer -c 2 info | grep "vc4-hdmi-0" Aug 27 18:59:07 volumio volumio[1235]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Aug 27 18:59:07 volumio volumio[1235]: amixer -c 3 info | grep "vc4-hdmi-1" Aug 27 18:59:08 volumio volumio[1235]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Aug 27 18:59:08 volumio volumio[1235]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Aug 27 18:59:08 volumio volumio[1235]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 27 18:59:08 volumio volumio[1235]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 27 18:59:08 volumio volumio[1235]: amixer -c 4 info | grep "Allo BOSS2" Aug 27 18:59:08 volumio volumio[1235]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Aug 27 18:59:08 volumio volumio[1235]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 27 18:59:08 volumio volumio[1235]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 27 18:59:08 volumio volumio[1235]: amixer -c 4 info | grep "Allo Boss2" Aug 27 18:59:08 volumio volumio[1235]: Card sysdefault:4 'Boss2'/'Allo Boss2' Aug 27 18:59:08 volumio volumio[1235]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Aug 27 18:59:08 volumio volumio[1235]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 27 18:59:08 volumio volumio[1235]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 27 18:59:08 volumio volumio[1235]: amixer -c 4 info | grep "Allo BOSS2" Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.484+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" selectedOutputId=4 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.485+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" selectedOutputId=4 Aug 27 18:59:08 volumio volumio[1235]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Aug 27 18:59:08 volumio volumio[1235]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 27 18:59:08 volumio volumio[1235]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 27 18:59:08 volumio volumio[1235]: amixer -c 4 info | grep "Allo Boss2" Aug 27 18:59:08 volumio volumio[1235]: Card sysdefault:4 'Boss2'/'Allo Boss2' Aug 27 18:59:08 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:08 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:08 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:08 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:08 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:08 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.573+02:00 level=INFO msg="emitting software info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" currentVersion=4.119 latestVersion=4.119 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.574+02:00 level=INFO msg="emitting software update progress event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" status=UPDATE_STATUS_NONE progress=0 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.574+02:00 level=INFO msg="emitting user changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" userId=U2UKp9cSnaU9oFNhdXKkPk95mSz2 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.574+02:00 level=INFO msg="emitting music providers changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" providers=9 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.575+02:00 level=INFO msg="emitting plugins changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" plugins=71 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.575+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" currentVersion=4.119 latestVersion=4.119 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.576+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" status=UPDATE_STATUS_NONE progress=0 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.576+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" userId=U2UKp9cSnaU9oFNhdXKkPk95mSz2 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.577+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" providers=9 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.578+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" plugins=71 Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:08 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:08 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.647+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" state=STATUS_STOPPED positionMs=0 volume=73 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.647+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" state=STATUS_STOPPED positionMs=0 volume=73 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.648+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" id="https://streams.radio.dpgmedia.cloud/redirect/willy_be_class_x/mp3?source=tunein&player=rp_external&gdpr=1&gdpr_consent=&DIST=TuneIn&TGT=TuneIn&maxServers=2&gdpr=1&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc4NzM4MTk4MSwiaXNzIjoidGlzcnYifQ.nBCMHwP6jCndPqYta5VZ2920w-UUNDT1aHf7-t6o38Q" title="Willy Class X" Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.648+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01 @ 0x174aa50" id="https://streams.radio.dpgmedia.cloud/redirect/willy_be_class_x/mp3?source=tunein&player=rp_external&gdpr=1&gdpr_consent=&DIST=TuneIn&TGT=TuneIn&maxServers=2&gdpr=1&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc4NzM4MTk4MSwiaXNzIjoidGlzcnYifQ.nBCMHwP6jCndPqYta5VZ2920w-UUNDT1aHf7-t6o38Q" title="Willy Class X" Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.649+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" state=STATUS_STOPPED positionMs=0 volume=73 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.650+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" state=STATUS_STOPPED positionMs=0 volume=73 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.656+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" id="https://streams.radio.dpgmedia.cloud/redirect/willy_be_class_x/mp3?source=tunein&player=rp_external&gdpr=1&gdpr_consent=&DIST=TuneIn&TGT=TuneIn&maxServers=2&gdpr=1&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc4NzM4MTk4MSwiaXNzIjoidGlzcnYifQ.nBCMHwP6jCndPqYta5VZ2920w-UUNDT1aHf7-t6o38Q" title="Willy Class X" Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.656+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.100.200:59590 @ 0x15dbd70" id="https://streams.radio.dpgmedia.cloud/redirect/willy_be_class_x/mp3?source=tunein&player=rp_external&gdpr=1&gdpr_consent=&DIST=TuneIn&TGT=TuneIn&maxServers=2&gdpr=1&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTc4NzM4MTk4MSwiaXNzIjoidGlzcnYifQ.nBCMHwP6jCndPqYta5VZ2920w-UUNDT1aHf7-t6o38Q" title="Willy Class X" Aug 27 18:59:08 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:08 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.686+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=41.023711ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 27 18:59:08 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:08 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.709+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.806+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=http://pushupdates.volumio.org duration=50.55821ms Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.899+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=189.376202ms Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.899+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://functions.volumio.cloud duration=187.336927ms Aug 27 18:59:08 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:08.899+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://functions.volumio.cloud duration=189.350721ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.152+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://www.googleapis.com duration=439.663058ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.154+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=443.697125ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.162+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=http://cddb.volumio.org duration=450.458737ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.162+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://securetoken.googleapis.com duration=452.067201ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.187+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=477.302519ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.233+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=522.129163ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.259+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://google.com duration=547.877717ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.335+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=https://database.volumio.cloud duration=622.523832ms Aug 27 18:59:09 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:09.376+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:59590 @ 0x174aa50" latency=39.754372ms timeout=10s endpoint=http://plugins.volumio.org duration=664.407822ms Aug 27 18:59:09 volumio sudo[2072]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 18:59:09 volumio sudo[2072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 18:59:09 volumio sudo[2074]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 18:59:09 volumio sudo[2074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 18:59:09 volumio sudo[2072]: pam_unix(sudo:session): session closed for user root Aug 27 18:59:09 volumio sudo[2074]: pam_unix(sudo:session): session closed for user root Aug 27 18:59:10 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.150.6 from 192.168.100.200 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.170 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 27 18:59:10 volumio sudo[2078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 18:59:10 volumio sudo[2078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 18:59:10 volumio sudo[2078]: pam_unix(sudo:session): session closed for user root Aug 27 18:59:10 volumio sudo[2081]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 18:59:10 volumio sudo[2081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 18:59:10 volumio sudo[2081]: pam_unix(sudo:session): session closed for user root Aug 27 18:59:10 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.150.6 from 192.168.100.200 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.170 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:10 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 18:59:10 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:10 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:10 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:10 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:10 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 18:59:10 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:59:12 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 18:59:12 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:12 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:12 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:12 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:12 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:12 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:12 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:12 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 27 18:59:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 18:59:14 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:14 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:14 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:14 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:18 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:18 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:20 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 27 18:59:28 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:28 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:28 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:28 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 18:59:29 volumio volumio[1235]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 27 18:59:29 volumio volumio[1235]: info: Received Get System Version Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 18:59:29 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:29 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:29 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:29 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:36 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:36.622+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.100.200:59590 error="read tcp 192.168.150.6:7331->192.168.100.200:59590: read: connection reset by peer" Aug 27 18:59:36 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:36.623+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.100.200:59590 Aug 27 18:59:36 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:36.623+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.100.200:59590 Aug 27 18:59:36 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.150.6 from 192.168.100.200 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.170 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 27 18:59:36 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 18:59:36 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 18:59:36 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 18:59:36 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:36 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:36 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 18:59:36 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 18:59:37 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:37 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:37 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:37 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:37 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:59:37 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.150.6 from 192.168.100.200 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.170 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 18:59:37 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:37.958+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.100.200:60764 Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 18:59:37 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:37.976+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.100.200:60764 Aug 27 18:59:37 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:37.977+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.100.200:60764 Aug 27 18:59:37 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 18:59:37 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:37.988+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.100.200:60848 Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:38 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 18:59:38 volumio volumio[1235]: info: Received Get System Info Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 18:59:38 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:38 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:38 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.021+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.026+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=4.614377ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.034+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=12.744143ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.040+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=http://pushupdates.volumio.org duration=17.790589ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.041+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=18.757967ms Aug 27 18:59:38 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.072+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://google.com duration=50.981884ms Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.133+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://securetoken.googleapis.com duration=110.836786ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.133+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://www.googleapis.com duration=111.251856ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.149+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=127.170779ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.156+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://functions.volumio.cloud duration=134.374796ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.166+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://database.volumio.cloud duration=144.629335ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.255+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=https://functions.volumio.cloud duration=233.271375ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.355+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=http://cddb.volumio.org duration=332.398916ms Aug 27 18:59:38 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:38.473+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.100.200:60848 @ 0x1872c90" latency=40.407073ms timeout=10s endpoint=http://plugins.volumio.org duration=451.566966ms Aug 27 18:59:38 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:38 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:48 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:48 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 18:59:48 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:48 volumio volumio[1235]: info: Listing playlists Aug 27 18:59:56 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:56.962+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s Aug 27 18:59:56 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:56.967+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=4.843671ms Aug 27 18:59:56 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:56.977+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=13.788189ms Aug 27 18:59:56 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:56.982+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=http://pushupdates.volumio.org duration=18.679045ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.018+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://google.com duration=55.737101ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.073+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://www.googleapis.com duration=110.560953ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.075+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://securetoken.googleapis.com duration=112.497358ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.086+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=123.46267ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.092+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=129.043241ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.095+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://functions.volumio.cloud duration=132.535408ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.099+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://functions.volumio.cloud duration=135.33473ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.104+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=https://database.volumio.cloud duration=140.252049ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.291+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=http://cddb.volumio.org duration=328.076231ms Aug 27 18:59:57 volumio volumio5-onboarding[1842]: time=2026-08-27T18:59:57.409+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.100.200:60848 @ 0x174aa50" latency=43.067789ms timeout=10s endpoint=http://plugins.volumio.org duration=445.457964ms Aug 27 18:59:58 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 18:59:58 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:00:00 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 27 19:00:04 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:00:08 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:08 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:08 volumio volumio[1235]: info: Listing playlists Aug 27 19:00:08 volumio volumio[1235]: info: Listing playlists Aug 27 19:00:13 volumio volumio[1235]: info: Received OAUTH Data Aug 27 19:00:13 volumio volumio[1235]: info: Executing Spotify Oauth Login Aug 27 19:00:13 volumio volumio[1235]: info: Saving Spotify Refresh Token Aug 27 19:00:13 volumio volumio[1235]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 27 19:00:13 volumio volumio[1235]: SPOTIFY: BQDKj67l_DmuIBNj8Xg0ZXlCwEokp8idJ1l2dzOUfNAjQv8KZsvsER8YN0CEkQnYIkzKzyxhu1eiilRrF2htTc4O3tD5gu0c8rvukb3JEvMMMcddt7Ol9TvBgeRcZ_ehyMbeH1Z_VeyXW8acgPhpqT3fHHypLewWfcH1nNKsFGqBZWmpizmkx8wpKKKFtTa6JL0zM-Sw1kqiH6pd0QN9bL88Se4k9oy5OHmE2j2JwDcGaNPdBg3A_cB7zGmRZlSU-YrIa8chpitIw9gb5b3zNHSGql7Kvr-c-XcWKjM Aug 27 19:00:13 volumio volumio[1235]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 27 19:00:13 volumio volumio[1235]: info: New Spotify access token = BQDKj67l_DmuIBNj8Xg0ZXlCwEokp8idJ1l2dzOUfNAjQv8KZsvsER8YN0CEkQnYIkzKzyxhu1eiilRrF2htTc4O3tD5gu0c8rvukb3JEvMMMcddt7Ol9TvBgeRcZ_ehyMbeH1Z_VeyXW8acgPhpqT3fHHypLewWfcH1nNKsFGqBZWmpizmkx8wpKKKFtTa6JL0zM-Sw1kqiH6pd0QN9bL88Se4k9oy5OHmE2j2JwDcGaNPdBg3A_cB7zGmRZlSU-YrIa8chpitIw9gb5b3zNHSGql7Kvr-c-XcWKjM Aug 27 19:00:13 volumio volumio[1235]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 27 19:00:13 volumio volumio[1235]: SPOTIFY: User informations: {"account_id":"BIsxrbNAG0","country":"BE","display_name":"frederiekb","email":"fberthier@protonmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/frederiekb"},"followers":{"href":null,"total":5},"href":"https://api.spotify.com/v1/users/frederiekb","id":"frederiekb","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85b8485c0718174505fae56f9f","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82b8485c0718174505fae56f9f","width":64}],"product":"premium","type":"user","uri":"spotify:user:frederiekb"} Aug 27 19:00:13 volumio volumio[1235]: info: Creating Spotify config file Aug 27 19:00:13 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 19:00:13 volumio volumio[1235]: info: Spotify config file written Aug 27 19:00:14 volumio sudo[2176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 19:00:14 volumio sudo[2176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:00:14 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 27 19:00:14 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 27 19:00:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:14 volumio go-librespot[2178]: go-librespot daemon starting... Aug 27 19:00:14 volumio volumio[1235]: info: Connection to go-librespot Websocket closed Aug 27 19:00:14 volumio sudo[2176]: pam_unix(sudo:session): session closed for user root Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=info msg="running go-librespot 0.4.0" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="app state loaded" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:00:14 volumio volumio[1235]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 27 19:00:14 volumio volumio[1235]: SPOTIFY: BQCZNSbN-ycQQiTdHfMfRuCSjaeQAb4mxONRj-yIISFoEmVyCazo56aKIHBOyRHjWW14bh_8Q_wRJljMjqoeeOZvTLAQ_YgJMjKcTBZt_1ROv1Neym78b9cPQqXyona2xm871_uy5P8V0_TQiKqmROuwsx-6VjqZadnv54QgrZ-qjp-urhnzu-NAlrw9C9A6a42hJOl7GiM-ZU9bMl12VcdpSwsOImHrieoTde8Cx4JkIqqi0axZNjZLPLBvFCvC5XD3MruzqaOXyA69o44K0s5_N6uqhhWVM49CVvo Aug 27 19:00:14 volumio volumio[1235]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 27 19:00:14 volumio volumio[1235]: info: New Spotify access token = BQCZNSbN-ycQQiTdHfMfRuCSjaeQAb4mxONRj-yIISFoEmVyCazo56aKIHBOyRHjWW14bh_8Q_wRJljMjqoeeOZvTLAQ_YgJMjKcTBZt_1ROv1Neym78b9cPQqXyona2xm871_uy5P8V0_TQiKqmROuwsx-6VjqZadnv54QgrZ-qjp-urhnzu-NAlrw9C9A6a42hJOl7GiM-ZU9bMl12VcdpSwsOImHrieoTde8Cx4JkIqqi0axZNjZLPLBvFCvC5XD3MruzqaOXyA69o44K0s5_N6uqhhWVM49CVvo Aug 27 19:00:14 volumio volumio[1235]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 27 19:00:14 volumio sudo[2188]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 27 19:00:14 volumio sudo[2188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:00:14 volumio sudo[2186]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 27 19:00:14 volumio sudo[2186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 19:00:14 volumio sudo[2188]: pam_unix(sudo:session): session closed for user root Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=info msg="zeroconf server listening on port 44555" Aug 27 19:00:14 volumio sudo[2186]: pam_unix(sudo:session): session closed for user root Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="obtained new client token: AAEQ7bOFKqPtswyllQtXZeLTfATMHTHYoDdTk13RO8x7snWeqMuei47hEn2iTt53DwA+WmxgxnrOeJ0QCPPLEbtmlIyYTv82Wr/77alhtf5px32p/nXMlBfKOruDVnov/0t/W8RLC/clyAhMlMf1QHL7qmhCMeBMyzm5BCZKQ3Cs0tkNpRk6L5iqVwb5K2bTaD/vMnDIZ831WRARIE6WPZEN4OE7esMHRBusdt2QjMLURPwm4wCww8TN/EE=" Aug 27 19:00:14 volumio volumio[1235]: verbose: New Socket.io Connection to 192.168.150.6 from 192.168.100.200 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.170 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="completed keyexchange" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=debug msg="completed challenge" Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=info msg="authenticated AP" username="fr******kb" Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 19:00:14 volumio volumio[1235]: SPOTIFY: User informations: {"account_id":"BIsxrbNAG0","country":"BE","display_name":"frederiekb","email":"fberthier@protonmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/frederiekb"},"followers":{"href":null,"total":5},"href":"https://api.spotify.com/v1/users/frederiekb","id":"frederiekb","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85b8485c0718174505fae56f9f","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82b8485c0718174505fae56f9f","width":64}],"product":"premium","type":"user","uri":"spotify:user:frederiekb"} Aug 27 19:00:14 volumio volumio[1235]: info: Spotify Successfully logged in Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 19:00:14 volumio go-librespot[2179]: time="2026-08-27T19:00:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:00:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:00:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:00:14 volumio volumio[1235]: info: [1787850014819] CoreMusicLibrary::Adding element Spotify Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:00:14 volumio volumio[1235]: Cannot find translation for source Spotify Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:14 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 27 19:00:14 volumio volumio[1235]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 27 19:00:15 volumio volumio[1235]: info: Received Get System Info Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:00:15 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:15 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:15 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:15 volumio volumio[1235]: info: Listing playlists Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:00:15 volumio volumio[1235]: info: Received Get System Info Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:00:15 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:15 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:15 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:00:16 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 27 19:00:16 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 27 19:00:16 volumio volumio[1235]: info: Received Get System Info Aug 27 19:00:16 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 27 19:00:16 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 27 19:00:16 volumio volumio[1235]: info: Discovery: Getting this device information Aug 27 19:00:16 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:16 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:16 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 27 19:00:17 volumio volumio[1235]: info: Initializing connection to go-librespot Websocket Aug 27 19:00:17 volumio volumio[1235]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:00:17 volumio volumio[1235]: info: go-librespot daemon successfully initialized Aug 27 19:00:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 19:00:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:17 volumio go-librespot[2208]: go-librespot daemon starting... Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=info msg="running go-librespot 0.4.0" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="app state loaded" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=info msg="zeroconf server listening on port 40827" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="obtained new client token: AAGcd4rZ865Su48bchV89CeQjcmAnTUh6BAkJxSXwgh+GQX62hyTTAx8xT/bAEx7vkiZCBfvt01EVY1TtYGObXDjVpQxToC3UooV//8csZ0JI57eHOlGFZDEk8txhMoIMFI3hLs/FLDIz5+zvFux/Z+mn+X0qNXIdHqKg8ky0JjU86cFzZnMHds+2q43U91j6vsVa3ZZQkNeVkiVW7zypkpZ/tF9KJ/2SH66NBmckPNIP4snyS9rUY22GdY=" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="completed keyexchange" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=debug msg="completed challenge" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=info msg="authenticated AP" username="fr******kb" Aug 27 19:00:18 volumio go-librespot[2209]: time="2026-08-27T19:00:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:00:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:00:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:00:18 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:18 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:20 volumio volumio[1235]: info: Initializing connection to go-librespot Websocket Aug 27 19:00:20 volumio volumio[1235]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:00:20 volumio volumio[1235]: info: Initializing connection to go-librespot Websocket Aug 27 19:00:20 volumio volumio[1235]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:00:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 19:00:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:21 volumio go-librespot[2217]: go-librespot daemon starting... Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=info msg="running go-librespot 0.4.0" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=debug msg="app state loaded" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=info msg="zeroconf server listening on port 39557" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=debug msg="obtained new client token: AAEhpAt5rWPNEBIbiAddf7LlFav5reTqnFTUYBjJ2K3zixylBGpXO34bJx+MahB9Pb0/L8vgSHxGEMG5cWtGdJkvDPW97WCRiIQg81wlFaqFcV+JYXdb+fJbEo52CJQolhsXz29oXTT9IZ2sCMePMKHc12V8BbnCr1c3+EGbr+bWQVCCLsDw8R+eiSgfw+VD3Dx7JKEaA/7D94BEk3lGSDMwnop49Wx1cqJwB1lSGbf2JP5ZsKqDs5dfbxc=" Aug 27 19:00:21 volumio go-librespot[2218]: time="2026-08-27T19:00:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 27 19:00:22 volumio go-librespot[2218]: time="2026-08-27T19:00:22+02:00" level=debug msg="completed keyexchange" Aug 27 19:00:22 volumio go-librespot[2218]: time="2026-08-27T19:00:22+02:00" level=debug msg="completed challenge" Aug 27 19:00:22 volumio go-librespot[2218]: time="2026-08-27T19:00:22+02:00" level=info msg="authenticated AP" username="fr******kb" Aug 27 19:00:22 volumio go-librespot[2218]: time="2026-08-27T19:00:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:00:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:00:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:00:23 volumio volumio[1235]: info: Initializing connection to go-librespot Websocket Aug 27 19:00:23 volumio volumio[1235]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:00:24 volumio volumio[1235]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 27 19:00:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 27 19:00:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:25 volumio go-librespot[2227]: go-librespot daemon starting... Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=info msg="running go-librespot 0.4.0" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="app state loaded" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=info msg="zeroconf server listening on port 44641" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="obtained new client token: AAGkQ4Y3Af+rwfAggdhCz8X5uKVkU//4Nv1Dekgz9IikCIuyttd4Sk//70AnLKJOliDND3+0RloqYb5/d/g9joQie79HwUc015l1eaeo7OLEj+M8ImOpzWFteZYmXheeJxGMCW9R08AHtiHUqpbsteeUVEL3jLC5e5UBG6EvKfiMMQQtWMHAnwI27MdUwLf9EA8mO7+XBMlfrbvl9x3a+OADmJiMZiiDG+wJ4SCDjHAoANG322gr3MEdUQQ=" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="completed keyexchange" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=debug msg="completed challenge" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=info msg="authenticated AP" username="fr******kb" Aug 27 19:00:25 volumio go-librespot[2228]: time="2026-08-27T19:00:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:00:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:00:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:00:26 volumio volumio[1235]: info: Initializing connection to go-librespot Websocket Aug 27 19:00:26 volumio volumio[1235]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:00:28 volumio volumio[1235]: info: CoreCommandRouter::volumioGetState Aug 27 19:00:28 volumio volumio[1235]: info: CorePlayQueue::getTrack 0 Aug 27 19:00:28 volumio volumio[1235]: info: Listing playlists Aug 27 19:00:28 volumio volumio[1235]: info: Listing playlists Aug 27 19:00:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 27 19:00:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:29 volumio go-librespot[2250]: go-librespot daemon starting... Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=info msg="running go-librespot 0.4.0" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="app state loaded" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:00:29 volumio volumio[1235]: info: Initializing connection to go-librespot Websocket Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="new websocket client" Aug 27 19:00:29 volumio volumio[1235]: info: Connection to go-librespot Websocket established Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=info msg="zeroconf server listening on port 37117" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="obtained new client token: AAE1Tv0pz9vu/6vJnFbwgzxOPjMmDaZjbJh4nai1qPPnHcX+ljq/jWR7aK/+z8uGjkqzXx1taLMJ4TkeOISxNe7eM29cTwphYzxPtTfO3JG6L9Lv2rU0O95WQpdsW4tz/DOdvjj9opSFBXkM8/vHnpJ9l6bUMIqLTu9JSj8BNoq321XcNAwvdHSdTVn3wAWd73xzkZ2KwyjHu0rOn/UVigkE/1mQj91Qu1a1q+urygP/XtAUNGuWUOJQhm0=" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="completed keyexchange" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=debug msg="completed challenge" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=info msg="authenticated AP" username="fr******kb" Aug 27 19:00:29 volumio go-librespot[2251]: time="2026-08-27T19:00:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:00:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:00:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:00:29 volumio volumio[1235]: info: Connection to go-librespot Websocket closed Aug 27 19:00:32 volumio volumio[1235]: info: Getting Spotify volume Aug 27 19:00:32 volumio volumio[1235]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 19:00:32 volumio volumio[1235]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 19:00:32 volumio volumio[1235]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 27 19:00:32 volumio volumio[1235]: errno: -111, Aug 27 19:00:32 volumio volumio[1235]: code: 'ECONNREFUSED', Aug 27 19:00:32 volumio volumio[1235]: syscall: 'connect', Aug 27 19:00:32 volumio volumio[1235]: address: '127.0.0.1', Aug 27 19:00:32 volumio volumio[1235]: port: 9879, Aug 27 19:00:32 volumio volumio[1235]: response: undefined Aug 27 19:00:32 volumio volumio[1235]: } Aug 27 19:00:32 volumio volumio[1235]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 19:00:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 27 19:00:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 19:00:32 volumio go-librespot[2271]: go-librespot daemon starting... Aug 27 19:00:32 volumio go-librespot[2272]: time="2026-08-27T19:00:32+02:00" level=info msg="running go-librespot 0.4.0" Aug 27 19:00:32 volumio go-librespot[2272]: time="2026-08-27T19:00:32+02:00" level=debug msg="app state loaded" Aug 27 19:00:32 volumio go-librespot[2272]: time="2026-08-27T19:00:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=info msg="zeroconf server listening on port 45923" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="obtained new client token: AAHkLKuyPZO2AwOINzPDNOSe7g2irHZQs4uzGeFxlr35LHme4ZUW7TBWfUbi8wGbIwTFaiubXb8Sqr+znRb7cDBmrn/6+S5qi3CPd3ecRcDV9q2Ytj6zu5InOyFOi+8QmGcbq7qahoeSX1qySuQUtQHVjjv26aopHIToEBBSKHXyoIjViB46a+Pqn4cPnezBIb4N//+Cwt3uvGSyl6wulJEcdZZtJzPs/i0uieZN+QHYKclFuPePfBL9" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="completed keyexchange" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=debug msg="completed challenge" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=info msg="authenticated AP" username="fr******kb" Aug 27 19:00:33 volumio go-librespot[2272]: time="2026-08-27T19:00:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 27 19:00:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 19:00:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 19:00:35 volumio sudo[2283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-27 18:59' Aug 27 19:00:35 volumio sudo[2283]: 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"