Aug 26 16:01:26 salonvolumio volumio[27118]: 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 16:01:26 salonvolumio volumio[27118]: 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 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 16:01:26 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:26 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:26 salonvolumio volumio[27118]: info: Listing playlists Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:26 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:26 salonvolumio volumio[27118]: 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 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 16:01:26 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.315+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.2.170:59548 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.327+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.2.170:59548 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.328+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.2.170:59548 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.331+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.2.170:59568 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.343+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.343+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.170:59568 @ 0x30006f0" latency=67.986487ms timeout=20s Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.343+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" Aug 26 16:01:27 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:27 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.345+02:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" name=SalonVolumio Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.345+02:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" language=pl Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.348+02:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" timezone=Europe/Warsaw Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.349+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" available=true connected=true macAddress=2c:cf:67:fc:27:f1 ip4Address=192.168.2.136/24 ip6Address= Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.349+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.349+02:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" setupComplete=true Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 26 16:01:27 salonvolumio volumio[27118]: amixer -c 0 info | grep "vc4-hdmi-0" Aug 26 16:01:27 salonvolumio volumio[27118]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Aug 26 16:01:27 salonvolumio volumio[27118]: amixer -c 1 info | grep "vc4-hdmi-1" Aug 26 16:01:27 salonvolumio volumio[27118]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Aug 26 16:01:27 salonvolumio volumio[27118]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 26 16:01:27 salonvolumio volumio[27118]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 26 16:01:27 salonvolumio volumio[27118]: {"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 16:01:27 salonvolumio volumio[27118]: amixer -c 5 info | grep "Tone2 Pro" Aug 26 16:01:27 salonvolumio volumio[27118]: Card sysdefault:5 'Pro'/'Khadas Tone2 Pro at usb-xhci-hcd.0-1, high speed' Aug 26 16:01:27 salonvolumio volumio[27118]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Aug 26 16:01:27 salonvolumio volumio[27118]: /bin/sh: 1: /usr/local/bin/alsacap: not found Aug 26 16:01:27 salonvolumio volumio[27118]: {"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 16:01:27 salonvolumio volumio[27118]: amixer -c 5 info | grep "Tone2 Pro" Aug 26 16:01:27 salonvolumio volumio[27118]: Card sysdefault:5 'Pro'/'Khadas Tone2 Pro at usb-xhci-hcd.0-1, high speed' Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.448+02:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" selectedOutputId=5 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.449+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=http://pushupdates.volumio.org duration=102.583733ms Aug 26 16:01:27 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:27 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.466+02:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" currentVersion=4.119 latestVersion=4.119 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.467+02:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.170:59568 @ 0x30006f0" status=UPDATE_STATUS_NONE progress=0 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.467+02:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" userId=ErAYZlcHlgSLwDBbAvsqX7W6wkB2 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.467+02:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" providers=9 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.467+02:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" plugins=71 Aug 26 16:01:27 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.468+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" state=STATUS_STOPPED positionMs=104043 volume=3 Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.468+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.170:59568 @ 0x30006f0" id=spotify:track:2uXlHCUbq9OMUwx3hrk06o title=Riptide Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.472+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=129.754964ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.582+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://www.googleapis.com duration=239.767912ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.588+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=242.125038ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.600+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://securetoken.googleapis.com duration=254.234468ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.615+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=269.208935ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.704+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=355.454749ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.739+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://database.volumio.cloud duration=393.064601ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.784+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://functions.volumio.cloud duration=434.461423ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.795+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://functions.volumio.cloud duration=448.6107ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.810+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=http://cddb.volumio.org duration=467.580228ms Aug 26 16:01:27 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:27.898+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=https://google.com duration=555.096217ms Aug 26 16:01:28 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:28.112+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=69.969857ms timeout=10s endpoint=http://plugins.volumio.org duration=766.588948ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.637+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.2.170:59568 @ 0x30006f0" latency=69.709843ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.646+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.670+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=23.490651ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.672+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=http://pushupdates.volumio.org duration=24.943771ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.684+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=37.552723ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.697+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=49.984118ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.760+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://www.googleapis.com duration=113.104135ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.782+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://securetoken.googleapis.com duration=135.105257ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.790+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=143.787628ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.797+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://database.volumio.cloud duration=150.409745ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.798+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://functions.volumio.cloud duration=150.948489ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.815+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://functions.volumio.cloud duration=167.848376ms Aug 26 16:01:29 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:29.975+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=https://google.com duration=328.439241ms Aug 26 16:01:30 salonvolumio sudo[30451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 16:01:30 salonvolumio sudo[30451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:30 salonvolumio sudo[30451]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:30 salonvolumio sudo[30453]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 16:01:30 salonvolumio sudo[30453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:30 salonvolumio sudo[30453]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:30 salonvolumio volumio[27118]: 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 16:01:30 salonvolumio sudo[30457]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 16:01:30 salonvolumio sudo[30457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:30 salonvolumio sudo[30457]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:30 salonvolumio sudo[30459]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 16:01:30 salonvolumio sudo[30459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:30 salonvolumio sudo[30459]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:30 salonvolumio volumio[27118]: 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: 11 Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 16:01:30 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:30 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:30 salonvolumio volumio[27118]: info: Listing playlists Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:30 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 16:01:31 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 26 16:01:32 salonvolumio volumio[27118]: 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: 12 Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 16:01:32 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:32 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:32 salonvolumio volumio[27118]: info: Listing playlists Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 16:01:32 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:32 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 16:01:32 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:32 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:32 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:33 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 16:01:33 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:33 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 26 16:01:37 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:37.430+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=http://cddb.volumio.org duration=7.782795007s Aug 26 16:01:38 salonvolumio volumio5-onboarding[1624]: time=2026-08-26T16:01:38.103+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.2.170:59568 @ 0x30006f0" latency=70.600818ms timeout=10s endpoint=http://plugins.volumio.org duration=8.456377135s Aug 26 16:01:40 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 26 16:01:43 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:47 salonvolumio volumio[27118]: info: Received OAUTH Data Aug 26 16:01:47 salonvolumio volumio[27118]: info: Executing Spotify Oauth Login Aug 26 16:01:47 salonvolumio volumio[27118]: info: Saving Spotify Refresh Token Aug 26 16:01:47 salonvolumio sudo[30499]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 16:01:47 salonvolumio sudo[30499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:47 salonvolumio sudo[30499]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:47 salonvolumio sudo[30501]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 16:01:47 salonvolumio sudo[30501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:47 salonvolumio sudo[30501]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:47 salonvolumio volumio[27118]: 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: 12 Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 16:01:47 salonvolumio volumio[27118]: info: New Spotify access tokenBQDEbDtQGz... Aug 26 16:01:47 salonvolumio volumio[27118]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 16:01:47 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:47 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:47 salonvolumio volumio[27118]: info: Listing playlists Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 26 16:01:47 salonvolumio volumio[27118]: 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 16:01:47 salonvolumio volumio[27118]: info: Creating Spotify config file Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 16:01:47 salonvolumio volumio[27118]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 26 16:01:47 salonvolumio volumio[27118]: info: Spotify config file written Aug 26 16:01:47 salonvolumio sudo[30506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 26 16:01:47 salonvolumio sudo[30506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 26 16:01:47 salonvolumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 26 16:01:47 salonvolumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 26 16:01:47 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 16:01:47 salonvolumio systemd[1]: go-librespot-daemon.service: Consumed 16.130s CPU time. Aug 26 16:01:47 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 16:01:47 salonvolumio sudo[30506]: pam_unix(sudo:session): session closed for user root Aug 26 16:01:47 salonvolumio go-librespot[30508]: go-librespot daemon starting... Aug 26 16:01:47 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:47+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 16:01:47 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:47+02:00" level=debug msg="app state loaded" Aug 26 16:01:47 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:47+02:00" level=debug msg="stored credentials not found" Aug 26 16:01:47 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 16:01:47 salonvolumio volumio[27118]: info: Connection to go-librespot Websocket closed Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+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 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+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 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+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 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+02:00" level=info msg="zeroconf server listening on port 33471" Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 16:01:48 salonvolumio volumio[27118]: info: New Spotify access tokenBQBzYN5c72... Aug 26 16:01:48 salonvolumio volumio[27118]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+02:00" level=debug msg="obtained new client token: AAHbzaMc+Luc9opAm0uHxGUGryelhdCxbeWtOSk2nVRQgedOEbBCHE99id9I9JxDkXI3j1l+HP7lxgH5Tgu5dl0e7qD0XWp4LHdKji1yVgs8crqHifT22VoQM76HvNySyHUIDji4E3nsPoOTiD6KclXST6B2Ywj84sqB9iZ9NjdpUYJG0Ag1kSxDYbhC0JWM81f17ykqmzW5sNt+5u/oYal8xB6xL+k0PlH5CE80Ul17Yteg8QyWAA==" Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+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:43128->34.158.1.133:4070: read: connection reset by peer" Aug 26 16:01:48 salonvolumio volumio[27118]: 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 16:01:48 salonvolumio volumio[27118]: info: Spotify Successfully logged in Aug 26 16:01:48 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 16:01:48 salonvolumio volumio[27118]: info: [1787752908286] CoreMusicLibrary::Adding element Spotify Aug 26 16:01:48 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 16:01:48 salonvolumio volumio[27118]: Cannot find translation for source RADIO 357 Aug 26 16:01:48 salonvolumio volumio[27118]: Cannot find translation for source Spotify Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 16:01:48 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:48+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 16:01:49 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 26 16:01:49 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:49+02:00" level=debug msg="completed keyexchange" Aug 26 16:01:49 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:49+02:00" level=debug msg="completed challenge" Aug 26 16:01:49 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 26 16:01:49 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:49+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 16:01:49 salonvolumio go-librespot[30509]: time="2026-08-26T16:01:49+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 16:01:49 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 16:01:49 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 16:01:49 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 16:01:49 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:49 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:49 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:49 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:49 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:49 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:50 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 26 16:01:50 salonvolumio volumio[27118]: info: Received Get System Info Aug 26 16:01:50 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 16:01:50 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 16:01:50 salonvolumio volumio[27118]: info: Discovery: Getting this device information Aug 26 16:01:50 salonvolumio volumio[27118]: info: CoreCommandRouter::volumioGetState Aug 26 16:01:50 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 16:01:50 salonvolumio volumio[27118]: info: Initializing connection to go-librespot Websocket Aug 26 16:01:51 salonvolumio volumio[27118]: info: go-librespot daemon successfully initialized Aug 26 16:01:51 salonvolumio volumio[27118]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 16:01:52 salonvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 26 16:01:52 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 16:01:52 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 16:01:52 salonvolumio go-librespot[30532]: go-librespot daemon starting... Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=debug msg="app state loaded" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=debug msg="stored credentials not found" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+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 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+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 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+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 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=info msg="zeroconf server listening on port 35471" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=debug msg="obtained new client token: AAGuMpiSyjqS9ax9A55PTIcc48nRj+PrelGKheWNvPDNw9csOljsRFI/7vCjG9GChSUfxd7aArtujRc7V8KOtRPxewf2UkA7cqwNqZ0V1dpff7B6fRXxczudOkLrcRwA9qni2K2SNKhREkZE1mIxakDTpQ/lqNH2Hf1EseZIqPNJoBL7bmg0zxkri6ScnBJ3NpfDqmGwLIDvYGEkdYXjj673+mAgm2476x6OVcFsKb7RAsHrlTZ1R7nA" Aug 26 16:01:52 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 16:01:53 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:53+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:35462->34.158.1.133:4070: read: connection reset by peer" Aug 26 16:01:53 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 16:01:53 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:53+02:00" level=debug msg="completed keyexchange" Aug 26 16:01:53 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:53+02:00" level=debug msg="completed challenge" Aug 26 16:01:53 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:53+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 16:01:53 salonvolumio go-librespot[30533]: time="2026-08-26T16:01:53+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 16:01:53 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 16:01:53 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 16:01:54 salonvolumio volumio[27118]: info: Initializing connection to go-librespot Websocket Aug 26 16:01:54 salonvolumio volumio[27118]: info: Initializing connection to go-librespot Websocket Aug 26 16:01:54 salonvolumio volumio[27118]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 16:01:54 salonvolumio volumio[27118]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 16:01:56 salonvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 26 16:01:56 salonvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 26 16:01:56 salonvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 26 16:01:56 salonvolumio go-librespot[30542]: go-librespot daemon starting... Aug 26 16:01:56 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:56+02:00" level=info msg="running go-librespot 0.7.1" Aug 26 16:01:56 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:56+02:00" level=debug msg="app state loaded" Aug 26 16:01:56 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:56+02:00" level=debug msg="stored credentials not found" Aug 26 16:01:56 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 26 16:01:57 salonvolumio volumio[27118]: info: Initializing connection to go-librespot Websocket Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=debug msg="new websocket client" Aug 26 16:01:57 salonvolumio volumio[27118]: info: Connection to go-librespot Websocket established Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+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 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+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 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+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 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=info msg="zeroconf server listening on port 44965" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=debug msg="obtained new client token: AAGb4jQIXFNuaIhd0lTgqJKwZTwrFrMLuzuIZqzKxPQdMfDqCm6sVeKbCdy8LnnbBY/YTrmGueGtaC89nbiOUacN+FmNogV7V8JjTOPpe+cF2A7N7gv4Y6Cw9kfLMSiuNbBa919qAaTWDwmIWLzFVVBV1ana/TyUzBigLUGsDP+oZNDCg2+GfgBbMAYlPrCg0h7wEey3xcRdEP9onKkMUxZpaIKzvBjlq0um6RLQP9TLRNM6/L17PA==" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+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 16:01:57 salonvolumio volumio[27118]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=debug msg="completed keyexchange" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=debug msg="completed challenge" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+02:00" level=info msg="authenticated AP" username="k2*********************g3" Aug 26 16:01:57 salonvolumio go-librespot[30543]: time="2026-08-26T16:01:57+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 16:01:57 salonvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 26 16:01:57 salonvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 26 16:01:57 salonvolumio volumio[27118]: info: Connection to go-librespot Websocket closed Aug 26 16:02:00 salonvolumio volumio[27118]: info: Getting Spotify volume Aug 26 16:02:00 salonvolumio volumio[27118]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 16:02:00 salonvolumio volumio[27118]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 26 16:02:00 salonvolumio volumio[27118]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 26 16:02:00 salonvolumio volumio[27118]: errno: -111, Aug 26 16:02:00 salonvolumio volumio[27118]: code: 'ECONNREFUSED', Aug 26 16:02:00 salonvolumio volumio[27118]: syscall: 'connect', Aug 26 16:02:00 salonvolumio volumio[27118]: address: '127.0.0.1', Aug 26 16:02:00 salonvolumio volumio[27118]: port: 9879, Aug 26 16:02:00 salonvolumio volumio[27118]: response: undefined Aug 26 16:02:00 salonvolumio volumio[27118]: } Aug 26 16:02:00 salonvolumio volumio[27118]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 16:02:00 salonvolumio sudo[30580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-26 16:01' Aug 26 16:02:00 salonvolumio sudo[30580]: 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"