Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="handling skip_next player command from 2de4fd599e1c061162f195033f0185a6ab1b2cd4" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=trace msg="emitting websocket event: will_play" Apr 12 13:51:08 volumio volumio[1346]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:1uXol4dKqzMsUiqvHpwhZh","uri":"spotify:track:0albqvScVSjiJgAkirPjGa","play_origin":"album"}} Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="selected format OGG_VORBIS_320 (3c1851c7f27a3d2c2c61a093968ebbf27cfca75a)" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="requested aes key for file 3c1851c7f27a3d2c2c61a093968ebbf27cfca75a, gid: 0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="fetched first chunk of 87, total size is 45567271 bytes" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=info msg="loaded track \"Close to the Edge: i. The Solid Time of Change, ii. Total Mass Retain, iii. I Get up I Get Down, iv. Seasons of Man - 2025 Steven Wilson Remix\" (paused: false, position: 0ms, duration: 1122000ms, prefetched: false)" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=trace msg="scheduling prefetch in 1092s" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=trace msg="emitting websocket event: metadata" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="sending successful reply for dealer request" Apr 12 13:51:08 volumio volumio[1346]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0albqvScVSjiJgAkirPjGa","name":"Close to the Edge: i. The Solid Time of Change, ii. Total Mass Retain, iii. I Get up I Get Down, iv. Seasons of Man - 2025 Steven Wilson Remix","artist_names":["Yes"],"album_name":"Close to the Edge (Super Deluxe Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02593f4d2b1bcf28ac44459ddf","position":0,"duration":1122000,"release_date":"year:1972 month:9 day:8","track_number":1,"disc_number":2}} Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=trace msg="emitting websocket event: playing" Apr 12 13:51:08 volumio volumio[1346]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:1uXol4dKqzMsUiqvHpwhZh","uri":"spotify:track:0albqvScVSjiJgAkirPjGa","resume":false,"play_origin":"album"}} Apr 12 13:51:08 volumio volumio[1346]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 13:51:08 volumio volumio[1346]: SPOTIFY: {"status":"play","service":"spop","title":"Close to the Edge: i. The Solid Time of Change, ii. Total Mass Retain, iii. I Get up I Get Down, iv. Seasons of Man - 2025 Steven Wilson Remix","artist":"Yes","album":"Close to the Edge (Super Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e02593f4d2b1bcf28ac44459ddf","uri":"spotify:track:0albqvScVSjiJgAkirPjGa","trackType":"spotify","seek":0,"duration":1122,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 12 13:51:08 volumio volumio[1346]: info: CoreCommandRouter::servicePushState Apr 12 13:51:08 volumio volumio[1346]: info: CoreStateMachine::pushState Apr 12 13:51:08 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 13:51:08 volumio volumio[1346]: info: CoreCommandRouter::volumioPushState Apr 12 13:51:08 volumio volumio[1346]: info: [LastFM] Current track has sufficient metadata: title (Close to the Edge: i. The Solid Time of Change, ii. Total Mass Retain, iii. I Get up I Get Down, iv. Seasons of Man - 2025 Steven Wilson Remix) and artist (Yes) passed on explicitly Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="fetched chunk 1/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:08 volumio go-librespot[1781]: time="2026-04-12T13:51:08+01:00" level=debug msg="fetched chunk 2/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:09 volumio volumio[1346]: SPOTIFY: PUSH STATE SPOTIFY Apr 12 13:51:09 volumio volumio[1346]: SPOTIFY: {"status":"play","service":"spop","title":"Close to the Edge: i. The Solid Time of Change, ii. Total Mass Retain, iii. I Get up I Get Down, iv. Seasons of Man - 2025 Steven Wilson Remix","artist":"Yes","album":"Close to the Edge (Super Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e02593f4d2b1bcf28ac44459ddf","uri":"spotify:track:0albqvScVSjiJgAkirPjGa","trackType":"spotify","seek":0,"duration":1122,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 12 13:51:09 volumio volumio[1346]: info: CoreCommandRouter::servicePushState Apr 12 13:51:09 volumio volumio[1346]: info: CoreStateMachine::pushState Apr 12 13:51:09 volumio volumio[1346]: info: CoreCommandRouter::volumioPushState Apr 12 13:51:09 volumio go-librespot[1781]: time="2026-04-12T13:51:09+01:00" level=debug msg="fetched chunk 3/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:12 volumio volumio5-onboarding[1978]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Apr 12 13:51:12 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 12 13:51:12 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 12 13:51:12 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Apr 12 13:51:12 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 12 13:51:12 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 12 13:51:12 volumio volumio5-onboarding[2066]: time=2026-04-12T13:51:12.406+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Apr 12 13:51:12 volumio volumio[1346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Apr 12 13:51:12 volumio volumio[1346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Apr 12 13:51:12 volumio volumio[1346]: info: Received Get System Info Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 13:51:12 volumio volumio[1346]: info: Discovery: Getting this device information Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::volumioGetState Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 13:51:12 volumio volumio5-onboarding[2066]: time=2026-04-12T13:51:12.419+01:00 level=INFO msg="system info for 0703ff9fbf22df82d76680c8a63d2d5c" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Apr 12 13:51:12 volumio volumio5-onboarding[2066]: time=2026-04-12T13:51:12.434+01:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 12 13:51:12 volumio volumio[1346]: info: Received Get System Info Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 13:51:12 volumio volumio[1346]: info: Discovery: Getting this device information Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::volumioGetState Apr 12 13:51:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 13:51:24 volumio go-librespot[1781]: time="2026-04-12T13:51:24+01:00" level=debug msg="fetched chunk 4/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:27 volumio go-librespot[1781]: time="2026-04-12T13:51:27+01:00" level=trace msg="sent dealer ping" Apr 12 13:51:27 volumio go-librespot[1781]: time="2026-04-12T13:51:27+01:00" level=trace msg="received dealer pong" Apr 12 13:51:38 volumio go-librespot[1781]: time="2026-04-12T13:51:38+01:00" level=debug msg="fetched chunk 5/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:42 volumio volumio5-onboarding[2066]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Apr 12 13:51:42 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 12 13:51:42 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 12 13:51:42 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Apr 12 13:51:42 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 12 13:51:42 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 12 13:51:42 volumio volumio5-onboarding[2119]: time=2026-04-12T13:51:42.658+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Apr 12 13:51:42 volumio volumio[1346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Apr 12 13:51:42 volumio volumio[1346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Apr 12 13:51:42 volumio volumio[1346]: info: Received Get System Info Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 13:51:42 volumio volumio[1346]: info: Discovery: Getting this device information Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::volumioGetState Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 13:51:42 volumio volumio5-onboarding[2119]: time=2026-04-12T13:51:42.670+01:00 level=INFO msg="system info for 0703ff9fbf22df82d76680c8a63d2d5c" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Apr 12 13:51:42 volumio volumio5-onboarding[2119]: time=2026-04-12T13:51:42.686+01:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 12 13:51:42 volumio volumio[1346]: info: Received Get System Info Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 13:51:42 volumio volumio[1346]: info: Discovery: Getting this device information Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::volumioGetState Apr 12 13:51:42 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 13:51:50 volumio go-librespot[1781]: time="2026-04-12T13:51:50+01:00" level=debug msg="fetched chunk 6/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:51:57 volumio go-librespot[1781]: time="2026-04-12T13:51:57+01:00" level=trace msg="sent dealer ping" Apr 12 13:51:57 volumio go-librespot[1781]: time="2026-04-12T13:51:57+01:00" level=trace msg="received dealer pong" Apr 12 13:52:01 volumio go-librespot[1781]: time="2026-04-12T13:52:01+01:00" level=debug msg="fetched chunk 7/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:52:12 volumio go-librespot[1781]: time="2026-04-12T13:52:12+01:00" level=debug msg="fetched chunk 8/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:52:12 volumio volumio5-onboarding[2119]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Apr 12 13:52:12 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 12 13:52:12 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 12 13:52:12 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 4. Apr 12 13:52:12 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 12 13:52:12 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 12 13:52:12 volumio volumio5-onboarding[2173]: time=2026-04-12T13:52:12.906+01:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Apr 12 13:52:12 volumio volumio[1346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Apr 12 13:52:12 volumio volumio[1346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Apr 12 13:52:12 volumio volumio[1346]: info: Received Get System Info Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 13:52:12 volumio volumio[1346]: info: Discovery: Getting this device information Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::volumioGetState Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 13:52:12 volumio volumio5-onboarding[2173]: time=2026-04-12T13:52:12.918+01:00 level=INFO msg="system info for 0703ff9fbf22df82d76680c8a63d2d5c" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Apr 12 13:52:12 volumio volumio5-onboarding[2173]: time=2026-04-12T13:52:12.934+01:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 12 13:52:12 volumio volumio[1346]: info: Received Get System Info Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 13:52:12 volumio volumio[1346]: info: Discovery: Getting this device information Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::volumioGetState Apr 12 13:52:12 volumio volumio[1346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 13:52:24 volumio go-librespot[1781]: time="2026-04-12T13:52:24+01:00" level=debug msg="fetched chunk 9/86, size: 524288" uri="spotify:track:0albqvScVSjiJgAkirPjGa" Apr 12 13:52:26 volumio volumio-remote-updater[960]: curl_easy_perform() failed: Timeout was reached Apr 12 13:52:26 volumio volumio-remote-updater[960]: terminate called after throwing an instance of 'std::invalid_argument' Apr 12 13:52:26 volumio volumio-remote-updater[960]: what(): parse error - unexpected end of input Apr 12 13:52:26 volumio volumio[1346]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 13:52:26 volumio systemd[1]: volumio-remote-updater.service: Main process exited, code=killed, status=6/ABRT Apr 12 13:52:26 volumio systemd[1]: volumio-remote-updater.service: Failed with result 'signal'. Apr 12 13:52:26 volumio volumio[1346]: Error: connect ETIMEDOUT 130.211.19.189:80 Apr 12 13:52:26 volumio volumio[1346]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 12 13:52:26 volumio volumio[1346]: errno: -110, Apr 12 13:52:26 volumio volumio[1346]: code: 'ETIMEDOUT', Apr 12 13:52:26 volumio volumio[1346]: syscall: 'connect', Apr 12 13:52:26 volumio volumio[1346]: address: '130.211.19.189', Apr 12 13:52:26 volumio volumio[1346]: port: 80 Apr 12 13:52:26 volumio volumio[1346]: } Apr 12 13:52:26 volumio volumio[1346]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 13:52:26 volumio sudo[2213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 13:51' Apr 12 13:52:26 volumio sudo[2213]: 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"