-- Logs begin at Thu 2019-02-14 13:11:58 +03, end at Wed 2025-11-05 01:58:10 +03. -- Nov 05 01:57:08 volumio go-librespot[16629]: time="2025-11-05T01:57:08+03:00" level=debug msg="fetched chunk 11/12, size: 524288" uri="spotify:track:2gtEcc5Beh1U3E0iQdzlCK" Nov 05 01:57:15 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp manualdelay Nov 05 01:57:15 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , manualdelay Nov 05 01:57:15 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:15 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:15 volumio volumio[16368]: info: FusionDsp - Choose a preset Nov 05 01:57:15 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:57:15 volumio go-librespot[16629]: time="2025-11-05T01:57:15+03:00" level=trace msg="sent dealer ping" Nov 05 01:57:16 volumio go-librespot[16629]: time="2025-11-05T01:57:16+03:00" level=trace msg="received dealer pong" Nov 05 01:57:18 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp speakerdistance Nov 05 01:57:18 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , speakerdistance Nov 05 01:57:18 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:18 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:18 volumio volumio[16368]: info: FusionDsp - Choose a preset Nov 05 01:57:18 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:57:20 volumio go-librespot[16629]: time="2025-11-05T01:57:20+03:00" level=debug msg="fetched chunk 12/12, size: 461859" uri="spotify:track:2gtEcc5Beh1U3E0iQdzlCK" Nov 05 01:57:25 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp lesssettings Nov 05 01:57:25 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , lesssettings Nov 05 01:57:25 volumio volumio[16368]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 05 01:57:25 volumio volumio[16368]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 05 01:57:25 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:25 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:25 volumio volumio[16368]: info: FusionDsp - Choose a preset Nov 05 01:57:25 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:57:27 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp saveparameq [object Object] Nov 05 01:57:27 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , saveparameq Nov 05 01:57:28 volumio volumio[16368]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 05 01:57:28 volumio volumio[16368]: error: FusionDsp - WebSocket error: [object Object] Nov 05 01:57:28 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:28 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:28 volumio volumio[16368]: info: FusionDsp - no preset used Nov 05 01:57:28 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:57:36 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp saveparameq [object Object] Nov 05 01:57:36 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , saveparameq Nov 05 01:57:36 volumio volumio[16368]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 05 01:57:36 volumio volumio[16368]: error: FusionDsp - WebSocket error: [object Object] Nov 05 01:57:36 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:36 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:36 volumio volumio[16368]: info: FusionDsp - no preset used Nov 05 01:57:37 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:57:45 volumio go-librespot[16629]: time="2025-11-05T01:57:45+03:00" level=trace msg="sent dealer ping" Nov 05 01:57:46 volumio go-librespot[16629]: time="2025-11-05T01:57:46+03:00" level=trace msg="received dealer pong" Nov 05 01:57:46 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp usethispreset [object Object] Nov 05 01:57:46 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , usethispreset Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - Value for usedpreset: Nov 05 01:57:46 volumio volumio[16368]: error: FusionDsp - Value reading JSON file: {"geq15":"0,-1,-2,-2,-2,0,1,2,0,-1,-1,-1,-1,1,2","x2geq15":"0,-1,-2,-2,-2,0,1,2,0,-1,-1,-1,-1,1,2","state4preset":["None",false,false,50,0,0,0,"None",true,false,false,0,0,false]} Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - geq15 0,-1,-2,-2,-2,0,1,2,0,-1,-1,-1,-1,1,2 Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - value state4preset None,false,false,50,0,0,0,None,true,false,false,0,0,false Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 05 01:57:46 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:46 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - Classic-FusionDsp Nov 05 01:57:46 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:57:51 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp usethispreset [object Object] Nov 05 01:57:51 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , usethispreset Nov 05 01:57:51 volumio volumio[16368]: info: FusionDsp - Value for usedpreset: Nov 05 01:57:51 volumio volumio[16368]: error: FusionDsp - Value reading JSON file: {"geq15":"-0.5,1,1.5,1,0.5,1.5,1,0.5,-0.5,-1,-1,1,2,2,1.5","x2geq15":"-0.5,1,1.5,1,0.5,1.5,1,0.5,-0.5,-1,-1,1,2,2,1.5","state4preset":["None",false,false,50,0,0,0,"None",true,false,false,0,0,false]} Nov 05 01:57:51 volumio volumio[16368]: info: FusionDsp - geq15 -0.5,1,1.5,1,0.5,1.5,1,0.5,-0.5,-1,-1,1,2,2,1.5 Nov 05 01:57:51 volumio volumio[16368]: info: FusionDsp - value state4preset None,false,false,50,0,0,0,None,true,false,false,0,0,false Nov 05 01:57:51 volumio volumio[16368]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 05 01:57:51 volumio volumio[16368]: error: FusionDsp - WebSocket error: [object Object] Nov 05 01:57:52 volumio volumio[16368]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 05 01:57:52 volumio volumio[16368]: info: CoreCommandRouter::Close All Modals sent Nov 05 01:57:52 volumio volumio[16368]: info: FusionDsp - Rock-FusionDsp Nov 05 01:57:52 volumio volumio[16368]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Nov 05 01:58:01 volumio volumio[16368]: info: CorePlayQueue::getTrack 2 Nov 05 01:58:01 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:01 volumio volumio[16368]: info: Prefetching next song Nov 05 01:58:01 volumio volumio[16368]: info: [1762297081590] ControllerSpotify::prefetch Nov 05 01:58:01 volumio volumio[16368]: info: Sending Spotify command with payload to local API: /player/add_to_queue Nov 05 01:58:01 volumio go-librespot[16629]: time="2025-11-05T01:58:01+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:01 volumio go-librespot[16629]: time="2025-11-05T01:58:01+03:00" level=debug msg="prefetching next track" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:01 volumio go-librespot[16629]: time="2025-11-05T01:58:01+03:00" level=debug msg="selected format OGG_VORBIS_320 (6a38d2f7b3bb7dccfe2a3315aea5730146554797)" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:01 volumio go-librespot[16629]: time="2025-11-05T01:58:01+03:00" level=debug msg="requested aes key for file 6a38d2f7b3bb7dccfe2a3315aea5730146554797, gid: 2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:01 volumio go-librespot[16629]: time="2025-11-05T01:58:01+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:02 volumio go-librespot[16629]: time="2025-11-05T01:58:02+03:00" level=debug msg="fetched first chunk of 13, total size is 6567076 bytes" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:02 volumio go-librespot[16629]: time="2025-11-05T01:58:02+03:00" level=info msg="prefetched track \"Yerin Dolmuyor\" (duration: 154940ms)" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:02 volumio go-librespot[16629]: time="2025-11-05T01:58:02+03:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:02 volumio go-librespot[16629]: time="2025-11-05T01:58:02+03:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:02 volumio go-librespot[16629]: time="2025-11-05T01:58:02+03:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:04 volumio volumio[16368]: info: CALLMETHOD: audio_interface fusiondsp resampling [object Object] Nov 05 01:58:04 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , resampling Nov 05 01:58:04 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 05 01:58:04 volumio volumio[16368]: info: FusionDsp - Resampling 44100Hz ++ Nov 05 01:58:04 volumio volumio[16368]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 05 01:58:04 volumio volumio[16368]: error: FusionDsp - WebSocket error: [object Object] Nov 05 01:58:06 volumio volumio[16368]: info: CoreStateMachine::startPlaybackTimer Nov 05 01:58:06 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:06 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:06 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:06 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 05 01:58:06 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:06 volumio volumio[16368]: info: [ASDebug] CurState: play PrevState: play Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=trace msg="emitting websocket event: not_playing" Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:2RlpOjMTH17Gf0F0AM40Lw","uri":"spotify:track:2gtEcc5Beh1U3E0iQdzlCK","play_origin":"go-librespot"}} Nov 05 01:58:06 volumio volumio[16368]: error: Failed to decode event: not_playing Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=trace msg="emitting websocket event: will_play" Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=info msg="loaded track \"Yerin Dolmuyor\" (paused: false, position: 0ms, duration: 154940ms, prefetched: true)" uri="spotify:track:2xVM712dqGiYhbBCeRlMkl" Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:2RlpOjMTH17Gf0F0AM40Lw","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","play_origin":"go-librespot"}} Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=trace msg="scheduling prefetch in 125s" Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=trace msg="emitting websocket event: metadata" Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","name":"Yerin Dolmuyor","artist_names":["Salman Tin","Fatma Turgut"],"album_name":"Yerin Dolmuyor","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0223c37155f48e47db4a355435","position":0,"duration":154940,"release_date":"year:2025 month:10 day:24","track_number":1,"disc_number":1}} Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:06 volumio go-librespot[16629]: time="2025-11-05T01:58:06+03:00" level=trace msg="emitting websocket event: playing" Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:2RlpOjMTH17Gf0F0AM40Lw","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","resume":false,"play_origin":"go-librespot"}} Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: PUSH STATE SPOTIFY Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: {"status":"play","service":"spop","title":"Yerin Dolmuyor","artist":"Salman Tin, Fatma Turgut","album":"Yerin Dolmuyor","albumart":"https://i.scdn.co/image/ab67616d00001e0223c37155f48e47db4a355435","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","trackType":"spotify","seek":0,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 05 01:58:06 volumio volumio[16368]: info: CoreCommandRouter::servicePushState Nov 05 01:58:06 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:06 volumio volumio[16368]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Yerin Dolmuyor","artist":"Salman Tin, Fatma Turgut","album":"Yerin Dolmuyor","albumart":"https://i.scdn.co/image/ab67616d00001e0223c37155f48e47db4a355435","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","trackType":"spotify","seek":0,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 05 01:58:06 volumio volumio[16368]: verbose: CURRENT POSITION 3 Nov 05 01:58:06 volumio volumio[16368]: info: CoreStateMachine::syncState stateService play Nov 05 01:58:06 volumio volumio[16368]: info: CoreStateMachine::syncState currentStatus play Nov 05 01:58:06 volumio volumio[16368]: info: Received an update from plugin. extracting info from payload Nov 05 01:58:06 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:06 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:06 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 05 01:58:06 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:06 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:06 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:06 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:06 volumio volumio[16368]: info: [ASDebug] CurState: play PrevState: play Nov 05 01:58:06 volumio volumio[16368]: info: [ASDebug] CurState: play PrevState: play Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:06 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: PUSH STATE SPOTIFY Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: {"status":"play","service":"spop","title":"Yerin Dolmuyor","artist":"Salman Tin, Fatma Turgut","album":"Yerin Dolmuyor","albumart":"https://i.scdn.co/image/ab67616d00001e0223c37155f48e47db4a355435","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","trackType":"spotify","seek":0,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 05 01:58:07 volumio volumio[16368]: info: CoreCommandRouter::servicePushState Nov 05 01:58:07 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:07 volumio volumio[16368]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Yerin Dolmuyor","artist":"Salman Tin, Fatma Turgut","album":"Yerin Dolmuyor","albumart":"https://i.scdn.co/image/ab67616d00001e0223c37155f48e47db4a355435","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","trackType":"spotify","seek":0,"duration":154,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 05 01:58:07 volumio volumio[16368]: verbose: CURRENT POSITION 3 Nov 05 01:58:07 volumio volumio[16368]: info: CoreStateMachine::syncState stateService play Nov 05 01:58:07 volumio volumio[16368]: info: CoreStateMachine::syncState currentStatus play Nov 05 01:58:07 volumio volumio[16368]: info: Received an update from plugin. extracting info from payload Nov 05 01:58:07 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:07 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:07 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:07 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:07 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:07 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:07 volumio volumio[16368]: info: [ASDebug] CurState: play PrevState: play Nov 05 01:58:07 volumio volumio[16368]: info: [ASDebug] CurState: play PrevState: play Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:07 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::volumioNext Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::next Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::stop Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::stPlaybackTimer Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::updateTrackBlock Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrackBlock Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::serviceStop Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrack 3 Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::serviceStop Nov 05 01:58:09 volumio volumio[16368]: info: Spotify Stop Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: SPOTIFY STOP Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: {"status":"play","position":3,"title":"Yerin Dolmuyor","artist":"Salman Tin","album":"Yerin Dolmuyor","albumart":"https://i.scdn.co/image/ab67616d0000b27323c37155f48e47db4a355435","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","trackType":"spotify","codec":"ogg","seek":0,"duration":154,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 05 01:58:09 volumio volumio[16368]: info: Sending Spotify command to local API: /player/pause Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::play index undefined Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrack 4 Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::startPlaybackTimer Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrack 4 Nov 05 01:58:09 volumio volumio[16368]: info: [1762297089328] ControllerSpotify::clearAddPlayTrack Nov 05 01:58:09 volumio volumio[16368]: info: Sending Spotify command with payload to local API: /player/play Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::updateTrackBlock Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrackBlock Nov 05 01:58:09 volumio volumio[16368]: info: [ASDebug] CurState: stop PrevState: play Nov 05 01:58:09 volumio volumio[16368]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="pause track at 2394ms" Nov 05 01:58:09 volumio volumio[16368]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=trace msg="emitting websocket event: paused" Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:2RlpOjMTH17Gf0F0AM40Lw","uri":"spotify:track:2xVM712dqGiYhbBCeRlMkl","play_origin":"go-librespot"}} Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: PUSH STATE SPOTIFY Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::servicePushState Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrack 4 Nov 05 01:58:09 volumio volumio[16368]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 05 01:58:09 volumio volumio[16368]: verbose: CURRENT POSITION 4 Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::syncState stateService pause Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::syncState currentStatus stop Nov 05 01:58:09 volumio volumio[16368]: info: CoreStateMachine::pushState Nov 05 01:58:09 volumio volumio[16368]: info: CorePlayQueue::getTrack 4 Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 05 01:58:09 volumio volumio[16368]: info: CoreCommandRouter::volumioPushState Nov 05 01:58:09 volumio volumio[16368]: info: [ASDebug] CurState: stop PrevState: play Nov 05 01:58:09 volumio volumio[16368]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: SPOTIFY VOLUME 65 Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: VOLUMIO VOLUME 66 Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="resolved context of track" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=trace msg="emitting websocket event: will_play" Nov 05 01:58:09 volumio volumio[16368]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:4SJjMPowhsrYSWgxM61yxm","uri":"spotify:track:4SJjMPowhsrYSWgxM61yxm","play_origin":"go-librespot"}} Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="selected format OGG_VORBIS_320 (e1adc1203d15160d3503c76647b1fa451aebf438)" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="requested aes key for file e1adc1203d15160d3503c76647b1fa451aebf438, gid: 4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=debug msg="fetched first chunk of 14, total size is 7239887 bytes" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:09 volumio go-librespot[16629]: time="2025-11-05T01:58:09+03:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:4SJjMPowhsrYSWgxM61yxm: ALSA error at snd_pcm_open: Device or resource busy" Nov 05 01:58:09 volumio volumio[16368]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Nov 05 01:58:10 volumio go-librespot[16629]: time="2025-11-05T01:58:10+03:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:10 volumio go-librespot[16629]: time="2025-11-05T01:58:10+03:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:10 volumio go-librespot[16629]: time="2025-11-05T01:58:10+03:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:4SJjMPowhsrYSWgxM61yxm" Nov 05 01:58:10 volumio volumio[16368]: info: [ASDebug] Togle GPIO: OFF Nov 05 01:58:10 volumio volumio[16368]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 05 01:58:10 volumio volumio[16368]: Error: ESPIPE: invalid seek, write Nov 05 01:58:10 volumio volumio[16368]: at Object.writeSync (fs.js:711:3) Nov 05 01:58:10 volumio volumio[16368]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Nov 05 01:58:10 volumio volumio[16368]: at AmpSwitchController.off (/data/plugins/system_controller/ampswitch/index.js:221:23) Nov 05 01:58:10 volumio volumio[16368]: at Timeout._onTimeout (/data/plugins/system_controller/ampswitch/index.js:195:88) Nov 05 01:58:10 volumio volumio[16368]: at listOnTimeout (internal/timers.js:554:17) Nov 05 01:58:10 volumio volumio[16368]: at processTimers (internal/timers.js:497:7) { Nov 05 01:58:10 volumio volumio[16368]: errno: -29, Nov 05 01:58:10 volumio volumio[16368]: syscall: 'write', Nov 05 01:58:10 volumio volumio[16368]: code: 'ESPIPE' Nov 05 01:58:10 volumio volumio[16368]: } Nov 05 01:58:10 volumio volumio[16368]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 05 01:58:10 volumio sudo[6756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-05 01:57 Nov 05 01:58:10 volumio sudo[6756]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"