-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-03-16 13:14:41 CET. -- Mar 16 13:13:06 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 16 13:13:06 volumio volumio[1032]: info: In handleBrowseUri, curUri=spotify:artist:21duhyZJK8hendNaT1yM7p Mar 16 13:13:07 volumio volumio[1032]: info: Preload queue cleared Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:0waBylEcT3qE24oV7eJ22A Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:5uayvDikecabF24o3OaHic Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:1v6fhWYoiXlD8R6NK1w6rf Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:4oVNZU59Y4HCFQrdUgI4tq Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:6v16FtEHrTrkkRBSaLgaWY Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:1tL72b2eZcP5kSoig9ZJVz Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:71FmLbDJvjuoLvw65gOfz0 Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:0Pez1fxynZTjUXcXPrC9a4 Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:0X7oNwr7DIuYtvvv7xc7Eg Mar 16 13:13:07 volumio volumio[1032]: info: Preloading song: spotify:track:58pLt0N4Q6YwLtWIZkuGhU Mar 16 13:13:07 volumio volumio[1032]: info: Preload queue cleared Mar 16 13:13:38 volumio volumio[1032]: info: CorePlayQueue::getTrack 0 Mar 16 13:13:38 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:38 volumio volumio[1032]: info: Prefetching next song Mar 16 13:13:43 volumio go-librespot[1275]: time="2025-03-16T13:13:43+01:00" level=trace msg="emitting websocket event: not_playing" Mar 16 13:13:43 volumio go-librespot[1275]: time="2025-03-16T13:13:43+01:00" level=debug msg="loading track spotify:track:7yyaaonjoDFFtgRB1nkjbH (paused: true, position: 0ms)" Mar 16 13:13:43 volumio volumio[1032]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:7yyaaonjoDFFtgRB1nkjbH","play_origin":"go-librespot"}} Mar 16 13:13:43 volumio volumio[1032]: error: Failed to decode event: not_playing Mar 16 13:13:43 volumio go-librespot[1275]: time="2025-03-16T13:13:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:43 volumio go-librespot[1275]: time="2025-03-16T13:13:43+01:00" level=trace msg="emitting websocket event: will_play" Mar 16 13:13:43 volumio volumio[1032]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7yyaaonjoDFFtgRB1nkjbH","play_origin":"go-librespot"}} Mar 16 13:13:43 volumio go-librespot[1275]: time="2025-03-16T13:13:43+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:7yyaaonjoDFFtgRB1nkjbH" Mar 16 13:13:43 volumio go-librespot[1275]: time="2025-03-16T13:13:43+01:00" level=debug msg="requested aes key for file d424fbb50d2d5b4d053f2134f7f32a32932cc238, gid: 7yyaaonjoDFFtgRB1nkjbH" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="fetched first chunk of 13, total size is 6740441 bytes" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Mar 16 13:13:44 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=info msg="loaded track \"Kluska\" (uri: spotify:track:7yyaaonjoDFFtgRB1nkjbH, paused: true, position: 0ms, duration: 217798ms)" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=trace msg="emitting websocket event: metadata" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=trace msg="emitting websocket event: stopped" Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7yyaaonjoDFFtgRB1nkjbH","name":"Kluska","artist_names":["Ranko Ukulele"],"album_name":"Piosenki z bazgrołkami","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","position":0,"duration":217798,"release_date":"year:2020 month:1 day:20","track_number":7,"disc_number":1}} Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}} Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: {"status":"stop","service":"spop","title":"Kluska","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","uri":"spotify:track:7yyaaonjoDFFtgRB1nkjbH","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 0 Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 0 Mar 16 13:13:44 volumio volumio[1032]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Kluska","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","uri":"spotify:track:7yyaaonjoDFFtgRB1nkjbH","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:44 volumio volumio[1032]: verbose: CURRENT POSITION 0 Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::syncState stateService stop Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus play Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::play index undefined Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::startPlaybackTimer Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:44 volumio volumio[1032]: info: [1742127224252] ControllerSpotify::clearAddPlayTrack Mar 16 13:13:44 volumio volumio[1032]: info: Sending Spotify command with payload to local API: /player/play Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=trace msg="emitting websocket event: paused" Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7yyaaonjoDFFtgRB1nkjbH","play_origin":"go-librespot"}} Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:44 volumio volumio[1032]: 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} Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:44 volumio volumio[1032]: 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} Mar 16 13:13:44 volumio volumio[1032]: verbose: CURRENT POSITION 1 Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::syncState stateService pause Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus stop Mar 16 13:13:44 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:44 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:44 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="fetched chunk 1/12, size: 524288" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="loading track spotify:track:65pbRWEDI0fVyzGKluwTdY (paused: false, position: 0ms)" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=trace msg="emitting websocket event: will_play" Mar 16 13:13:44 volumio volumio[1032]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","play_origin":"go-librespot"}} Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:65pbRWEDI0fVyzGKluwTdY" Mar 16 13:13:44 volumio go-librespot[1275]: time="2025-03-16T13:13:44+01:00" level=debug msg="requested aes key for file 373fa99689eb49ad3d98998cd45d76081c0b4d99, gid: 65pbRWEDI0fVyzGKluwTdY" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="fetched chunk 3/12, size: 524288" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="fetched chunk 2/12, size: 524288" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="fetched first chunk of 7, total size is 3280648 bytes" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Mar 16 13:13:45 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=info msg="loaded track \"Żaklin\" (uri: spotify:track:65pbRWEDI0fVyzGKluwTdY, paused: false, position: 0ms, duration: 101587ms)" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=trace msg="emitting websocket event: metadata" Mar 16 13:13:45 volumio volumio[1032]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","name":"Żaklin","artist_names":["Ranko Ukulele"],"album_name":"Piosenki z bazgrołkami","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","position":0,"duration":101587,"release_date":"year:2020 month:1 day:20","track_number":1,"disc_number":1}} Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="fetched chunk 3/6, size: 524288" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="fetched chunk 2/6, size: 524288" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=trace msg="emitting websocket event: playing" Mar 16 13:13:45 volumio volumio[1032]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","play_origin":"go-librespot"}} Mar 16 13:13:45 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:45 volumio volumio[1032]: SPOTIFY: {"status":"play","service":"spop","title":"Żaklin","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","trackType":"spotify","seek":0,"duration":101,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:45 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:45 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:45 volumio volumio[1032]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Żaklin","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","trackType":"spotify","seek":0,"duration":101,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:45 volumio volumio[1032]: verbose: CURRENT POSITION 1 Mar 16 13:13:45 volumio volumio[1032]: info: CoreStateMachine::syncState stateService play Mar 16 13:13:45 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus stop Mar 16 13:13:45 volumio go-librespot[1275]: time="2025-03-16T13:13:45+01:00" level=debug msg="fetched chunk 1/6, size: 524288" Mar 16 13:13:46 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:46 volumio volumio[1032]: SPOTIFY: {"status":"play","service":"spop","title":"Żaklin","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","trackType":"spotify","seek":0,"duration":101,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:46 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:46 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:46 volumio volumio[1032]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Żaklin","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d00001e029206e8dac0916ce88428c771","uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","trackType":"spotify","seek":0,"duration":101,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:46 volumio volumio[1032]: verbose: CURRENT POSITION 1 Mar 16 13:13:46 volumio volumio[1032]: info: CoreStateMachine::syncState stateService play Mar 16 13:13:46 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus play Mar 16 13:13:46 volumio volumio[1032]: info: Received an update from plugin. extracting info from payload Mar 16 13:13:46 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:46 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:46 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:46 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:46 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:46 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:46 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:46 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:46 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:47 volumio volumio[1032]: info: Preload queue cleared Mar 16 13:13:47 volumio volumio[1032]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::ClearQueue Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::stop Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::stPlaybackTimer Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::updateTrackBlock Mar 16 13:13:47 volumio volumio[1032]: info: CorePlayQueue::getTrackBlock Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:47 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:47 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:47 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::serviceStop Mar 16 13:13:47 volumio volumio[1032]: info: CorePlayQueue::getTrack 1 Mar 16 13:13:47 volumio volumio[1032]: info: CoreCommandRouter::serviceStop Mar 16 13:13:47 volumio volumio[1032]: info: Spotify Stop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: SPOTIFY STOP Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: {"status":"play","position":1,"title":"Żaklin","artist":"Ranko Ukulele","album":"Piosenki z bazgrołkami","albumart":"https://i.scdn.co/image/ab67616d0000b2739206e8dac0916ce88428c771","uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","trackType":"spotify","codec":"ogg","seek":0,"duration":101,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":true,"repeatSingle":false,"consume":false,"volume":83,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Mar 16 13:13:47 volumio volumio[1032]: info: Sending Spotify command to local API: /player/pause Mar 16 13:13:47 volumio volumio[1032]: info: CorePlayQueue::clearPlayQueue Mar 16 13:13:47 volumio volumio[1032]: info: CorePlayQueue::saveQueue Mar 16 13:13:47 volumio volumio[1032]: info: CoreCommandRouter::volumioPushQueue Mar 16 13:13:47 volumio volumio[1032]: info: CoreStateMachine::addQueueItems Mar 16 13:13:47 volumio volumio[1032]: info: CorePlayQueue::addQueueItems Mar 16 13:13:47 volumio volumio[1032]: info: Preload queue cleared Mar 16 13:13:47 volumio volumio[1032]: info: Adding Item to queue: spotify:track:0waBylEcT3qE24oV7eJ22A Mar 16 13:13:47 volumio volumio[1032]: info: Exploding uri spotify:track:0waBylEcT3qE24oV7eJ22A in service spop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:0waBylEcT3qE24oV7eJ22A Mar 16 13:13:47 volumio volumio[1032]: info: Adding Item to queue: spotify:track:5uayvDikecabF24o3OaHic Mar 16 13:13:47 volumio volumio[1032]: info: Exploding uri spotify:track:5uayvDikecabF24o3OaHic in service spop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:5uayvDikecabF24o3OaHic Mar 16 13:13:47 volumio volumio[1032]: info: Adding Item to queue: spotify:track:1v6fhWYoiXlD8R6NK1w6rf Mar 16 13:13:47 volumio volumio[1032]: info: Exploding uri spotify:track:1v6fhWYoiXlD8R6NK1w6rf in service spop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:1v6fhWYoiXlD8R6NK1w6rf Mar 16 13:13:47 volumio volumio[1032]: info: Adding Item to queue: spotify:track:4oVNZU59Y4HCFQrdUgI4tq Mar 16 13:13:47 volumio volumio[1032]: info: Exploding uri spotify:track:4oVNZU59Y4HCFQrdUgI4tq in service spop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:4oVNZU59Y4HCFQrdUgI4tq Mar 16 13:13:47 volumio volumio[1032]: info: Adding Item to queue: spotify:track:6v16FtEHrTrkkRBSaLgaWY Mar 16 13:13:47 volumio volumio[1032]: info: Exploding uri spotify:track:6v16FtEHrTrkkRBSaLgaWY in service spop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:6v16FtEHrTrkkRBSaLgaWY Mar 16 13:13:47 volumio volumio[1032]: info: Adding Item to queue: spotify:track:1tL72b2eZcP5kSoig9ZJVz Mar 16 13:13:47 volumio volumio[1032]: info: Exploding uri spotify:track:1tL72b2eZcP5kSoig9ZJVz in service spop Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:1tL72b2eZcP5kSoig9ZJVz Mar 16 13:13:47 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:47 volumio go-librespot[1275]: time="2025-03-16T13:13:47+01:00" level=debug msg="pause track at 2739ms" Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6v16FtEHrTrkkRBSaLgaWY","service":"spop","name":"Ballada o Imogenie","artist":"Maciej Zembaty","album":"Piosenki z trumienki","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b2733cade4d54c42fa97a52e141b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","service":"spop","name":"Maleńka, nie wolno żegnać się w ten sposób","artist":"Maciej Zembaty","album":"Ballady Leonarda Cohena","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ecc137f70d6710bc443c9b3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5uayvDikecabF24o3OaHic","service":"spop","name":"Tańcz mnie po miłości kres","artist":"Maciej Zembaty","album":"Alleluja","type":"song","duration":289,"albumart":"https://i.scdn.co/image/ab67616d0000b27374d92bb2b2baa35bd9c621cc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0waBylEcT3qE24oV7eJ22A","service":"spop","name":"W prosektorium","artist":"Maciej Zembaty","album":"Piosenki z trumienki","type":"song","duration":134,"albumart":"https://i.scdn.co/image/ab67616d0000b2733cade4d54c42fa97a52e141b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1v6fhWYoiXlD8R6NK1w6rf","service":"spop","name":"Alleluja","artist":"Maciej Zembaty","album":"Alleluja","type":"song","duration":287,"albumart":"https://i.scdn.co/image/ab67616d0000b27374d92bb2b2baa35bd9c621cc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4oVNZU59Y4HCFQrdUgI4tq","service":"spop","name":"Dzisiaj tu, jutro tam","artist":"Maciej Zembaty","album":"Alleluja","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b27374d92bb2b2baa35bd9c621cc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: info: CoreCommandRouter::volumioPushQueue Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::saveQueue Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::updateTrackBlock Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::getTrackBlock Mar 16 13:13:48 volumio volumio[1032]: info: CoreCommandRouter::volumioPlay Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::play index 5 Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::addQueueItems Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::addQueueItems Mar 16 13:13:48 volumio volumio[1032]: info: Preload queue cleared Mar 16 13:13:48 volumio volumio[1032]: info: Adding Item to queue: spotify:track:71FmLbDJvjuoLvw65gOfz0 Mar 16 13:13:48 volumio volumio[1032]: info: Exploding uri spotify:track:71FmLbDJvjuoLvw65gOfz0 in service spop Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:71FmLbDJvjuoLvw65gOfz0 Mar 16 13:13:48 volumio volumio[1032]: info: Adding Item to queue: spotify:track:0Pez1fxynZTjUXcXPrC9a4 Mar 16 13:13:48 volumio volumio[1032]: info: Exploding uri spotify:track:0Pez1fxynZTjUXcXPrC9a4 in service spop Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:0Pez1fxynZTjUXcXPrC9a4 Mar 16 13:13:48 volumio volumio[1032]: info: Adding Item to queue: spotify:track:0X7oNwr7DIuYtvvv7xc7Eg Mar 16 13:13:48 volumio volumio[1032]: info: Exploding uri spotify:track:0X7oNwr7DIuYtvvv7xc7Eg in service spop Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:0X7oNwr7DIuYtvvv7xc7Eg Mar 16 13:13:48 volumio volumio[1032]: info: Adding Item to queue: spotify:track:58pLt0N4Q6YwLtWIZkuGhU Mar 16 13:13:48 volumio volumio[1032]: info: Exploding uri spotify:track:58pLt0N4Q6YwLtWIZkuGhU in service spop Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: EXPLODING URI:spotify:track:58pLt0N4Q6YwLtWIZkuGhU Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::stop Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::play index undefined Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::startPlaybackTimer Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:48 volumio volumio[1032]: info: [1742127228194] ControllerSpotify::clearAddPlayTrack Mar 16 13:13:48 volumio volumio[1032]: info: Sending Spotify command with payload to local API: /player/play Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=trace msg="emitting websocket event: paused" Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:65pbRWEDI0fVyzGKluwTdY","play_origin":"go-librespot"}} Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:48 volumio volumio[1032]: 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} Mar 16 13:13:48 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:48 volumio volumio[1032]: 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} Mar 16 13:13:48 volumio volumio[1032]: verbose: CURRENT POSITION 5 Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::syncState stateService pause Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus stop Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:48 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:48 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=debug msg="loading track spotify:track:1tL72b2eZcP5kSoig9ZJVz (paused: false, position: 1ms)" Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=trace msg="emitting websocket event: will_play" Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","play_origin":"go-librespot"}} Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:71FmLbDJvjuoLvw65gOfz0","service":"spop","name":"Onuce","artist":"Maciej Zembaty","album":"Piosenki z trumienki","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b2733cade4d54c42fa97a52e141b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:58pLt0N4Q6YwLtWIZkuGhU","service":"spop","name":"Wspomnienia","artist":"Maciej Zembaty","album":"Ballady Leonarda Cohena","type":"song","duration":385,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ecc137f70d6710bc443c9b3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0X7oNwr7DIuYtvvv7xc7Eg","service":"spop","name":"Wciąż wojna trwa","artist":"Maciej Zembaty","album":"Alleluja","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b27374d92bb2b2baa35bd9c621cc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Pez1fxynZTjUXcXPrC9a4","service":"spop","name":"Uszy","artist":"Maciej Zembaty","album":"Piosenki z trumienki","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b2733cade4d54c42fa97a52e141b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 16 13:13:48 volumio volumio[1032]: info: CoreCommandRouter::volumioPushQueue Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::saveQueue Mar 16 13:13:48 volumio volumio[1032]: info: CoreStateMachine::updateTrackBlock Mar 16 13:13:48 volumio volumio[1032]: info: CorePlayQueue::getTrackBlock Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1tL72b2eZcP5kSoig9ZJVz" Mar 16 13:13:48 volumio go-librespot[1275]: time="2025-03-16T13:13:48+01:00" level=debug msg="requested aes key for file 1452d2a0aa4fd97e7ee55eaf070d0a28838b3635, gid: 1tL72b2eZcP5kSoig9ZJVz" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=debug msg="fetched first chunk of 14, total size is 6937164 bytes" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" Mar 16 13:13:49 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=info msg="loaded track \"Maleńka, nie wolno żegnać się w ten sposób\" (uri: spotify:track:1tL72b2eZcP5kSoig9ZJVz, paused: false, position: 1ms, duration: 182253ms)" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=trace msg="emitting websocket event: metadata" Mar 16 13:13:49 volumio volumio[1032]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","name":"Maleńka, nie wolno żegnać się w ten sposób","artist_names":["Maciej Zembaty"],"album_name":"Ballady Leonarda Cohena","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023ecc137f70d6710bc443c9b3","position":1,"duration":182253,"release_date":"year:2002 month:12 day:31","track_number":10,"disc_number":1}} Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=debug msg="fetched chunk 3/13, size: 524288" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=debug msg="fetched chunk 2/13, size: 524288" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 16 13:13:49 volumio go-librespot[1275]: time="2025-03-16T13:13:49+01:00" level=trace msg="emitting websocket event: playing" Mar 16 13:13:49 volumio volumio[1032]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","play_origin":"go-librespot"}} Mar 16 13:13:49 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:49 volumio volumio[1032]: SPOTIFY: {"status":"play","service":"spop","title":"Maleńka, nie wolno żegnać się w ten sposób","artist":"Maciej Zembaty","album":"Ballady Leonarda Cohena","albumart":"https://i.scdn.co/image/ab67616d00001e023ecc137f70d6710bc443c9b3","uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","trackType":"spotify","seek":1,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:49 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:49 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:49 volumio volumio[1032]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Maleńka, nie wolno żegnać się w ten sposób","artist":"Maciej Zembaty","album":"Ballady Leonarda Cohena","albumart":"https://i.scdn.co/image/ab67616d00001e023ecc137f70d6710bc443c9b3","uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","trackType":"spotify","seek":1,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:49 volumio volumio[1032]: verbose: CURRENT POSITION 5 Mar 16 13:13:49 volumio volumio[1032]: info: CoreStateMachine::syncState stateService play Mar 16 13:13:49 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus stop Mar 16 13:13:50 volumio volumio[1032]: SPOTIFY: PUSH STATE SPOTIFY Mar 16 13:13:50 volumio volumio[1032]: SPOTIFY: {"status":"play","service":"spop","title":"Maleńka, nie wolno żegnać się w ten sposób","artist":"Maciej Zembaty","album":"Ballady Leonarda Cohena","albumart":"https://i.scdn.co/image/ab67616d00001e023ecc137f70d6710bc443c9b3","uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","trackType":"spotify","seek":1,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:50 volumio volumio[1032]: info: CoreCommandRouter::servicePushState Mar 16 13:13:50 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:50 volumio volumio[1032]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Maleńka, nie wolno żegnać się w ten sposób","artist":"Maciej Zembaty","album":"Ballady Leonarda Cohena","albumart":"https://i.scdn.co/image/ab67616d00001e023ecc137f70d6710bc443c9b3","uri":"spotify:track:1tL72b2eZcP5kSoig9ZJVz","trackType":"spotify","seek":1,"duration":182,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 16 13:13:50 volumio volumio[1032]: verbose: CURRENT POSITION 5 Mar 16 13:13:50 volumio volumio[1032]: info: CoreStateMachine::syncState stateService play Mar 16 13:13:50 volumio volumio[1032]: info: CoreStateMachine::syncState currentStatus play Mar 16 13:13:50 volumio volumio[1032]: info: Received an update from plugin. extracting info from payload Mar 16 13:13:50 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:50 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:50 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 16 13:13:50 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:50 volumio volumio[1032]: info: CoreStateMachine::pushState Mar 16 13:13:50 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:13:50 volumio volumio[1032]: info: CoreCommandRouter::volumioPushState Mar 16 13:13:50 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:50 volumio volumio[1032]: SPOTIFY: RECEIVED VOLUMIO VOLUME 83 Mar 16 13:13:50 volumio go-librespot[1275]: time="2025-03-16T13:13:50+01:00" level=debug msg="fetched chunk 1/13, size: 524288" Mar 16 13:14:02 volumio go-librespot[1275]: time="2025-03-16T13:14:02+01:00" level=debug msg="fetched chunk 4/13, size: 524288" Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 16 13:14:14 volumio volumio[1032]: info: Discovery: Getting this device information Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:14 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 16 13:14:14 volumio volumio[1032]: verbose: New Socket.io Connection to 192.168.1.15:3000 from 192.168.1.92 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:14 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 16 13:14:14 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 16 13:14:15 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 16 13:14:15 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 16 13:14:15 volumio volumio[1032]: info: Discovery: Getting this device information Mar 16 13:14:15 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:15 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:15 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 16 13:14:16 volumio go-librespot[1275]: time="2025-03-16T13:14:16+01:00" level=debug msg="fetched chunk 5/13, size: 524288" Mar 16 13:14:20 volumio sudo[4931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 16 13:14:20 volumio sudo[4929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 16 13:14:20 volumio sudo[4929]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 16 13:14:20 volumio sudo[4931]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 16 13:14:20 volumio sudo[4929]: pam_unix(sudo:session): session closed for user root Mar 16 13:14:20 volumio sudo[4931]: pam_unix(sudo:session): session closed for user root Mar 16 13:14:20 volumio volumio[1032]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 14; 22101316G Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6943.137 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 16 13:14:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 16 13:14:21 volumio sudo[4936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 16 13:14:21 volumio sudo[4936]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 16 13:14:21 volumio sudo[4936]: pam_unix(sudo:session): session closed for user root Mar 16 13:14:21 volumio sudo[4939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 16 13:14:21 volumio sudo[4939]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 16 13:14:21 volumio sudo[4939]: pam_unix(sudo:session): session closed for user root Mar 16 13:14:21 volumio volumio[1032]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 14; 22101316G Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6943.137 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::volumioGetVisibleSources Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:21 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::volumioGetQueue Mar 16 13:14:21 volumio volumio[1032]: info: CoreStateMachine::getQueue Mar 16 13:14:21 volumio volumio[1032]: info: CorePlayQueue::getQueue Mar 16 13:14:21 volumio volumio[1032]: info: Listing playlists Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 16 13:14:21 volumio volumio[1032]: info: Received Get System Info Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 16 13:14:21 volumio volumio[1032]: info: Discovery: Getting this device information Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:21 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:21 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 16 13:14:21 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 16 13:14:23 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 16 13:14:23 volumio volumio[1032]: info: Received Get System Info Mar 16 13:14:23 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 16 13:14:23 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 16 13:14:23 volumio volumio[1032]: info: Discovery: Getting this device information Mar 16 13:14:23 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:23 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:23 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 16 13:14:23 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 16 13:14:24 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 16 13:14:24 volumio volumio[1032]: info: Received Get System Info Mar 16 13:14:24 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 16 13:14:24 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 16 13:14:24 volumio volumio[1032]: info: Discovery: Getting this device information Mar 16 13:14:24 volumio volumio[1032]: info: CoreCommandRouter::volumioGetState Mar 16 13:14:24 volumio volumio[1032]: info: CorePlayQueue::getTrack 5 Mar 16 13:14:24 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 16 13:14:25 volumio kernel: hwmon hwmon1: Voltage normalised Mar 16 13:14:30 volumio go-librespot[1275]: time="2025-03-16T13:14:30+01:00" level=debug msg="fetched chunk 6/13, size: 524288" Mar 16 13:14:31 volumio volumio[1032]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 16 13:14:39 volumio volumio[1032]: info: ___________ PLUGINS: Run Shutdown Tasks ___________ Mar 16 13:14:39 volumio volumio[1032]: info: PLUGIN onShutdown : networkfs Mar 16 13:14:39 volumio volumio[1032]: info: PLUGIN onShutdown : audiophonicsonoff Mar 16 13:14:39 volumio volumio[1032]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 16 13:14:39 volumio volumio[1032]: TypeError: Cannot read property 'writeSync' of undefined Mar 16 13:14:39 volumio volumio[1032]: at ControllerAudiophonicsOnOff.onVolumioShutdown (/data/plugins/system_controller/audiophonicsonoff/index.js:43:25) Mar 16 13:14:39 volumio volumio[1032]: at PluginManager.onVolumioShutdownPlugin (/volumio/app/pluginmanager.js:638:30) Mar 16 13:14:39 volumio volumio[1032]: at HashMap. (/volumio/app/pluginmanager.js:621:31) Mar 16 13:14:39 volumio volumio[1032]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 16 13:14:39 volumio volumio[1032]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 16 13:14:39 volumio volumio[1032]: at PluginManager.onVolumioShutdown (/volumio/app/pluginmanager.js:619:20) Mar 16 13:14:39 volumio volumio[1032]: at CoreCommandRouter.shutdown (/volumio/app/index.js:1332:24) Mar 16 13:14:39 volumio volumio[1032]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:859:33) Mar 16 13:14:39 volumio volumio[1032]: at Socket.emit (events.js:315:20) Mar 16 13:14:39 volumio volumio[1032]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 16 13:14:39 volumio volumio[1032]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 16 13:14:39 volumio volumio[1032]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 16 13:14:41 volumio sudo[4988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-16 13:13 Mar 16 13:14:41 volumio sudo[4988]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"