Feb 24 14:16:08 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:08+01:00" level=trace msg="sent dealer ping" Feb 24 14:16:08 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:08+01:00" level=trace msg="received dealer pong" Feb 24 14:16:25 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:25 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 14 Feb 24 14:16:25 jans-volumio volumio[1384]: info: Prefetching next song Feb 24 14:16:25 jans-volumio volumio[1384]: info: [1771938985454] ControllerSpotify::prefetch Feb 24 14:16:25 jans-volumio volumio[1384]: info: Sending Spotify command with payload to local API: /player/add_to_queue Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="prefetching next track" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="selected format OGG_VORBIS_320 (d7cedbbc1e5935f8624e56bc3fbcdfdcd81190f5)" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="requested aes key for file d7cedbbc1e5935f8624e56bc3fbcdfdcd81190f5, gid: 4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="fetched first chunk of 19, total size is 9776216 bytes" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=info msg="prefetched track \"Shadowplay - 2007 Remaster\" (duration: 233719ms)" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:25 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:25+01:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=trace msg="emitting websocket event: not_playing" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:7k42ztYdHyKWrKrENxwjkV","uri":"spotify:track:7k42ztYdHyKWrKrENxwjkV","play_origin":"go-librespot"}} Feb 24 14:16:29 jans-volumio volumio[1384]: error: Failed to decode event: not_playing Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=trace msg="emitting websocket event: will_play" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=info msg="loaded track \"Shadowplay - 2007 Remaster\" (paused: false, position: 0ms, duration: 233719ms, prefetched: true)" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:7k42ztYdHyKWrKrENxwjkV","uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","play_origin":"go-librespot"}} Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=trace msg="scheduling prefetch in 205s" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=trace msg="emitting websocket event: metadata" Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","name":"Shadowplay - 2007 Remaster","artist_names":["Joy Division"],"album_name":"Unknown Pleasures (Collector's Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0216eb1e685e6bd37ab3228de6","position":0,"duration":233719,"release_date":"year:1979 month:6 day:1","track_number":7,"disc_number":1}} Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 14:16:29 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:29+01:00" level=trace msg="emitting websocket event: playing" Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:7k42ztYdHyKWrKrENxwjkV","uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","resume":false,"play_origin":"go-librespot"}} Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: PUSH STATE SPOTIFY Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: {"status":"play","service":"spop","title":"Shadowplay - 2007 Remaster","artist":"Joy Division","album":"Unknown Pleasures (Collector's Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0216eb1e685e6bd37ab3228de6","uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","trackType":"spotify","seek":0,"duration":233,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::servicePushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Shadowplay - 2007 Remaster","artist":"Joy Division","album":"Unknown Pleasures (Collector's Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0216eb1e685e6bd37ab3228de6","uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","trackType":"spotify","seek":0,"duration":233,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 14:16:29 jans-volumio volumio[1384]: verbose: CURRENT POSITION 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::syncState stateService play Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:16:29 jans-volumio volumio[1384]: info: Received an update from plugin. extracting info from payload Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::pushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioPushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioGetState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::pushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioPushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioGetState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.608+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" state=STATUS_PLAYING positionMs=251013 volume=100 Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.608+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" id=spotify:track:7k42ztYdHyKWrKrENxwjkV title="Atmosphere - 2020 Digital Remaster" Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.609+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" state=STATUS_PLAYING positionMs=251013 volume=100 Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.609+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" id=spotify:track:7k42ztYdHyKWrKrENxwjkV title="Atmosphere - 2020 Digital Remaster" Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: PUSH STATE SPOTIFY Feb 24 14:16:29 jans-volumio volumio[1384]: SPOTIFY: {"status":"play","service":"spop","title":"Shadowplay - 2007 Remaster","artist":"Joy Division","album":"Unknown Pleasures (Collector's Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0216eb1e685e6bd37ab3228de6","uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","trackType":"spotify","seek":0,"duration":233,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::servicePushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Shadowplay - 2007 Remaster","artist":"Joy Division","album":"Unknown Pleasures (Collector's Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0216eb1e685e6bd37ab3228de6","uri":"spotify:track:4ZuC5MfGjRQs3pZtPxqMYP","trackType":"spotify","seek":0,"duration":233,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 14:16:29 jans-volumio volumio[1384]: verbose: CURRENT POSITION 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::syncState stateService play Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:16:29 jans-volumio volumio[1384]: info: Received an update from plugin. extracting info from payload Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::pushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioPushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioGetState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::pushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioPushState Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:16:29 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioGetState Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 13 Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.908+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" state=STATUS_PLAYING positionMs=251262 volume=100 Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.908+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" id=spotify:track:7k42ztYdHyKWrKrENxwjkV title="Atmosphere - 2020 Digital Remaster" Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.910+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" state=STATUS_PLAYING positionMs=251262 volume=100 Feb 24 14:16:29 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:29.910+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" id=spotify:track:7k42ztYdHyKWrKrENxwjkV title="Atmosphere - 2020 Digital Remaster" Feb 24 14:16:29 jans-volumio volumio[1384]: info: CoreStateMachine::startPlaybackTimer Feb 24 14:16:29 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 14 Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 14:16:30 jans-volumio volumio[1384]: info: Discovery: Getting this device information Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioGetState Feb 24 14:16:30 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 14 Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 14:16:30 jans-volumio volumio[1384]: verbose: New Socket.io Connection to 192.168.1.29:3000 from 192.168.1.117 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreStateMachine::pushState Feb 24 14:16:30 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 14 Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioPushState Feb 24 14:16:30 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:16:30 jans-volumio volumio[1384]: info: MRS: Pushing multiroomSync output Feb 24 14:16:30 jans-volumio volumio[1384]: info: CoreCommandRouter::volumioGetState Feb 24 14:16:30 jans-volumio volumio[1384]: info: CorePlayQueue::getTrack 14 Feb 24 14:16:30 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:30.499+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" state=STATUS_PLAYING positionMs=500 volume=100 Feb 24 14:16:30 jans-volumio volumio5-onboarding[1772]: time=2026-02-24T14:16:30.499+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:44384 @ 0xc0002d1860" id=spotify:track:4ZuC5MfGjRQs3pZtPxqMYP title="Shadowplay - 2007 Remaster" Feb 24 14:16:38 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:38+01:00" level=trace msg="received accesspoint ping" Feb 24 14:16:38 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:38+01:00" level=trace msg="received accesspoint pong ack" Feb 24 14:16:38 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:38+01:00" level=trace msg="sent dealer ping" Feb 24 14:16:38 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:38+01:00" level=trace msg="received dealer pong" Feb 24 14:16:42 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 24 14:16:42 jans-volumio volumio[1384]: info: In handleBrowseUri, curUri=spotify Feb 24 14:16:42 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:16:42 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:16:42 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:16:42 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:16:44 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:44+01:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:16:56 jans-volumio go-librespot[15432]: time="2026-02-24T14:16:56+01:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:17:01 jans-volumio volumio[1384]: Searching plugin music_service/spop Feb 24 14:17:01 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 24 14:17:02 jans-volumio volumio[1384]: info: All search sources collected, pushing search results Feb 24 14:17:03 jans-volumio volumio[1384]: Searching plugin music_service/spop Feb 24 14:17:03 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 24 14:17:04 jans-volumio volumio[1384]: info: All search sources collected, pushing search results Feb 24 14:17:07 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:07+01:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:17:08 jans-volumio volumio[1384]: Searching plugin music_service/spop Feb 24 14:17:08 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 24 14:17:08 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:08+01:00" level=trace msg="sent dealer ping" Feb 24 14:17:08 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:08+01:00" level=trace msg="received dealer pong" Feb 24 14:17:09 jans-volumio volumio[1384]: info: All search sources collected, pushing search results Feb 24 14:17:10 jans-volumio volumio[1384]: Searching plugin music_service/spop Feb 24 14:17:10 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 24 14:17:10 jans-volumio volumio[1384]: info: All search sources collected, pushing search results Feb 24 14:17:14 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 24 14:17:14 jans-volumio volumio[1384]: info: In handleBrowseUri, curUri=spotify:artist:3iO5aVYkBcrQEGZwCfiBXb Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:01Hv9WX6Rjei88PgYokrGQ Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:4onJCqz3u3N7Rh0R4YAh7Y Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:243TPBDh7WHPanE4Q2SNxf Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:2wcy8Ocv8Dh9Wff3VSTTjG Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:5CQ87rpGo6alV70cmEZx8I Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:4oECVGBZGZbTwHKi6zhKVF Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:7qDk1LdYdfOxb1yNZHZ3cu Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:7f8zuGmlJ7M8pNSV2FIJ56 Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:2oIhce3JoKJQV8LC5CF3w5 Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preloading song: spotify:track:2WFLIA5N6Q7d35NfefYdvN Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:17:15 jans-volumio volumio[1384]: info: Preload queue cleared Feb 24 14:17:15 jans-volumio volumio[1384]: info: Executing endpoint getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: Executing endpoint getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: Executing endpoint getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: Executing endpoint getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:17:15 jans-volumio volumio[1384]: info: Executing endpoint metavolumio Feb 24 14:17:15 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:17:15 jans-volumio volumio[1384]: info: Executing endpoint metavolumio Feb 24 14:17:15 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:17:16 jans-volumio volumio[1384]: info: Executing endpoint metavolumio Feb 24 14:17:16 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:17:16 jans-volumio volumio[1384]: info: Executing endpoint metavolumio Feb 24 14:17:16 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:17:20 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:20+01:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:17:33 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:33+01:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:17:38 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:38+01:00" level=trace msg="sent dealer ping" Feb 24 14:17:38 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:38+01:00" level=trace msg="received dealer pong" Feb 24 14:17:46 jans-volumio go-librespot[15432]: time="2026-02-24T14:17:46+01:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:4ZuC5MfGjRQs3pZtPxqMYP" Feb 24 14:17:51 jans-volumio volumio[1384]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 24 14:17:51 jans-volumio volumio[1384]: info: In handleBrowseUri, curUri=spotify:artist:1rFWDtcMdp7qz2EtOBu0xJ Feb 24 14:17:51 jans-volumio volumio[1384]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 14:17:51 jans-volumio volumio[1384]: TypeError: Cannot read properties of undefined (reading 'url') Feb 24 14:17:51 jans-volumio volumio[1384]: at /data/plugins/music_service/spop/index.js:2449:60 Feb 24 14:17:51 jans-volumio volumio[1384]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 24 14:17:51 jans-volumio volumio[1384]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 14:17:51 jans-volumio sudo[21403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-24 14:16' Feb 24 14:17:51 jans-volumio sudo[21403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"