Mar 28 16:19:00 volumio go-librespot[10321]: time="2026-03-28T16:19:00+01:00" level=trace msg="received accesspoint ping" Mar 28 16:19:00 volumio go-librespot[10321]: time="2026-03-28T16:19:00+01:00" level=trace msg="received accesspoint pong ack" Mar 28 16:19:00 volumio go-librespot[10321]: time="2026-03-28T16:19:00+01:00" level=trace msg="sent dealer ping" Mar 28 16:19:00 volumio go-librespot[10321]: time="2026-03-28T16:19:00+01:00" level=trace msg="received dealer pong" Mar 28 16:19:04 volumio go-librespot[10321]: time="2026-03-28T16:19:04+01:00" level=debug msg="fetched chunk 5/21, size: 524288" uri="spotify:track:79xLxZrpdURjzJmdHKB85a" Mar 28 16:19:11 volumio volumio-remote-updater[806]: [2026-03-28 16:19:11] [connect] Successful connection Mar 28 16:19:17 volumio go-librespot[10321]: time="2026-03-28T16:19:17+01:00" level=debug msg="fetched chunk 6/21, size: 524288" uri="spotify:track:79xLxZrpdURjzJmdHKB85a" Mar 28 16:19:23 volumio volumio5-onboarding[1627]: time=2026-03-28T16:19:23.464+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 16:19:23 volumio volumio[1234]: info: Checking if install.sh is present Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:2mOW4uVTRSU2uF2ef0aQtg","play_origin":"playlist"}} Mar 28 16:19:23 volumio volumio[1234]: error: Failed to decode event: not_playing Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","play_origin":"playlist"}} Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","name":"Downgrade Desert","artist_names":["Igorrr"],"album_name":"Spirituality and Distortion","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","position":1,"duration":263520,"release_date":"year:2020 month:3 day:27","track_number":1,"disc_number":1}} Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","resume":false,"play_origin":"playlist"}} Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","seek":1,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreStateMachine::pushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Mar 28 16:19:23 volumio volumio5-onboarding[1627]: time=2026-03-28T16:19:23.526+01:00 level=ERROR msg="failed reading message" error="websocket: close 1000 (normal)" Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:2mOW4uVTRSU2uF2ef0aQtg","play_origin":"playlist"}} Mar 28 16:19:23 volumio volumio[1234]: error: Failed to decode event: not_playing Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","play_origin":"playlist"}} Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","name":"Downgrade Desert","artist_names":["Igorrr"],"album_name":"Spirituality and Distortion","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","position":1,"duration":263520,"release_date":"year:2020 month:3 day:27","track_number":1,"disc_number":1}} Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","resume":false,"play_origin":"playlist"}} Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","seek":1,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreStateMachine::pushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Mar 28 16:19:23 volumio volumio[1234]: info: Executing install.sh Mar 28 16:19:23 volumio sudo[10802]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/now_playing/install.sh Mar 28 16:19:23 volumio sudo[10802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 1 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Mar 28 16:19:23 volumio su[10805]: (to volumio) root on none Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Mar 28 16:19:23 volumio su[10805]: pam_unix(su:session): session opened for user volumio(uid=1000) by (uid=0) Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Mar 28 16:19:23 volumio volumio[1234]: info: Installing geo-tz node dependency Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 8 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 11 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 12 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 15 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 16 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 17 Mar 28 16:19:23 volumio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 18 Mar 28 16:19:23 volumio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 19 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 20 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 21 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 22 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 23 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 24 Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","seek":1,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreStateMachine::pushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 25 Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 16:19:23 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","seek":1,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreStateMachine::pushState Mar 28 16:19:23 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 26 Mar 28 16:19:23 volumio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Mar 28 16:19:23 volumio systemd[1]: Starting user@1000.service - User Manager for UID 1000... Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 27 Mar 28 16:19:23 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 28 Mar 28 16:19:23 volumio (systemd)[10807]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Mar 28 16:19:23 volumio volumio[1234]: 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: 29 Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 16:19:24 volumio volumio[1234]: 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: 29 Mar 28 16:19:24 volumio volumio[1234]: 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: 29 Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 28 16:19:24 volumio volumio[1234]: info: Received Get System Info Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 16:19:24 volumio volumio[1234]: info: Discovery: Getting this device information Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:24 volumio volumio[1234]: info: Listing playlists Mar 28 16:19:24 volumio volumio[1234]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 30 Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 28 16:19:24 volumio volumio[1234]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 31 Mar 28 16:19:24 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:24 volumio systemd[10807]: Queued start job for default target default.target. Mar 28 16:19:24 volumio systemd[10807]: Created slice app.slice - User Application Slice. Mar 28 16:19:24 volumio systemd[10807]: Reached target paths.target - Paths. Mar 28 16:19:24 volumio systemd[10807]: Reached target timers.target - Timers. Mar 28 16:19:24 volumio systemd[10807]: Starting dbus.socket - D-Bus User Message Bus Socket... Mar 28 16:19:24 volumio systemd[10807]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Mar 28 16:19:24 volumio systemd[10807]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Mar 28 16:19:24 volumio systemd[10807]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Mar 28 16:19:24 volumio systemd[10807]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Mar 28 16:19:24 volumio systemd[10807]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Mar 28 16:19:24 volumio systemd[10807]: Listening on dbus.socket - D-Bus User Message Bus Socket. Mar 28 16:19:24 volumio systemd[10807]: Reached target sockets.target - Sockets. Mar 28 16:19:24 volumio systemd[10807]: Reached target basic.target - Basic System. Mar 28 16:19:24 volumio systemd[1]: Started user@1000.service - User Manager for UID 1000. Mar 28 16:19:24 volumio systemd[10807]: Started mpris-proxy.service - Bluetooth mpris proxy. Mar 28 16:19:24 volumio systemd[10807]: Reached target default.target - Main User Target. Mar 28 16:19:24 volumio systemd[10807]: Startup finished in 996ms. Mar 28 16:19:24 volumio systemd[1]: Started session-c1.scope - Session c1 of User volumio. Mar 28 16:19:24 volumio volumio[1234]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 32 Mar 28 16:19:25 volumio systemd[10807]: Created slice session.slice - User Core Session Slice. Mar 28 16:19:25 volumio systemd[10807]: Starting dbus.service - D-Bus User Message Bus... Mar 28 16:19:25 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:25 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 16:19:25 volumio systemd[10807]: Started dbus.service - D-Bus User Message Bus. Mar 28 16:19:25 volumio volumio[1234]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 33 Mar 28 16:19:26 volumio volumio-remote-updater[806]: [2026-03-28 16:19:26] [connect] Successful connection Mar 28 16:19:26 volumio volumio-remote-updater[806]: [2026-03-28 16:19:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774711166 101 Mar 28 16:19:26 volumio volumio[1234]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 34 Mar 28 16:19:27 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.30 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 OPR/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 35 Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 28 16:19:27 volumio volumio[1234]: info: Received Get System Info Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 16:19:27 volumio volumio[1234]: info: Discovery: Getting this device information Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:19:27 volumio volumio[1234]: info: Listing playlists Mar 28 16:19:27 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::volumioPause Mar 28 16:19:29 volumio volumio[1234]: info: CoreStateMachine::pause Mar 28 16:19:29 volumio volumio[1234]: info: CoreStateMachine::stPlaybackTimer Mar 28 16:19:29 volumio volumio[1234]: info: CoreStateMachine::servicePause Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::servicePause Mar 28 16:19:29 volumio volumio[1234]: info: Spotify Received pause Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: SPOTIFY PAUSE Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: {"status":"play","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","codec":"ogg","seek":1001,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Mar 28 16:19:29 volumio volumio[1234]: info: Sending Spotify command to local API: /player/pause Mar 28 16:19:29 volumio go-librespot[10321]: time="2026-03-28T16:19:29+01:00" level=debug msg="pause track at 50693ms" Mar 28 16:19:29 volumio go-librespot[10321]: time="2026-03-28T16:19:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 16:19:29 volumio go-librespot[10321]: time="2026-03-28T16:19:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 16:19:29 volumio go-librespot[10321]: time="2026-03-28T16:19:29+01:00" level=trace msg="emitting websocket event: paused" Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","play_origin":"playlist"}} Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: {"status":"pause","service":"spop","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","seek":5001,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Mar 28 16:19:29 volumio volumio[1234]: info: CoreStateMachine::pushState Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:user:marek.mika:collection","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","play_origin":"playlist"}} Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: {"status":"pause","service":"spop","title":"Downgrade Desert","artist":"Igorrr","album":"Spirituality and Distortion","albumart":"https://i.scdn.co/image/ab67616d00001e02bee3918143b9d6e5571239b4","uri":"spotify:track:79xLxZrpdURjzJmdHKB85a","trackType":"spotify","seek":5001,"duration":263,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Mar 28 16:19:29 volumio volumio[1234]: info: CoreStateMachine::pushState Mar 28 16:19:29 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 16:19:29 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 16:19:29 volumio volumio[1234]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 28 16:19:30 volumio go-librespot[10321]: time="2026-03-28T16:19:30+01:00" level=trace msg="sent dealer ping" Mar 28 16:19:30 volumio go-librespot[10321]: time="2026-03-28T16:19:30+01:00" level=trace msg="received dealer pong" Mar 28 16:19:38 volumio kernel: Mar 28 16:19:38 volumio kernel: WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 2 Mar 28 16:19:38 volumio kernel: lan78xx 1-1.1.1:1.0 eth0: Failed to write register index 0x00000120. ret = -110 Mar 28 16:19:46 volumio volumio[1234]: info: Enabling plugin now_playing Mar 28 16:19:46 volumio volumio[1234]: info: Loading plugin "now_playing"... Mar 28 16:20:00 volumio go-librespot[10321]: time="2026-03-28T16:20:00+01:00" level=trace msg="sent dealer ping" Mar 28 16:20:00 volumio go-librespot[10321]: time="2026-03-28T16:20:00+01:00" level=trace msg="received dealer pong" Mar 28 16:20:09 volumio kernel: lan78xx 1-1.1.1:1.0 eth0: Failed to write register index 0x00000120. ret = -71 Mar 28 16:20:09 volumio kernel: lan78xx 1-1.1.1:1.0 eth0: Failed to read register index 0x00000120. ret = -71 Mar 28 16:20:30 volumio go-librespot[10321]: time="2026-03-28T16:20:30+01:00" level=trace msg="sent dealer ping" Mar 28 16:20:30 volumio go-librespot[10321]: time="2026-03-28T16:20:30+01:00" level=trace msg="received dealer pong" Mar 28 16:20:46 volumio volumio[1234]: error: !!!! WARNING !!!! Mar 28 16:20:46 volumio volumio[1234]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Mar 28 16:20:46 volumio volumio[1234]: Require stack: Mar 28 16:20:46 volumio volumio[1234]: - /data/plugins/user_interface/now_playing/dist/index.js Mar 28 16:20:46 volumio volumio[1234]: - /volumio/app/pluginmanager.js Mar 28 16:20:46 volumio volumio[1234]: - /volumio/app/index.js Mar 28 16:20:46 volumio volumio[1234]: - /volumio/index.js Mar 28 16:20:46 volumio volumio[1234]: error: Stack trace: Error: Cannot find module 'geo-tz' Mar 28 16:20:46 volumio volumio[1234]: Require stack: Mar 28 16:20:46 volumio volumio[1234]: - /data/plugins/user_interface/now_playing/dist/index.js Mar 28 16:20:46 volumio volumio[1234]: - /volumio/app/pluginmanager.js Mar 28 16:20:46 volumio volumio[1234]: - /volumio/app/index.js Mar 28 16:20:46 volumio volumio[1234]: - /volumio/index.js Mar 28 16:20:46 volumio volumio[1234]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Mar 28 16:20:46 volumio volumio[1234]: at Module._load (node:internal/modules/cjs/loader:901:27) Mar 28 16:20:46 volumio volumio[1234]: at Module.require (node:internal/modules/cjs/loader:1115:19) Mar 28 16:20:46 volumio volumio[1234]: at require (node:internal/modules/helpers:130:18) Mar 28 16:20:46 volumio volumio[1234]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:56:34) Mar 28 16:20:46 volumio volumio[1234]: at Module._compile (node:internal/modules/cjs/loader:1233:14) Mar 28 16:20:46 volumio volumio[1234]: at Module._extensions..js (node:internal/modules/cjs/loader:1287:10) Mar 28 16:20:46 volumio volumio[1234]: at Module.load (node:internal/modules/cjs/loader:1091:32) Mar 28 16:20:46 volumio volumio[1234]: at Module._load (node:internal/modules/cjs/loader:938:12) Mar 28 16:20:46 volumio volumio[1234]: at Module.require (node:internal/modules/cjs/loader:1115:19) Mar 28 16:20:46 volumio volumio[1234]: at require (node:internal/modules/helpers:130:18) Mar 28 16:20:46 volumio volumio[1234]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Mar 28 16:20:46 volumio volumio[1234]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Mar 28 16:20:46 volumio volumio[1234]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 28 16:20:46 volumio volumio[1234]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 28 16:20:46 volumio volumio[1234]: error: !!!! WARNING !!!! Mar 28 16:20:46 volumio volumio[1234]: info: Done. Mar 28 16:20:47 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 16:20:47 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Mar 28 16:20:50 volumio volumio[1234]: info: Mar 28 16:20:50 volumio volumio[1234]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 16:20:50 volumio volumio5-onboarding[1627]: time=2026-03-28T16:20:50.564+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 16:20:50 volumio volumio[1234]: TypeError: Cannot read properties of null (reading 'broadcastMessage') Mar 28 16:20:50 volumio volumio[1234]: at /volumio/app/index.js:1534:32 Mar 28 16:20:50 volumio volumio[1234]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Mar 28 16:20:50 volumio volumio[1234]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Mar 28 16:20:50 volumio volumio[1234]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Mar 28 16:20:50 volumio volumio[1234]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Mar 28 16:20:50 volumio volumio[1234]: at Tail. (/volumio/app/pluginmanager.js:860:24) Mar 28 16:20:50 volumio volumio[1234]: at Tail.emit (node:events:514:28) Mar 28 16:20:50 volumio volumio[1234]: at ReadStream. (/volumio/node_modules/tail/lib/tail.js:51:33) Mar 28 16:20:50 volumio volumio[1234]: at ReadStream.emit (node:events:514:28) Mar 28 16:20:50 volumio volumio[1234]: at addChunk (node:internal/streams/readable:343:12) Mar 28 16:20:50 volumio volumio[1234]: at readableAddChunk (node:internal/streams/readable:312:11) Mar 28 16:20:50 volumio volumio[1234]: at Readable.push (node:internal/streams/readable:253:10) Mar 28 16:20:50 volumio volumio[1234]: at node:internal/fs/streams:275:14 Mar 28 16:20:50 volumio volumio[1234]: at FSReqCallback.wrapper [as oncomplete] (node:fs:701:5) Mar 28 16:20:50 volumio volumio[1234]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 16:20:50 volumio su[10805]: pam_unix(su:session): session closed for user volumio Mar 28 16:20:50 volumio systemd[1]: session-c1.scope: Deactivated successfully. Mar 28 16:20:50 volumio systemd[1]: session-c1.scope: Consumed 44.896s CPU time. Mar 28 16:20:51 volumio sudo[10802]: pam_unix(sudo:session): session closed for user root Mar 28 16:20:52 volumio sudo[10977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 16:19' Mar 28 16:20:52 volumio sudo[10977]: 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"