Mar 28 08:10:04 volumio go-librespot[1634]: time="2026-03-28T08:10:04+07:00" level=debug msg="fetched chunk 16/26, size: 524288" uri="spotify:track:39seDNDfTOVEReqnJASkkm" Mar 28 08:10:07 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:07 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:08 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:08 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:08 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:09 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:11 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:11 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:11 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:14 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:14 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:15 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:16 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:16 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:17 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:18 volumio go-librespot[1634]: time="2026-03-28T08:10:18+07:00" level=debug msg="fetched chunk 17/26, size: 524288" uri="spotify:track:39seDNDfTOVEReqnJASkkm" Mar 28 08:10:18 volumio go-librespot[1634]: time="2026-03-28T08:10:18+07:00" level=trace msg="sent dealer ping" Mar 28 08:10:18 volumio go-librespot[1634]: time="2026-03-28T08:10:18+07:00" level=trace msg="received dealer pong" Mar 28 08:10:29 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:29 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:30 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:31 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:31 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:32 volumio go-librespot[1634]: time="2026-03-28T08:10:32+07:00" level=debug msg="fetched chunk 18/26, size: 524288" uri="spotify:track:39seDNDfTOVEReqnJASkkm" Mar 28 08:10:32 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:33 volumio volumio[1202]: Searching plugin music_service/spop Mar 28 08:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 28 08:10:34 volumio volumio[1202]: info: All search sources collected, pushing search results Mar 28 08:10:41 volumio volumio[1202]: info: Preload queue cleared Mar 28 08:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::ClearQueue Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::stop Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::stPlaybackTimer Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::updateTrackBlock Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrackBlock Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrack 1 Mar 28 08:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 08:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrack 1 Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::serviceStop Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrack 1 Mar 28 08:10:41 volumio volumio[1202]: info: CoreCommandRouter::serviceStop Mar 28 08:10:41 volumio volumio[1202]: info: Spotify Stop Mar 28 08:10:41 volumio volumio[1202]: SPOTIFY: SPOTIFY STOP Mar 28 08:10:41 volumio volumio[1202]: SPOTIFY: {"status":"play","position":1,"title":"Emotionally Yours - Live at Madison Square Garden, New York, NY - October 1992","artist":"The O'Jays","album":"Bob Dylan - 30th Anniversary Concert Celebration [(Deluxe Edition) [Remastered]]","albumart":"https://i.scdn.co/image/ab67616d0000b27383d8116743c8b818a18666c5","uri":"spotify:track:39seDNDfTOVEReqnJASkkm","trackType":"spotify","codec":"ogg","seek":1,"duration":343,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Mar 28 08:10:41 volumio volumio[1202]: info: Sending Spotify command to local API: /player/pause Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::clearPlayQueue Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::saveQueue Mar 28 08:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioPushQueue Mar 28 08:10:41 volumio volumio[1202]: info: CoreStateMachine::addQueueItems Mar 28 08:10:41 volumio volumio[1202]: info: CorePlayQueue::addQueueItems Mar 28 08:10:41 volumio volumio[1202]: info: Preload queue cleared Mar 28 08:10:41 volumio volumio[1202]: info: Adding Item to queue: spotify:artist:67PZTxaHKMZBFRUh8wIzCy Mar 28 08:10:41 volumio volumio[1202]: info: Exploding uri spotify:artist:67PZTxaHKMZBFRUh8wIzCy in service spop Mar 28 08:10:41 volumio volumio[1202]: SPOTIFY: EXPLODING URI:spotify:artist:67PZTxaHKMZBFRUh8wIzCy Mar 28 08:10:41 volumio go-librespot[1634]: time="2026-03-28T08:10:41+07:00" level=debug msg="pause track at 204624ms" Mar 28 08:10:42 volumio go-librespot[1634]: time="2026-03-28T08:10:42+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:42 volumio volumio[1202]: info: Preload queue cleared Mar 28 08:10:42 volumio volumio[1202]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::ClearQueue Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::stop Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:42 volumio volumio[1202]: info: CorePlayQueue::clearPlayQueue Mar 28 08:10:42 volumio volumio[1202]: info: CorePlayQueue::saveQueue Mar 28 08:10:42 volumio volumio[1202]: info: CoreCommandRouter::volumioPushQueue Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::addQueueItems Mar 28 08:10:42 volumio volumio[1202]: info: CorePlayQueue::addQueueItems Mar 28 08:10:42 volumio volumio[1202]: info: Preload queue cleared Mar 28 08:10:42 volumio volumio[1202]: info: Adding Item to queue: spotify:artist:67PZTxaHKMZBFRUh8wIzCy Mar 28 08:10:42 volumio volumio[1202]: info: Exploding uri spotify:artist:67PZTxaHKMZBFRUh8wIzCy in service spop Mar 28 08:10:42 volumio volumio[1202]: SPOTIFY: EXPLODING URI:spotify:artist:67PZTxaHKMZBFRUh8wIzCy Mar 28 08:10:42 volumio go-librespot[1634]: time="2026-03-28T08:10:42+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:42 volumio go-librespot[1634]: time="2026-03-28T08:10:42+07:00" level=trace msg="emitting websocket event: paused" Mar 28 08:10:42 volumio volumio[1202]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:39seDNDfTOVEReqnJASkkm","uri":"spotify:track:39seDNDfTOVEReqnJASkkm","play_origin":"go-librespot"}} Mar 28 08:10:42 volumio volumio[1202]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 08:10:42 volumio volumio[1202]: SPOTIFY: {"status":"pause","service":"spop","title":"Emotionally Yours - Live at Madison Square Garden, New York, NY - October 1992","artist":"The O'Jays","album":"Bob Dylan - 30th Anniversary Concert Celebration [(Deluxe Edition) [Remastered]]","albumart":"https://i.scdn.co/image/ab67616d00001e0283d8116743c8b818a18666c5","uri":"spotify:track:39seDNDfTOVEReqnJASkkm","trackType":"spotify","seek":204001,"duration":343,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:42 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Mar 28 08:10:42 volumio volumio[1202]: info: CorePlayQueue::getTrack 1 Mar 28 08:10:42 volumio volumio[1202]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Emotionally Yours - Live at Madison Square Garden, New York, NY - October 1992","artist":"The O'Jays","album":"Bob Dylan - 30th Anniversary Concert Celebration [(Deluxe Edition) [Remastered]]","albumart":"https://i.scdn.co/image/ab67616d00001e0283d8116743c8b818a18666c5","uri":"spotify:track:39seDNDfTOVEReqnJASkkm","trackType":"spotify","seek":204001,"duration":343,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:42 volumio volumio[1202]: verbose: CURRENT POSITION 1 Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::syncState stateService pause Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus stop Mar 28 08:10:42 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:42 volumio volumio[1202]: info: CorePlayQueue::getTrack 1 Mar 28 08:10:42 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 08:10:42 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:42 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:42 volumio volumio[1202]: info: CorePlayQueue::getTrack 1 Mar 28 08:10:42 volumio volumio[1202]: info: camilladsp respawn in 100 ms (attempt 1/10) Mar 28 08:10:43 volumio volumio[1202]: info: CoreCommandRouter::volumioPushQueue Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::saveQueue Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::updateTrackBlock Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrackBlock Mar 28 08:10:43 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::play index 0 Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::stop Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::play index undefined Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:43 volumio volumio[1202]: info: [1774660243329] ControllerSpotify::clearAddPlayTrack Mar 28 08:10:43 volumio volumio[1202]: info: Sending Spotify command with payload to local API: /player/play Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=debug msg="resolved context of track" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:43 volumio volumio[1202]: info: CoreCommandRouter::volumioPushQueue Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::saveQueue Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::updateTrackBlock Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrackBlock Mar 28 08:10:43 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::play index 0 Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::stop Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::play index undefined Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:43 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Mar 28 08:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:43 volumio volumio[1202]: info: [1774660243496] ControllerSpotify::clearAddPlayTrack Mar 28 08:10:43 volumio volumio[1202]: info: Sending Spotify command with payload to local API: /player/play Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=trace msg="emitting websocket event: will_play" Mar 28 08:10:43 volumio volumio[1202]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","play_origin":"go-librespot"}} Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=debug msg="selected format OGG_VORBIS_320 (237e65422a59dd47be70cab5e5a24116cae273fe)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=debug msg="requested aes key for file 237e65422a59dd47be70cab5e5a24116cae273fe, gid: 75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:43 volumio go-librespot[1634]: time="2026-03-28T08:10:43+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched first chunk of 20, total size is 10380544 bytes" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=info msg="loaded track \"Naima\" (paused: false, position: 0ms, duration: 262906ms, prefetched: false)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="scheduling prefetch in 232s" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="emitting websocket event: metadata" Mar 28 08:10:44 volumio volumio[1202]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","name":"Naima","artist_names":["John Coltrane Quartet"],"album_name":"Giant Step (Plus Bonus)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","position":0,"duration":262906,"release_date":"year:2010 month:1 day:1","track_number":7,"disc_number":1}} Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="resolved context of track" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio volumio[1202]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 28 08:10:44 volumio volumio[1202]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="emitting websocket event: will_play" Mar 28 08:10:44 volumio volumio[1202]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","play_origin":"go-librespot"}} Mar 28 08:10:44 volumio volumio[1202]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 28 08:10:44 volumio volumio[1202]: info: FusionDsp - Effects disabled Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="selected format OGG_VORBIS_320 (237e65422a59dd47be70cab5e5a24116cae273fe)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="requested aes key for file 237e65422a59dd47be70cab5e5a24116cae273fe, gid: 75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched first chunk of 20, total size is 10380544 bytes" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=info msg="loaded track \"Naima\" (paused: false, position: 1ms, duration: 262906ms, prefetched: false)" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="scheduling prefetch in 233s" Mar 28 08:10:44 volumio go-librespot[1634]: time="2026-03-28T08:10:44+07:00" level=trace msg="emitting websocket event: metadata" Mar 28 08:10:44 volumio volumio[1202]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","name":"Naima","artist_names":["John Coltrane Quartet"],"album_name":"Giant Step (Plus Bonus)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","position":1,"duration":262906,"release_date":"year:2010 month:1 day:1","track_number":7,"disc_number":1}} Mar 28 08:10:45 volumio go-librespot[1634]: time="2026-03-28T08:10:45+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:45 volumio go-librespot[1634]: time="2026-03-28T08:10:45+07:00" level=trace msg="emitting websocket event: playing" Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","resume":false,"play_origin":"go-librespot"}} Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: verbose: CURRENT POSITION 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus stop Mar 28 08:10:45 volumio go-librespot[1634]: time="2026-03-28T08:10:45+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 08:10:45 volumio go-librespot[1634]: time="2026-03-28T08:10:45+07:00" level=trace msg="emitting websocket event: playing" Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","resume":false,"play_origin":"go-librespot"}} Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: verbose: CURRENT POSITION 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Mar 28 08:10:45 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: verbose: CURRENT POSITION 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Mar 28 08:10:45 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: PUSH STATE SPOTIFY Mar 28 08:10:45 volumio volumio[1202]: SPOTIFY: {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Naima","artist":"John Coltrane Quartet","album":"Giant Step (Plus Bonus)","albumart":"https://i.scdn.co/image/ab67616d00001e02b5a6fb2792b875de77aef175","uri":"spotify:track:75AtxYxVGGKTcopoB4kUU8","trackType":"spotify","seek":1,"duration":262,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 28 08:10:45 volumio volumio[1202]: verbose: CURRENT POSITION 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Mar 28 08:10:45 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreStateMachine::pushState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Mar 28 08:10:45 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Mar 28 08:10:45 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Mar 28 08:10:48 volumio go-librespot[1634]: time="2026-03-28T08:10:48+07:00" level=trace msg="sent dealer ping" Mar 28 08:10:48 volumio go-librespot[1634]: time="2026-03-28T08:10:48+07:00" level=trace msg="received dealer pong" Mar 28 08:10:56 volumio go-librespot[1634]: time="2026-03-28T08:10:56+07:00" level=trace msg="received accesspoint ping" Mar 28 08:10:56 volumio go-librespot[1634]: time="2026-03-28T08:10:56+07:00" level=trace msg="received accesspoint pong ack" Mar 28 08:10:57 volumio go-librespot[1634]: time="2026-03-28T08:10:57+07:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:11:10 volumio go-librespot[1634]: time="2026-03-28T08:11:10+07:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:75AtxYxVGGKTcopoB4kUU8" Mar 28 08:11:14 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 28 08:11:14 volumio volumio[1202]: info: In handleBrowseUri, curUri=spotify:artist:2zqU9R9jjSlHk1VMWKoA5t Mar 28 08:11:14 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 28 08:11:14 volumio volumio[1202]: info: In handleBrowseUri, curUri=spotify:artist:2zqU9R9jjSlHk1VMWKoA5t Mar 28 08:11:15 volumio volumio[1202]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 08:11:15 volumio volumio[1202]: TypeError: Cannot read properties of undefined (reading 'url') Mar 28 08:11:15 volumio volumio[1202]: at /data/plugins/music_service/spop/index.js:2446:60 Mar 28 08:11:15 volumio volumio[1202]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Mar 28 08:11:15 volumio volumio[1202]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 08:11:16 volumio sudo[8949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 08:10' Mar 28 08:11:16 volumio sudo[8949]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"