Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.407+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.2.170:45404 Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.441+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.170:45404 @ 0x3000870" latency=66.347601ms timeout=20s Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.441+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.441+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.2.170:45404 @ 0x3000870" latency=67.202822ms platform=PLATFORM_ANDROID version=6.260807.0 Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 15:29:31 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:31 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.443+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" name=SalonVolumio Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.446+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" language=pl Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.447+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" timezone=Europe/Warsaw Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.447+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" available=true connected=true macAddress=2c:cf:67:fc:27:f1 ip4Address=192.168.2.136/24 ip6Address= Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.448+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.448+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" setupComplete=true Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 26 15:29:31 salonvolumio volumio[1372]: amixer -c 0 info | grep "vc4-hdmi-0" Aug 26 15:29:31 salonvolumio volumio[1372]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Aug 26 15:29:31 salonvolumio volumio[1372]: amixer -c 1 info | grep "vc4-hdmi-1" Aug 26 15:29:31 salonvolumio volumio[1372]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Aug 26 15:29:31 salonvolumio volumio[1372]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 26 15:29:31 salonvolumio volumio[1372]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 26 15:29:31 salonvolumio volumio[1372]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 26 15:29:31 salonvolumio volumio[1372]: amixer -c 5 info | grep "Tone2 Pro" Aug 26 15:29:31 salonvolumio volumio[1372]: Card sysdefault:5 'Pro'/'Khadas Tone2 Pro at usb-xhci-hcd.0-1, high speed' Aug 26 15:29:31 salonvolumio volumio[1372]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 26 15:29:31 salonvolumio volumio[1372]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 26 15:29:31 salonvolumio volumio[1372]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 26 15:29:31 salonvolumio volumio[1372]: amixer -c 5 info | grep "Tone2 Pro" Aug 26 15:29:31 salonvolumio volumio[1372]: Card sysdefault:5 'Pro'/'Khadas Tone2 Pro at usb-xhci-hcd.0-1, high speed' Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.507+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" selectedOutputId=5 Aug 26 15:29:31 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:31 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.528+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" currentVersion=4.119 latestVersion=4.119 Aug 26 15:29:31 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:31.528+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.170:45404 @ 0x3000870" status=UPDATE_STATUS_NONE progress=0 Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:31 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:31 salonvolumio volumio[1372]: verbose: New Socket.io Connection to 192.168.2.136:3000 from 192.168.2.170 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 15:29:31 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.325+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=ErAYZlcHlgSLwDBbAvsqX7W6wkB2 tokenExpiry=2026-08-26T16:29:32.325+02:00 Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.545+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.2.170:45404 @ 0x3000870" latency=64.091139ms platform=PLATFORM_ANDROID version=6.260807.0 Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.548+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.170:45404 @ 0x3000870" latency=65.301956ms timeout=20s Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.548+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" Aug 26 15:29:32 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:32 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.549+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" name=SalonVolumio Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.550+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" language=pl Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.550+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" timezone=Europe/Warsaw Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.551+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" available=true connected=true macAddress=2c:cf:67:fc:27:f1 ip4Address=192.168.2.136/24 ip6Address= Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.551+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.551+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" setupComplete=true Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 26 15:29:32 salonvolumio volumio[1372]: amixer -c 0 info | grep "vc4-hdmi-0" Aug 26 15:29:32 salonvolumio volumio[1372]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Aug 26 15:29:32 salonvolumio volumio[1372]: amixer -c 1 info | grep "vc4-hdmi-1" Aug 26 15:29:32 salonvolumio volumio[1372]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Aug 26 15:29:32 salonvolumio volumio[1372]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 26 15:29:32 salonvolumio volumio[1372]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 26 15:29:32 salonvolumio volumio[1372]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 26 15:29:32 salonvolumio volumio[1372]: amixer -c 5 info | grep "Tone2 Pro" Aug 26 15:29:32 salonvolumio volumio[1372]: Card sysdefault:5 'Pro'/'Khadas Tone2 Pro at usb-xhci-hcd.0-1, high speed' Aug 26 15:29:32 salonvolumio volumio[1372]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 26 15:29:32 salonvolumio volumio[1372]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 26 15:29:32 salonvolumio volumio[1372]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Aug 26 15:29:32 salonvolumio volumio[1372]: amixer -c 5 info | grep "Tone2 Pro" Aug 26 15:29:32 salonvolumio volumio[1372]: Card sysdefault:5 'Pro'/'Khadas Tone2 Pro at usb-xhci-hcd.0-1, high speed' Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.612+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" selectedOutputId=5 Aug 26 15:29:32 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:32 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:32 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.629+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" currentVersion=4.119 latestVersion=4.119 Aug 26 15:29:32 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:32.629+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.170:45404 @ 0x3000870" status=UPDATE_STATUS_NONE progress=0 Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.056+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" userId=ErAYZlcHlgSLwDBbAvsqX7W6wkB2 Aug 26 15:29:33 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:33 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:33 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.318+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" userId=ErAYZlcHlgSLwDBbAvsqX7W6wkB2 Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.989+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.989+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.989+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.989+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" providers=9 Aug 26 15:29:33 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:33.990+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" providers=9 Aug 26 15:29:33 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:33 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:33 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.301+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" plugins=71 Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.302+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" plugins=71 Aug 26 15:29:34 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.303+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" state=STATUS_PAUSED positionMs=64000 volume=20 Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.303+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" state=STATUS_PAUSED positionMs=64000 volume=20 Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.303+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" id=spotify:track:4ue5TY2La1qXd74vw2Td2e title="POŻYCZONY CZAS" Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.303+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" id=spotify:track:4ue5TY2La1qXd74vw2Td2e title="POŻYCZONY CZAS" Aug 26 15:29:34 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.304+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" state=STATUS_PAUSED positionMs=64000 volume=20 Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.304+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.170:45404 @ 0x3000870" id=spotify:track:4ue5TY2La1qXd74vw2Td2e title="POŻYCZONY CZAS" Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.364+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.2.170:45404 @ 0x3000870" latency=63.901203ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.377+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.469+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=http://pushupdates.volumio.org duration=90.852612ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.501+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=124.056477ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.520+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=141.542127ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.528+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://functions.volumio.cloud duration=150.986671ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.530+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://functions.volumio.cloud duration=152.054233ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.579+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://www.googleapis.com duration=202.003023ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.601+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://securetoken.googleapis.com duration=223.363791ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.650+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=272.218629ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.658+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=279.970883ms Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.757+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://database.volumio.cloud duration=379.990424ms Aug 26 15:29:34 salonvolumio sudo[23337]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 15:29:34 salonvolumio sudo[23337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:29:34 salonvolumio sudo[23337]: pam_unix(sudo:session): session closed for user root Aug 26 15:29:34 salonvolumio sudo[23339]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:29:34 salonvolumio sudo[23339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:29:34 salonvolumio sudo[23339]: pam_unix(sudo:session): session closed for user root Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.875+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=http://cddb.volumio.org duration=497.368376ms Aug 26 15:29:34 salonvolumio volumio[1372]: verbose: New Socket.io Connection to 192.168.2.136 from 192.168.2.170 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 26 15:29:34 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:34.916+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=https://google.com duration=538.776146ms Aug 26 15:29:34 salonvolumio sudo[23343]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 15:29:34 salonvolumio sudo[23343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:29:34 salonvolumio sudo[23343]: pam_unix(sudo:session): session closed for user root Aug 26 15:29:34 salonvolumio sudo[23345]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:29:34 salonvolumio sudo[23345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:29:34 salonvolumio sudo[23345]: pam_unix(sudo:session): session closed for user root Aug 26 15:29:34 salonvolumio volumio[1372]: verbose: New Socket.io Connection to 192.168.2.136 from 192.168.2.170 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 15:29:35 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:35.078+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404 @ 0x3000870" latency=64.35747ms timeout=10s endpoint=http://plugins.volumio.org duration=700.994483ms Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 15:29:35 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:35 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:35 salonvolumio volumio[1372]: info: Listing playlists Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:29:35 salonvolumio volumio[1372]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 15:29:36 salonvolumio bluealsa[1127]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_5F_F5_14_C8_16_63, ...) Aug 26 15:29:36 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 26 15:29:36 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:36 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:36 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:36 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:36 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:36 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:36 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:37 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioVolatilePlay Aug 26 15:29:37 salonvolumio volumio[1372]: info: CoreStateMachine::volatilePlay Aug 26 15:29:37 salonvolumio volumio[1372]: info: Spotify Play Aug 26 15:29:37 salonvolumio volumio[1372]: info: Sending Spotify command to local API: /player/resume Aug 26 15:29:38 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:38.056+02:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Aug 26 15:29:38 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:38 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:38 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:38 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:38 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:38 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:38 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:38 salonvolumio dbus-daemon[1002]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.14" (uid=0 pid=1624 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.0" (uid=0 pid=1001 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Aug 26 15:29:40 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioVolatilePlay Aug 26 15:29:40 salonvolumio volumio[1372]: info: CoreStateMachine::volatilePlay Aug 26 15:29:40 salonvolumio volumio[1372]: info: Spotify Play Aug 26 15:29:40 salonvolumio volumio[1372]: info: Sending Spotify command to local API: /player/resume Aug 26 15:29:44 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 26 15:29:46 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioVolatilePlay Aug 26 15:29:46 salonvolumio volumio[1372]: info: CoreStateMachine::volatilePlay Aug 26 15:29:46 salonvolumio volumio[1372]: info: Spotify Play Aug 26 15:29:46 salonvolumio volumio[1372]: info: Sending Spotify command to local API: /player/resume Aug 26 15:29:50 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioVolatilePlay Aug 26 15:29:50 salonvolumio volumio[1372]: info: CoreStateMachine::volatilePlay Aug 26 15:29:50 salonvolumio volumio[1372]: info: Spotify Play Aug 26 15:29:50 salonvolumio volumio[1372]: info: Sending Spotify command to local API: /player/resume Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:29:53 salonvolumio volumio[1372]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 26 15:29:53 salonvolumio volumio[1372]: info: Received Get System Version Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 15:29:53 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:53 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.525+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.546+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=21.281731ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.549+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=http://pushupdates.volumio.org duration=23.8311ms Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:29:53 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.564+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=38.147379ms Aug 26 15:29:53 salonvolumio volumio[1372]: verbose: New Socket.io Connection to 192.168.2.136:3000 from 192.168.2.170 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 15:29:53 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.575+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=49.617731ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.636+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://www.googleapis.com duration=111.70784ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.659+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://securetoken.googleapis.com duration=133.493001ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.670+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=144.308183ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.678+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://database.volumio.cloud duration=152.702163ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.683+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://functions.volumio.cloud duration=157.790456ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.686+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://functions.volumio.cloud duration=160.799642ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.923+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=http://cddb.volumio.org duration=398.137191ms Aug 26 15:29:53 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:53.944+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=https://google.com duration=419.152402ms Aug 26 15:29:54 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T15:29:54.045+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:45404,00:00:00:00:00:00%01 @ 0x3000870" latency=67.100229ms timeout=10s endpoint=http://plugins.volumio.org duration=519.903171ms Aug 26 15:29:55 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:29:55 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 15:29:55 salonvolumio volumio[1372]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 15:30:00 salonvolumio volumio[1372]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 15:30:03 salonvolumio volumio[1372]: info: Received OAUTH Data Aug 26 15:30:03 salonvolumio volumio[1372]: info: Executing Spotify Oauth Login Aug 26 15:30:03 salonvolumio volumio[1372]: info: Saving Spotify Refresh Token Aug 26 15:30:03 salonvolumio sudo[23417]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 15:30:03 salonvolumio sudo[23417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:30:03 salonvolumio sudo[23419]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 15:30:03 salonvolumio sudo[23417]: pam_unix(sudo:session): session closed for user root Aug 26 15:30:03 salonvolumio sudo[23419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:30:03 salonvolumio sudo[23419]: pam_unix(sudo:session): session closed for user root Aug 26 15:30:03 salonvolumio volumio[1372]: verbose: New Socket.io Connection to 192.168.2.136 from 192.168.2.170 UA: Mozilla/5.0 (Linux; Android 16; SM-S928B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 15:30:03 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:30:03 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:30:03 salonvolumio volumio[1372]: info: Listing playlists Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 15:30:03 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 15:30:03 salonvolumio volumio[1372]: info: New Spotify access tokenBQCTkUOrfj... Aug 26 15:30:03 salonvolumio volumio[1372]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 15:30:04 salonvolumio volumio[1372]: SPOTIFY: User informations: {"account_id":"R04TzqAnpq","country":"PL","display_name":"A.szelag","email":"a.szelag@op.pl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/k25ys6h2p13vgvto8d39bqcg3"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/k25ys6h2p13vgvto8d39bqcg3","id":"k25ys6h2p13vgvto8d39bqcg3","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85c8a94c98f4388806435eb37e","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82c8a94c98f4388806435eb37e","width":64}],"product":"premium","type":"user","uri":"spotify:user:k25ys6h2p13vgvto8d39bqcg3"} Aug 26 15:30:04 salonvolumio volumio[1372]: info: Creating Spotify config file Aug 26 15:30:04 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:30:04 salonvolumio volumio[1372]: info: Spotify config file written Aug 26 15:30:04 salonvolumio sudo[23425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 15:30:04 salonvolumio sudo[23425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:30:04 salonvolumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 26 15:30:04 salonvolumio systemd[1]: go-librespot-daemon.service: Killing process 2093 (go-librespot) with signal SIGKILL. Aug 26 15:30:04 salonvolumio systemd[1]: go-librespot-daemon.service: Killing process 2095 (go-librespot) with signal SIGKILL. Aug 26 15:30:04 salonvolumio volumio[1372]: info: Connection to go-librespot Websocket closed Aug 26 15:30:04 salonvolumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 26 15:30:04 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:04 salonvolumio systemd[1]: go-librespot-daemon.service: Consumed 1min 8.533s CPU time. Aug 26 15:30:04 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:04 salonvolumio go-librespot[23427]: go-librespot daemon starting... Aug 26 15:30:04 salonvolumio sudo[23425]: pam_unix(sudo:session): session closed for user root Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=debug msg="app state loaded" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=debug msg="stored credentials not found" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:30:04 salonvolumio volumio[1372]: info: New Spotify access tokenBQD6QBAbTV... Aug 26 15:30:04 salonvolumio volumio[1372]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+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 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+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 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+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 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=info msg="zeroconf server listening on port 33959" Aug 26 15:30:04 salonvolumio volumio[1372]: SPOTIFY: User informations: {"account_id":"R04TzqAnpq","country":"PL","display_name":"A.szelag","email":"a.szelag@op.pl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/k25ys6h2p13vgvto8d39bqcg3"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/k25ys6h2p13vgvto8d39bqcg3","id":"k25ys6h2p13vgvto8d39bqcg3","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85c8a94c98f4388806435eb37e","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82c8a94c98f4388806435eb37e","width":64}],"product":"premium","type":"user","uri":"spotify:user:k25ys6h2p13vgvto8d39bqcg3"} Aug 26 15:30:04 salonvolumio volumio[1372]: info: Spotify Successfully logged in Aug 26 15:30:04 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 15:30:04 salonvolumio volumio[1372]: info: [1787751004367] CoreMusicLibrary::Adding element Spotify Aug 26 15:30:04 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 15:30:04 salonvolumio volumio[1372]: Cannot find translation for source RADIO 357 Aug 26 15:30:04 salonvolumio volumio[1372]: Cannot find translation for source Spotify Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=debug msg="obtained new client token: AAGhqRVZjr/NzEQcsaGeY0AI6zO/KEtbSBVHWHvUlJtC+Jo9kP7vO0bTSAnpaM2046Eims2M6mtAFJT0JK4/3uHprCDzgM12/9YgKgBB/GZdATH9/Qz7t5ydlH4iWlCVtAKWbSZNR98vQJqwrqcO7uVzPVKWF/WJd6yv6oOxgJ4Ec1k+M5bvH+yKpNqTYc3Txo2mADzbLeyiF/6BJBq0FUrJjDyDAaRe2xRPDQHrej4bSkEOjX6Hh9Sd" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=debug msg="completed keyexchange" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=debug msg="completed challenge" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 15:30:04 salonvolumio go-librespot[23428]: time="2026-08-26T15:30:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:30:04 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:30:04 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:30:05 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 26 15:30:05 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:30:05 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:30:05 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:30:05 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:30:05 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:30:05 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:30:05 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:30:07 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 15:30:07 salonvolumio volumio[1372]: info: Received Get System Info Aug 26 15:30:07 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 15:30:07 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 15:30:07 salonvolumio volumio[1372]: info: Discovery: Getting this device information Aug 26 15:30:07 salonvolumio volumio[1372]: info: CoreCommandRouter::volumioGetState Aug 26 15:30:07 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 15:30:07 salonvolumio volumio[1372]: info: Initializing connection to go-librespot Websocket Aug 26 15:30:07 salonvolumio volumio[1372]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:30:07 salonvolumio volumio[1372]: info: go-librespot daemon successfully initialized Aug 26 15:30:07 salonvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 15:30:07 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:07 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:07 salonvolumio go-librespot[23458]: go-librespot daemon starting... Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=debug msg="app state loaded" Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=debug msg="stored credentials not found" Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+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 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+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 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+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 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=info msg="zeroconf server listening on port 43243" Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:30:07 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:07+02:00" level=debug msg="obtained new client token: AAFvq4dEiYGjU9pbOPdaa/FoWrlmskuaqBCqqndOBPWc4I8/667ME2oSXdQ7Mitm3PmsL8Z5XTTIBA17BVG1rHPEWaWsSjsdgY42mxFzbJ8+6cEytx4ua2MuINuCJ+8hCv0tdfpOnNbqbq9F7A++b0QDvseC54eWdw+ekBKALuk+1AIPursxk5QOYvbujS7ghkgdv2+pvImTEtCLZJRmdmobd1PkUB4yJLElr9PoHryhg1Mffz54yvfE" Aug 26 15:30:08 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 15:30:08 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:08+02:00" level=debug msg="completed keyexchange" Aug 26 15:30:08 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:08+02:00" level=debug msg="completed challenge" Aug 26 15:30:08 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:08+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 15:30:08 salonvolumio go-librespot[23459]: time="2026-08-26T15:30:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:30:08 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:30:08 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:30:10 salonvolumio volumio[1372]: info: Initializing connection to go-librespot Websocket Aug 26 15:30:10 salonvolumio volumio[1372]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:30:10 salonvolumio volumio[1372]: info: Initializing connection to go-librespot Websocket Aug 26 15:30:10 salonvolumio volumio[1372]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:30:11 salonvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 15:30:11 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:11 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:11 salonvolumio go-librespot[23468]: go-librespot daemon starting... Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=debug msg="app state loaded" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=debug msg="stored credentials not found" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+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 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+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 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+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 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=info msg="zeroconf server listening on port 44265" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=debug msg="obtained new client token: AAFr7reS6gxzgNhePDeC6+Gh3VHB/P8DniXkEeKMGzesEEzviwraOFlHXFhVEo/kRQvwNdpj6NTCaISg90jWkL2C3zepu83LiW2CJLguJuuKz/e7e+M5nQ9Gz9VsFxQ0JeUg1HhvRLJAeKSPKeWOxse+CtH6U8aMg8JevVW+XUpZMXSz0R97CxxuTROqYXlhNXLoTa7WqbBowxckwNA11gnMlYjQHVFlne5ns2mBWqdZhSWhCZVwhRyn" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 15:30:11 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:11+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 15:30:12 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 15:30:12 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:12+02:00" level=debug msg="completed keyexchange" Aug 26 15:30:12 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:12+02:00" level=debug msg="completed challenge" Aug 26 15:30:12 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:12+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 15:30:12 salonvolumio go-librespot[23469]: time="2026-08-26T15:30:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 26 15:30:12 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:30:12 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:30:13 salonvolumio volumio[1372]: info: Initializing connection to go-librespot Websocket Aug 26 15:30:13 salonvolumio volumio[1372]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:30:13 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 26 15:30:15 salonvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 26 15:30:15 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:15 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:15 salonvolumio go-librespot[23478]: go-librespot daemon starting... Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=debug msg="app state loaded" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=debug msg="stored credentials not found" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+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 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+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 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+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 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=info msg="zeroconf server listening on port 40493" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=debug msg="obtained new client token: AAGTcDUoe1EJrS512PJfPM1xF9G0KYcVgvcxJljP4obAsJARuSlchO4OF/wAMhTq5tVhYNDAWl8R4iJkvX6iRtBjt22GvHSsS0N494GSoczpOIsaCT6jh+qr5QeXxS4TCrrWA7EW3yOHxqaAsNjy77Cf9uNqBQZ7cHftI/M6BJOsxxdZW37p5RNcQlWfK7C1tatfDecSIYZ5LrXCQ2iqDYf3ybqmkhh86QXO2t0DmTLSkGWNAV568rB3" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=debug msg="completed keyexchange" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=debug msg="completed challenge" Aug 26 15:30:15 salonvolumio go-librespot[23479]: time="2026-08-26T15:30:15+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 15:30:15 salonvolumio volumio[1372]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 26 15:30:15 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 26 15:30:15 salonvolumio volumio[1372]: info: Creating Spotify config file Aug 26 15:30:15 salonvolumio volumio[1372]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 15:30:15 salonvolumio volumio[1372]: info: Spotify config file written Aug 26 15:30:15 salonvolumio sudo[23489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 15:30:15 salonvolumio sudo[23489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 15:30:15 salonvolumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 26 15:30:15 salonvolumio systemd[1]: go-librespot-daemon.service: Killing process 23481 (go-librespot) with signal SIGKILL. Aug 26 15:30:15 salonvolumio systemd[1]: go-librespot-daemon.service: Killing process 23484 (go-librespot) with signal SIGKILL. Aug 26 15:30:15 salonvolumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 26 15:30:15 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:15 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 15:30:15 salonvolumio go-librespot[23491]: go-librespot daemon starting... Aug 26 15:30:15 salonvolumio sudo[23489]: pam_unix(sudo:session): session closed for user root Aug 26 15:30:15 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:15+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 15:30:15 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:15+02:00" level=debug msg="app state loaded" Aug 26 15:30:15 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:15+02:00" level=debug msg="stored credentials not found" Aug 26 15:30:15 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+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 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+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 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+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 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=info msg="zeroconf server listening on port 46647" Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 15:30:16 salonvolumio volumio[1372]: info: Initializing connection to go-librespot Websocket Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=debug msg="obtained new client token: AAEM2Gp6fMqfY+1Xfiwqb692MO8FQQdk5N3mVJH6Ibdw8inJQspfUiLy5Ys1hE7jcBiD/1q4OyKMDICEkgycGs6JmRUpta/PR1/1xFw+WDXjntrtg3hNCCMOLOM7o9LpWtZG1eN0CZFBq1ztpRZ71L/mXbl8Y/mSXsws/1L0lGXdBRItk3kUlIxwlFmzNcn0+y8WzatW+l2/0x+zBIWWT2SjmapvRXTz+ih8/Wq9qWFuJotrIlhwmg==" Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=debug msg="new websocket client" Aug 26 15:30:16 salonvolumio volumio[1372]: info: Connection to go-librespot Websocket established Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 15:30:16 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:16+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.2.136:44164->34.158.1.133:443: read: connection reset by peer" Aug 26 15:30:17 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 15:30:17 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:17+02:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.2.136:55206->34.158.1.133:80: read: connection reset by peer" Aug 26 15:30:17 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:17+02:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Aug 26 15:30:18 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:18+02:00" level=debug msg="completed keyexchange" Aug 26 15:30:18 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:18+02:00" level=debug msg="completed challenge" Aug 26 15:30:18 salonvolumio go-librespot[23492]: time="2026-08-26T15:30:18+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 15:30:18 salonvolumio go-librespot[23492]: time="2026-08-26T15:30: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 26 15:30:18 salonvolumio volumio[1372]: info: Connection to go-librespot Websocket closed Aug 26 15:30:18 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 15:30:18 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 15:30:18 salonvolumio volumio[1372]: info: go-librespot daemon successfully initialized Aug 26 15:30:19 salonvolumio volumio[1372]: info: Getting Spotify volume Aug 26 15:30:19 salonvolumio volumio[1372]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 15:30:19 salonvolumio volumio[1372]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 15:30:19 salonvolumio volumio[1372]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 15:30:19 salonvolumio volumio[1372]: errno: -111, Aug 26 15:30:19 salonvolumio volumio[1372]: code: 'ECONNREFUSED', Aug 26 15:30:19 salonvolumio volumio[1372]: syscall: 'connect', Aug 26 15:30:19 salonvolumio volumio[1372]: address: '127.0.0.1', Aug 26 15:30:19 salonvolumio volumio[1372]: port: 9879, Aug 26 15:30:19 salonvolumio volumio[1372]: response: undefined Aug 26 15:30:19 salonvolumio volumio[1372]: } Aug 26 15:30:19 salonvolumio volumio[1372]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 15:30:19 salonvolumio sudo[23529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 15:29' Aug 26 15:30:19 salonvolumio sudo[23529]: 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"