Apr 12 16:29:01 terror go-librespot[1774]: time="2026-04-12T16:29:01+10:00" level=trace msg="sent dealer ping" Apr 12 16:29:02 terror go-librespot[1774]: time="2026-04-12T16:29:02+10:00" level=trace msg="received dealer pong" Apr 12 16:29:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:03.209+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:03.210+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:03.210+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:06 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:06.517+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:06 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:06.518+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:06 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:06.518+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:06 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: bandcamp , handleBrowseUri Apr 12 16:29:06 terror volumio[1233]: info: [bandcamp-browse] browseUri: bandcamp/fan@username=fathersooon/fan@username=fathersooon@view=wishlist Apr 12 16:29:08 terror volumio[1233]: info: Preload queue cleared Apr 12 16:29:09 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:09.826+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:09 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:09.826+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:09 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:09.826+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:12 terror volumio[1233]: info: Preload queue cleared Apr 12 16:29:12 terror volumio[1233]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 12 16:29:12 terror volumio[1233]: info: CoreStateMachine::ClearQueue Apr 12 16:29:12 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:29:12 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:12 terror volumio[1233]: info: CorePlayQueue::clearPlayQueue Apr 12 16:29:12 terror volumio[1233]: info: CorePlayQueue::saveQueue Apr 12 16:29:12 terror volumio[1233]: info: CoreCommandRouter::volumioPushQueue Apr 12 16:29:12 terror volumio[1233]: info: CoreStateMachine::addQueueItems Apr 12 16:29:12 terror volumio[1233]: info: CorePlayQueue::addQueueItems Apr 12 16:29:12 terror volumio[1233]: info: Preload queue cleared Apr 12 16:29:12 terror volumio[1233]: info: Adding Item to queue: bandcamp/fan@username=fathersooon/fan@username=fathersooon@view=wishlist/album@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:29:12 terror volumio[1233]: info: Exploding uri bandcamp/fan@username=fathersooon/fan@username=fathersooon@view=wishlist/album@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds in service bandcamp Apr 12 16:29:12 terror volumio[1233]: info: [bandcamp-browse] explodeUri: bandcamp/fan@username=fathersooon/fan@username=fathersooon@view=wishlist/album@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:29:13 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:13.228+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:13 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:13.228+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:13 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:13.228+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:13 terror volumio[1233]: info: CoreCommandRouter::volumioPushQueue Apr 12 16:29:13 terror volumio[1233]: info: CorePlayQueue::saveQueue Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::updateTrackBlock Apr 12 16:29:13 terror volumio[1233]: info: CorePlayQueue::getTrackBlock Apr 12 16:29:13 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::play index 0 Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:13 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:29:13 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:13 terror volumio[1233]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Ftrack%2Fconditional@artistUrl=https%3A%2F%2Fjkflesh.bandcamp.com@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:29:13 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:13 terror volumio[1233]: info: sendMpdCommand stop took 1 milliseconds Apr 12 16:29:13 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: sendMpdCommand clear took 1 milliseconds Apr 12 16:29:13 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3" Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: error: updateQueue error: null Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:29:13 terror volumio[1233]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3" took 3 milliseconds Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:13 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:13 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:13 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 5ms Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:13 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:13 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: Apr 12 16:29:13 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:13 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:13 terror volumio[1233]: info: sendMpdCommand play took 2 milliseconds Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:13 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:29:14 terror volumio[1233]: info: Apr 12 16:29:14 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:14 terror volumio[1233]: info: Apr 12 16:29:14 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:14 terror volumio[1233]: info: Apr 12 16:29:14 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:14 terror volumio[1233]: info: Apr 12 16:29:14 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand status took 17 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand status took 18 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand status took 17 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:14 terror volumio[1233]: info: Apr 12 16:29:14 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:14 terror volumio[1233]: info: Apr 12 16:29:14 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand status took 4 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:14 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:14 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:14 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus stop Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:14 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:14 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:14 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:14 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:14 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:14 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:14 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:14 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:14 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:14 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:14 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:14 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: ------------------------------ 47ms Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.214+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.215+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.216+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.217+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.218+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.219+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio[1233]: info: ------------------------------ 72ms Apr 12 16:29:14 terror volumio[1233]: info: ------------------------------ 72ms Apr 12 16:29:14 terror volumio[1233]: info: ------------------------------ 58ms Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand playlistinfo took 45 milliseconds Apr 12 16:29:14 terror volumio[1233]: info: sendMpdCommand playlistinfo took 44 milliseconds Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:14 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:14 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:14 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":297,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:14 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:14 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:14 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:14 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:14 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:14 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:14 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.249+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.250+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.251+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:14.252+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=100 Apr 12 16:29:14 terror volumio[1233]: info: ------------------------------ 80ms Apr 12 16:29:14 terror volumio[1233]: info: ------------------------------ 79ms Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:14 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:16 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:16.537+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:16 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:16.537+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:16 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:16.537+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::volumioPause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::servicePause Apr 12 16:29:17 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::servicePause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::pause Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand pause Apr 12 16:29:17 terror volumio[1233]: info: Apr 12 16:29:17 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand pause took 1 milliseconds Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:17 terror volumio[1233]: info: Apr 12 16:29:17 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:17 terror volumio[1233]: info: Apr 12 16:29:17 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand status took 3 milliseconds Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:17 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:17 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:17 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:17 terror volumio[1233]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3778,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:17 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::syncState stateService pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:17 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:17 terror volumio[1233]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3778,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:17 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::syncState stateService pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:17 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:17 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:17 terror volumio[1233]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3778,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:17 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::syncState stateService pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus pause Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:17 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:17 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:17 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:17.175+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PAUSED positionMs=3035 volume=100 Apr 12 16:29:17 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:17.176+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PAUSED positionMs=3035 volume=100 Apr 12 16:29:17 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:17.177+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PAUSED positionMs=3035 volume=100 Apr 12 16:29:17 terror volumio[1233]: info: ------------------------------ 28ms Apr 12 16:29:17 terror volumio[1233]: info: ------------------------------ 28ms Apr 12 16:29:17 terror volumio[1233]: info: ------------------------------ 27ms Apr 12 16:29:17 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:17 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:17 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 12 16:29:20 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:20.004+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:20 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:20.005+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:20 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:20.005+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:21 terror volumio[1233]: info: VolumeController::SetAlsaVolume12 Apr 12 16:29:21 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:21 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:21 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:21 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:21.439+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PAUSED positionMs=4059 volume=12 Apr 12 16:29:21 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Apr 12 16:29:21 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 100 Apr 12 16:29:21 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 12 Apr 12 16:29:21 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:21 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 12 Apr 12 16:29:22 terror volumio[1233]: SPOTIFY: SETTING SPOTIFY VOLUME 12 Apr 12 16:29:22 terror volumio[1233]: info: Sending Spotify command with payload to local API: /player/volume Apr 12 16:29:22 terror go-librespot[1774]: time="2026-04-12T16:29:22+10:00" level=debug msg="update volume requested to 7864/65535" Apr 12 16:29:23 terror go-librespot[1774]: time="2026-04-12T16:29:23+10:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 16:29:23 terror go-librespot[1774]: time="2026-04-12T16:29:23+10:00" level=trace msg="emitting websocket event: volume" Apr 12 16:29:23 terror volumio[1233]: SPOTIFY: received: {"type":"volume","data":{"value":12,"max":100}} Apr 12 16:29:23 terror volumio[1233]: SPOTIFY: RECEIVED SPOTIFY VOLUME 12 Apr 12 16:29:23 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:23.376+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:23 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:23.377+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:23 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:23.377+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:26 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:29:26 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::resume Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:29:26 terror volumio[1233]: info: Apr 12 16:29:26 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand play took 16 milliseconds Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:26 terror volumio[1233]: info: Apr 12 16:29:26 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:26 terror volumio[1233]: info: Apr 12 16:29:26 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand status took 3 milliseconds Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:26 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:26 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4672,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:26 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus pause Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.463+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=4059 volume=12 Apr 12 16:29:26 terror volumio[1233]: info: ------------------------------ 15ms Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 12 16:29:26 terror volumio[1233]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:26 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:26 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:26 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4672,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:26 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:26 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:26 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:26 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:26 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4672,"duration":368,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - CONDITIONAL","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/afc4247899a0777400ab730072b19af6/mp3-128/3446585398?p=0&ts=1776061752&t=58105a78a12262dbc856eb4ede22d3f4d1f29826&token=1776061752_85f39297dda97cd0a23138d6fc81b9b53bb3ce14&t.mp3","trackType":"mp3"} Apr 12 16:29:26 terror volumio[1233]: verbose: CURRENT POSITION 0 Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:26 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:26 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:26 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.486+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=4059 volume=12 Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.487+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=4059 volume=12 Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.488+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=4059 volume=12 Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.490+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=4059 volume=12 Apr 12 16:29:26 terror volumio[1233]: info: ------------------------------ 44ms Apr 12 16:29:26 terror volumio[1233]: info: ------------------------------ 44ms Apr 12 16:29:26 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Apr 12 16:29:26 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Apr 12 16:29:26 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Apr 12 16:29:26 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Apr 12 16:29:26 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.928+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.928+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:26 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:26.929+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:29 terror volumio[1233]: info: VolumeController::SetAlsaVolume32 Apr 12 16:29:29 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:29 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:29 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:29 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:29.536+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=7063 volume=32 Apr 12 16:29:29 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Apr 12 16:29:29 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 12 Apr 12 16:29:29 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 32 Apr 12 16:29:29 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:29 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 32 Apr 12 16:29:30 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:30.237+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:30 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:30.237+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:30 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:30.237+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:30 terror volumio[1233]: info: VolumeController::SetAlsaVolume47 Apr 12 16:29:30 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:30 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:30 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:30 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:30.977+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=8565 volume=47 Apr 12 16:29:30 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47 Apr 12 16:29:30 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 32 Apr 12 16:29:30 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 47 Apr 12 16:29:30 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:30 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 47 Apr 12 16:29:31 terror volumio[1233]: info: VolumeController::SetAlsaVolume56 Apr 12 16:29:31 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:31 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:31 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:31 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:31.668+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=9066 volume=56 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 47 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 56 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:31 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 56 Apr 12 16:29:31 terror volumio[1233]: info: VolumeController::SetAlsaVolume45 Apr 12 16:29:31 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:31 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:31 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:31 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:31.892+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=9316 volume=45 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 56 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 45 Apr 12 16:29:31 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:31 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 45 Apr 12 16:29:31 terror go-librespot[1774]: time="2026-04-12T16:29:31+10:00" level=trace msg="sent dealer ping" Apr 12 16:29:32 terror go-librespot[1774]: time="2026-04-12T16:29:32+10:00" level=trace msg="received dealer pong" Apr 12 16:29:32 terror volumio[1233]: info: VolumeController::SetAlsaVolume50 Apr 12 16:29:32 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:32 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:32 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:32 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:32.360+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=9817 volume=50 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 45 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 50 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:32 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 50 Apr 12 16:29:32 terror volumio[1233]: info: VolumeController::SetAlsaVolume45 Apr 12 16:29:32 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:32 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:32 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:32 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:32.580+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=10067 volume=45 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: SPOTIFY VOLUME 50 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: VOLUMIO VOLUME 45 Apr 12 16:29:32 terror volumio[1233]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 12 16:29:32 terror volumio[1233]: info: Setting Spotify Volume from Volumio: 45 Apr 12 16:29:33 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:33.545+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:33 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:33.546+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:33 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:33.546+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:34 terror volumio[1233]: SPOTIFY: SETTING SPOTIFY VOLUME 45 Apr 12 16:29:34 terror volumio[1233]: info: Sending Spotify command with payload to local API: /player/volume Apr 12 16:29:34 terror go-librespot[1774]: time="2026-04-12T16:29:34+10:00" level=debug msg="update volume requested to 29490/65535" Apr 12 16:29:34 terror go-librespot[1774]: time="2026-04-12T16:29:34+10:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 12 16:29:34 terror go-librespot[1774]: time="2026-04-12T16:29:34+10:00" level=trace msg="emitting websocket event: volume" Apr 12 16:29:34 terror volumio[1233]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} Apr 12 16:29:34 terror volumio[1233]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 Apr 12 16:29:36 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:36.855+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:36 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:36.855+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:36 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:36.855+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:38 terror wpa_supplicant[1197]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 16:29:39 terror wpa_supplicant[1197]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 16:29:40 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:40.164+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:40 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:40.164+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:40 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:40.164+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:43 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:43.472+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:43 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:43.472+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:43 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:43.472+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:46 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:46.781+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:46 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:46.781+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%01,00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone\npeer is gone" Apr 12 16:29:46 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:46.781+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:48 terror wpa_supplicant[1197]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 16:29:49 terror wpa_supplicant[1197]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 16:29:50 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:50.279+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:50 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:50.279+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:29:50 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:50.279+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:50 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::play index 3 Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::updateTrackBlock Apr 12 16:29:50 terror volumio[1233]: info: CorePlayQueue::getTrackBlock Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:50 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:50 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:50 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::serviceStop Apr 12 16:29:50 terror volumio[1233]: info: CorePlayQueue::getTrack 0 Apr 12 16:29:50 terror volumio[1233]: info: CoreCommandRouter::serviceStop Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:50 terror volumio[1233]: info: ControllerMpd::stop Apr 12 16:29:50 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:50 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:50.988+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 367.65 into Go struct field State.duration of type int" Apr 12 16:29:50 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:50 terror volumio[1233]: info: Apr 12 16:29:50 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:50 terror volumio[1233]: info: sendMpdCommand stop took 8 milliseconds Apr 12 16:29:50 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:50 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:50 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:50 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:29:50 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:50 terror volumio[1233]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Ftrack%2Fused-user@artistUrl=https%3A%2F%2Fjkflesh.bandcamp.com@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 8 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.013+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 340.05 into Go struct field State.duration of type int" Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 20ms Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.025+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 340.05 into Go struct field State.duration of type int" Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.026+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 340.05 into Go struct field State.duration of type int" Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 25ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 24ms Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand stop took 1 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand clear took 1 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3" Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: error: updateQueue error: null Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3" took 2 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:29:51 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:51 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:51 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:51 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand play took 5 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 5ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 12 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 13 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":340,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - USED / USER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3","trackType":"mp3"} Apr 12 16:29:51 terror volumio[1233]: verbose: CURRENT POSITION 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus stop Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 18ms Apr 12 16:29:51 terror volumio[1233]: info: Apr 12 16:29:51 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 4 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":340,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - USED / USER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3","trackType":"mp3"} Apr 12 16:29:51 terror volumio[1233]: verbose: CURRENT POSITION 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:51 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":340,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - USED / USER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3","trackType":"mp3"} Apr 12 16:29:51 terror volumio[1233]: verbose: CURRENT POSITION 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:51 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":340,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - USED / USER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3","trackType":"mp3"} Apr 12 16:29:51 terror volumio[1233]: verbose: CURRENT POSITION 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:51 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.248+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.248+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.249+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.250+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.252+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.253+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 68ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 67ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 57ms Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 51 milliseconds Apr 12 16:29:51 terror volumio[1233]: info: sendMpdCommand playlistinfo took 50 milliseconds Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":340,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - USED / USER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3","trackType":"mp3"} Apr 12 16:29:51 terror volumio[1233]: verbose: CURRENT POSITION 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:51 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:51 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:51 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":340,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"JK FLESH - USED / USER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/05f3d51b60ebaa51bbc8731673437566/mp3-128/3192128999?p=0&ts=1776061752&t=2314086eb4347b8e79f7172fc1e9da79e73b822c&token=1776061752_a7a4ede42b5ce4c89acca6fcd2212f4c1afd899c&t.mp3","trackType":"mp3"} Apr 12 16:29:51 terror volumio[1233]: verbose: CURRENT POSITION 3 Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:51 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:51 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.281+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=267 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.282+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=267 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.283+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=267 volume=45 Apr 12 16:29:51 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:51.284+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=267 volume=45 Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 82ms Apr 12 16:29:51 terror volumio[1233]: info: ------------------------------ 79ms Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:51 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::play index 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::updateTrackBlock Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrackBlock Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::serviceStop Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 3 Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::serviceStop Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::stop Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.086+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 340.05 into Go struct field State.duration of type int" Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand stop took 12 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Ftrack%2Fnight-before-rake@artistUrl=https%3A%2F%2Fjkflesh.bandcamp.com@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 9 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.123+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 293.85 into Go struct field State.duration of type int" Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.124+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 293.85 into Go struct field State.duration of type int" Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.125+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 293.85 into Go struct field State.duration of type int" Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 35ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 27ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 26ms Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand stop took 0 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand clear took 1 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3" Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: error: updateQueue error: null Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3" took 3 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:53 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:53 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:53 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:53 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand play took 2 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":294,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - NIGHT BEFORE RAKE","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3","trackType":"mp3"} Apr 12 16:29:53 terror volumio[1233]: verbose: CURRENT POSITION 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus stop Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 18ms Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: Apr 12 16:29:53 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":858,"duration":294,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - NIGHT BEFORE RAKE","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3","trackType":"mp3"} Apr 12 16:29:53 terror volumio[1233]: verbose: CURRENT POSITION 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:53 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":294,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - NIGHT BEFORE RAKE","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3","trackType":"mp3"} Apr 12 16:29:53 terror volumio[1233]: verbose: CURRENT POSITION 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:53 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":294,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - NIGHT BEFORE RAKE","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3","trackType":"mp3"} Apr 12 16:29:53 terror volumio[1233]: verbose: CURRENT POSITION 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:53 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.492+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.493+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.494+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.495+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.496+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.497+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 82ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 81ms Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 68ms Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand status took 65 milliseconds Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 63 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":294,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - NIGHT BEFORE RAKE","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3","trackType":"mp3"} Apr 12 16:29:53 terror volumio[1233]: verbose: CURRENT POSITION 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:53 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.531+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=172 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.532+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=172 volume=45 Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 80ms Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: info: sendMpdCommand playlistinfo took 29 milliseconds Apr 12 16:29:53 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:53 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:53 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:53 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":294,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - NIGHT BEFORE RAKE","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6785228f87f98868cd75433a69568e81/mp3-128/1515039330?p=0&ts=1776061752&t=b8e07121b2be9ad531fb9f0d149aa14200103490&token=1776061752_cc720a1d5126793e320f63295982209a239b85dd&t.mp3","trackType":"mp3"} Apr 12 16:29:53 terror volumio[1233]: verbose: CURRENT POSITION 4 Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:53 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:53 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.560+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=172 volume=45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.561+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=172 volume=45 Apr 12 16:29:53 terror volumio[1233]: info: ------------------------------ 109ms Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.586+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.586+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:29:53 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:53.586+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:56 terror dhcpcd[894]: wlan0: carrier lost - roaming Apr 12 16:29:56 terror dhcpcd[894]: wlan0: changing route to 192.168.0.0/24 Apr 12 16:29:56 terror dhcpcd[894]: wlan0: changing default route via 192.168.0.1 Apr 12 16:29:56 terror wpa_supplicant[1197]: wlan0: Associated with 8a:83:94:6f:d3:68 Apr 12 16:29:56 terror wpa_supplicant[1197]: MBO: Disable MBO/OCE due to misbehaving AP not having enabled PMF Apr 12 16:29:56 terror wpa_supplicant[1197]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 12 16:29:56 terror wpa_supplicant[1197]: wlan0: WPA: Key negotiation completed with 8a:83:94:6f:d3:68 [PTK=CCMP GTK=CCMP] Apr 12 16:29:56 terror wpa_supplicant[1197]: wlan0: CTRL-EVENT-CONNECTED - Connection to 8a:83:94:6f:d3:68 completed [id=0 id_str=] Apr 12 16:29:56 terror dhcpcd[894]: wlan0: carrier acquired Apr 12 16:29:56 terror dhcpcd[894]: wlan0: IAID 32:df:47:19 Apr 12 16:29:56 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:56.975+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:29:56 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:56.975+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:29:56 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:56.975+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:29:57 terror volumio[1233]: info: Received Get System Info Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:29:57 terror volumio[1233]: info: Discovery: Getting this device information Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::volumioGetState Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:29:57 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:57.311+10:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" available=true connected=true macAddress=dc:a6:32:df:47:19 ip4Address=192.168.0.112/24 ip6Address= ssid=TelstraF72DE0 Apr 12 16:29:57 terror volumio[1233]: error: error Apr 12 16:29:57 terror dhcpcd[894]: wlan0: soliciting an IPv6 router Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::play index 5 Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::updateTrackBlock Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrackBlock Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::serviceStop Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 4 Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::serviceStop Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::stop Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:57 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:57.920+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 293.85 into Go struct field State.duration of type int" Apr 12 16:29:57 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:57 terror volumio[1233]: info: Apr 12 16:29:57 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand stop took 13 milliseconds Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Ftrack%2Fslightly-over@artistUrl=https%3A%2F%2Fjkflesh.bandcamp.com@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:29:57 terror volumio[1233]: info: Apr 12 16:29:57 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:57 terror volumio[1233]: info: Apr 12 16:29:57 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand status took 11 milliseconds Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand status took 1 milliseconds Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:57 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:57 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:57 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:57 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:57 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:57 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:29:57 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:57.957+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 282.45 into Go struct field State.duration of type int" Apr 12 16:29:57 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:57.958+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 282.45 into Go struct field State.duration of type int" Apr 12 16:29:57 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:57.959+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 282.45 into Go struct field State.duration of type int" Apr 12 16:29:57 terror volumio[1233]: info: ------------------------------ 34ms Apr 12 16:29:57 terror volumio[1233]: info: ------------------------------ 25ms Apr 12 16:29:57 terror volumio[1233]: info: ------------------------------ 24ms Apr 12 16:29:57 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:57 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:57 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand stop took 1 milliseconds Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand clear took 0 milliseconds Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3" Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: error: updateQueue error: null Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3" took 3 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:58 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:58 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:58 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:29:58 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand play took 2 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand status took 15 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:58 terror volumio[1233]: info: Apr 12 16:29:58 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand status took 5 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand status took 3 milliseconds Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:58 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:58 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":282,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SLIGHTLY OVER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3","trackType":"mp3"} Apr 12 16:29:58 terror volumio[1233]: verbose: CURRENT POSITION 5 Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus stop Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:58 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:58 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":606,"duration":282,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SLIGHTLY OVER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3","trackType":"mp3"} Apr 12 16:29:58 terror volumio[1233]: verbose: CURRENT POSITION 5 Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:58 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:58 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:58 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":687,"duration":282,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SLIGHTLY OVER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3","trackType":"mp3"} Apr 12 16:29:58 terror volumio[1233]: verbose: CURRENT POSITION 5 Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:58 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror wpa_supplicant[1197]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 37ms Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.092+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.096+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.097+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.098+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 62ms Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 62ms Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand status took 45 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand playlistinfo took 42 milliseconds Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand playlistinfo took 41 milliseconds Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:58 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:58 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":282,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SLIGHTLY OVER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3","trackType":"mp3"} Apr 12 16:29:58 terror volumio[1233]: verbose: CURRENT POSITION 5 Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:58 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:58 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:58 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":282,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SLIGHTLY OVER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3","trackType":"mp3"} Apr 12 16:29:58 terror volumio[1233]: verbose: CURRENT POSITION 5 Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:58 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.127+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=83 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.129+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=83 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.130+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=83 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.132+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=83 volume=45 Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 80ms Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 77ms Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: info: sendMpdCommand playlistinfo took 56 milliseconds Apr 12 16:29:58 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:29:58 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:29:58 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:29:58 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":282,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SLIGHTLY OVER","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/6ab7dda176a6c064e7fb04fc5b5364f7/mp3-128/723091413?p=0&ts=1776061752&t=ebcd5579919475329738a6d7349e8afc3658d966&token=1776061752_5e1b6c26f9b3e137e6b67995c38da8ef20be9c64&t.mp3","trackType":"mp3"} Apr 12 16:29:58 terror volumio[1233]: verbose: CURRENT POSITION 5 Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:29:58 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:29:58 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.174+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=83 volume=45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.176+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=83 volume=45 Apr 12 16:29:58 terror volumio[1233]: info: ------------------------------ 116ms Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:29:58 terror volumio5-onboarding[1991]: time=2026-04-12T16:29:58.209+10:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:29:58 terror dhcpcd[894]: wlan0: soliciting a DHCP lease Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.371+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.371+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.371+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::play index 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::updateTrackBlock Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrackBlock Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::serviceStop Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 5 Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::serviceStop Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::stop Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.432+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 282.45 into Go struct field State.duration of type int" Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand stop took 11 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Ftrack%2Fdouble-red@artistUrl=https%3A%2F%2Fjkflesh.bandcamp.com@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 7 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.457+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 243.6 into Go struct field State.duration of type int" Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 20ms Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 10 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.472+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 243.6 into Go struct field State.duration of type int" Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 25ms Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 18 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.486+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 243.6 into Go struct field State.duration of type int" Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 38ms Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand stop took 1 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand clear took 1 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3" Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: error: updateQueue error: null Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3" took 2 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:30:00 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:30:00 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:30:00 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:00 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 11ms Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand play took 2 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 12 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 13 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 13 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":244,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - DOUBLE RED","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3","trackType":"mp3"} Apr 12 16:30:00 terror volumio[1233]: verbose: CURRENT POSITION 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus stop Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 17ms Apr 12 16:30:00 terror volumio[1233]: info: Apr 12 16:30:00 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 5 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":244,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - DOUBLE RED","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3","trackType":"mp3"} Apr 12 16:30:00 terror volumio[1233]: verbose: CURRENT POSITION 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:00 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":244,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - DOUBLE RED","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3","trackType":"mp3"} Apr 12 16:30:00 terror volumio[1233]: verbose: CURRENT POSITION 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:00 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":244,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - DOUBLE RED","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3","trackType":"mp3"} Apr 12 16:30:00 terror volumio[1233]: verbose: CURRENT POSITION 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:00 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.635+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.636+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.638+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.638+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.640+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.641+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 68ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 68ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 56ms Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 50 milliseconds Apr 12 16:30:00 terror volumio[1233]: info: sendMpdCommand playlistinfo took 49 milliseconds Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":244,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - DOUBLE RED","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3","trackType":"mp3"} Apr 12 16:30:00 terror volumio[1233]: verbose: CURRENT POSITION 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:00 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:00 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:00 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":244,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - DOUBLE RED","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/fdb5ef2eb4ba725aace3da62334ae235/mp3-128/3676074187?p=0&ts=1776061752&t=eaef6b488a00186c423075d4cdd87999534e5ac1&token=1776061752_926169acb53d88780e8b5d4631f86656d3e45875&t.mp3","trackType":"mp3"} Apr 12 16:30:00 terror volumio[1233]: verbose: CURRENT POSITION 6 Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:00 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:00 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.674+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=127 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.675+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=127 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.676+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=127 volume=45 Apr 12 16:30:00 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:00.678+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=127 volume=45 Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 89ms Apr 12 16:30:00 terror volumio[1233]: info: ------------------------------ 84ms Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:00 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:01 terror go-librespot[1774]: time="2026-04-12T16:30:01+10:00" level=trace msg="received accesspoint ping" Apr 12 16:30:01 terror go-librespot[1774]: time="2026-04-12T16:30:01+10:00" level=trace msg="received accesspoint pong ack" Apr 12 16:30:01 terror go-librespot[1774]: time="2026-04-12T16:30:01+10:00" level=trace msg="sent dealer ping" Apr 12 16:30:02 terror go-librespot[1774]: time="2026-04-12T16:30:02+10:00" level=trace msg="received dealer pong" Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPlay Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::play index 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::stop Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::stPlaybackTimer Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::updateTrackBlock Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrackBlock Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.679+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.679+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.679+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::serviceStop Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 6 Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::serviceStop Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::stop Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.685+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 243.6 into Go struct field State.duration of type int" Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand stop took 7 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::play index undefined Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::startPlaybackTimer Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Ftrack%2Fshelf@artistUrl=https%3A%2F%2Fjkflesh.bandcamp.com@albumUrl=https%3A%2F%2Fjkflesh.bandcamp.com%2Falbum%2Fshouting-the-odds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 8 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.708+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 279.75 into Go struct field State.duration of type int" Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 19ms Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 11 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 11 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.723+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 279.75 into Go struct field State.duration of type int" Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.724+10:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 279.75 into Go struct field State.duration of type int" Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 28ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 27ms Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand stop took 1 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand clear took 1 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3" Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: error: updateQueue error: null Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3" took 4 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:30:03 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:30:03 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:30:03 terror volumio[1233]: verbose: MPD COMMAND [object Object] Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror dhcpcd[894]: wlan0: offered 192.168.0.113 from 192.168.0.1 Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 4ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand play Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces system playlist update Apr 12 16:30:03 terror volumio[1233]: info: Ignoring MPD Status Update Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 3ms Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand play took 2 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 2ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 1ms Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 14 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 15 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 15 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 2 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":280,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SHELF","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3","trackType":"mp3"} Apr 12 16:30:03 terror volumio[1233]: verbose: CURRENT POSITION 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus stop Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 19ms Apr 12 16:30:03 terror volumio[1233]: info: Apr 12 16:30:03 terror volumio[1233]: ---------------------------- MPD announces state update: player Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::getState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand status Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":280,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SHELF","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3","trackType":"mp3"} Apr 12 16:30:03 terror volumio[1233]: verbose: CURRENT POSITION 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:03 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":280,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SHELF","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3","trackType":"mp3"} Apr 12 16:30:03 terror volumio[1233]: verbose: CURRENT POSITION 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:03 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":280,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SHELF","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3","trackType":"mp3"} Apr 12 16:30:03 terror volumio[1233]: verbose: CURRENT POSITION 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:03 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.867+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.867+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.870+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.871+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.872+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.873+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 71ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 71ms Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 58ms Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 55 milliseconds Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand status took 53 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseState Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":280,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SHELF","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3","trackType":"mp3"} Apr 12 16:30:03 terror volumio[1233]: verbose: CURRENT POSITION 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:03 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.904+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.909+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=0 volume=45 Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 81ms Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: info: sendMpdCommand playlistinfo took 48 milliseconds Apr 12 16:30:03 terror volumio[1233]: verbose: ControllerMpd::parseTrackInfo Apr 12 16:30:03 terror volumio[1233]: info: ControllerMpd::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::servicePushState Apr 12 16:30:03 terror volumio[1233]: info: CorePlayQueue::getTrack 7 Apr 12 16:30:03 terror volumio[1233]: verbose: STATE SERVICE {"status":"play","position":0,"seek":881,"duration":280,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"MONRELLA - SHELF","artist":"JK FLESH / MONRELLA","album":"SHOUTING THE ODDS","uri":"https://t4.bcbits.com/stream/9a45ebb835a2d86e460f7000f5697629/mp3-128/1711726947?p=0&ts=1776061752&t=d28ddcdd3b8d50c6939a73698d4bd6df11ebaef5&token=1776061752_08fad879c25b3e28f79089e54c581d1a0516e5e1&t.mp3","trackType":"mp3"} Apr 12 16:30:03 terror volumio[1233]: verbose: CURRENT POSITION 7 Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState stateService play Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::syncState currentStatus play Apr 12 16:30:03 terror volumio[1233]: info: Received an update from plugin. extracting info from payload Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror dhcpcd[894]: wlan0: NAK: requested address not available from 192.168.0.1 Apr 12 16:30:03 terror dhcpcd[894]: wlan0: message: requested address not available Apr 12 16:30:03 terror avahi-daemon[1481]: Withdrawing address record for 192.168.0.112 on wlan0. Apr 12 16:30:03 terror avahi-daemon[1481]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.112. Apr 12 16:30:03 terror volumio[1233]: info: CoreStateMachine::pushState Apr 12 16:30:03 terror volumio[1233]: info: CoreCommandRouter::volumioPushState Apr 12 16:30:03 terror avahi-daemon[1481]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 12 16:30:03 terror dhcpcd[894]: wlan0: deleting route to 192.168.0.0/24 Apr 12 16:30:03 terror dhcpcd[894]: wlan0: deleting default route via 192.168.0.1 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.960+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=155 volume=45 Apr 12 16:30:03 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:03.962+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_PLAYING positionMs=155 volume=45 Apr 12 16:30:03 terror volumio[1233]: info: ------------------------------ 133ms Apr 12 16:30:03 terror systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror volumio[1233]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 12 16:30:03 terror systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 12 16:30:03 terror systemd[1]: welcome.service: Deactivated successfully. Apr 12 16:30:03 terror systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 12 16:30:03 terror systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 12 16:30:03 terror dhcpcd[894]: wlan0: soliciting a DHCP lease Apr 12 16:30:03 terror volumio[1233]: info: Discovery: A device disappeared from network Apr 12 16:30:03 terror volumio[1233]: info: Discovery: A device disappeared from network Apr 12 16:30:04 terror systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 12 16:30:04 terror welcome[5271]: Resolved ip:[0] Apr 12 16:30:04 terror dhcpcd[894]: wlan0: offered 192.168.0.113 from 192.168.0.1 Apr 12 16:30:04 terror systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 12 16:30:04 terror systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 12 16:30:04 terror volumio[1233]: info: Received Get System Info Apr 12 16:30:04 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:30:04 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:30:04 terror volumio[1233]: info: Discovery: Getting this device information Apr 12 16:30:04 terror volumio[1233]: info: CoreCommandRouter::volumioGetState Apr 12 16:30:04 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:30:04 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:04.453+10:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" available=true connected=true macAddress=dc:a6:32:df:47:19 ip4Address= ip6Address= ssid=TelstraF72DE0 Apr 12 16:30:04 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:30:04 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:30:04 terror dhcpcd[894]: wlan0: probing address 192.168.0.113/24 Apr 12 16:30:05 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:05.266+10:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:30:05 terror ntpd[1037]: IO: Deleting interface #3 wlan0, 192.168.0.112#123, interface stats: received=442, sent=458, dropped=1, active_time=1938 secs Apr 12 16:30:05 terror ntpd[1037]: PROTO: 139.180.160.82 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 103.249.238.208 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 144.6.238.198 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 103.76.40.123 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 160.30.139.11 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 27.124.125.251 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 162.159.200.123 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 110.232.114.22 unlink local addr 192.168.0.112 -> Apr 12 16:30:05 terror ntpd[1037]: PROTO: 202.179.128.94 unlink local addr 192.168.0.112 -> Apr 12 16:30:06 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:06.987+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:30:06 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:06.987+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:30:06 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:06.987+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:30:08 terror wpa_supplicant[1197]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 16:30:09 terror dhcpcd[894]: wlan0: leased 192.168.0.113 for 86400 seconds Apr 12 16:30:09 terror avahi-daemon[1481]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.113. Apr 12 16:30:09 terror avahi-daemon[1481]: New relevant interface wlan0.IPv4 for mDNS. Apr 12 16:30:09 terror dhcpcd[894]: wlan0: adding route to 192.168.0.0/24 Apr 12 16:30:09 terror dhcpcd[894]: wlan0: adding default route via 192.168.0.1 Apr 12 16:30:09 terror avahi-daemon[1481]: Registering new address record for 192.168.0.113 on wlan0.IPv4. Apr 12 16:30:09 terror systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 12 16:30:09 terror systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 12 16:30:09 terror systemd[1]: welcome.service: Deactivated successfully. Apr 12 16:30:09 terror systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 12 16:30:09 terror systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 12 16:30:09 terror systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 12 16:30:09 terror welcome[5305]: Resolved ip:[1] 192.168.0.113 Apr 12 16:30:09 terror systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 12 16:30:09 terror systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 12 16:30:09 terror volumio[1233]: info: Received Get System Info Apr 12 16:30:09 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:30:09 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:30:09 terror volumio[1233]: info: Discovery: Getting this device information Apr 12 16:30:09 terror volumio[1233]: info: CoreCommandRouter::volumioGetState Apr 12 16:30:09 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:30:09 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:09.962+10:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" available=true connected=true macAddress=dc:a6:32:df:47:19 ip4Address=192.168.0.113/24 ip6Address= ssid=TelstraF72DE0 Apr 12 16:30:09 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:30:09 terror volumio[1233]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:30:10 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:10.295+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:30:10 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:10.296+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:30:10 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:10.296+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:30:10 terror volumio[1233]: info: Discovery: adding 07f56e5d-716a-481a-b80d-6557690be583 Apr 12 16:30:10 terror volumio[1233]: info: Discovery: Found device Terror Apr 12 16:30:10 terror volumio[1233]: info: CoreCommandRouter::volumioGetState Apr 12 16:30:10 terror volumio[1233]: info: Discovery: this is already registered, 07f56e5d-716a-481a-b80d-6557690be583 Apr 12 16:30:10 terror volumio[1233]: info: Discovery: Found device Terror Apr 12 16:30:10 terror volumio[1233]: info: CoreCommandRouter::volumioGetState Apr 12 16:30:10 terror ntpd[1037]: IO: Listen normally on 4 wlan0 192.168.0.113:123 Apr 12 16:30:10 terror ntpd[1037]: IO: new interface(s) found: waking up resolver Apr 12 16:30:10 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:10.845+10:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:30:13 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:13.604+10:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=2 chunks=1 index=0 tries=11 Apr 12 16:30:13 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:13.604+10:00 level=ERROR msg="failed to send event" component=server dst="00:00:00:00:00:00%02 @ 0x2c2a810" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED error="peer is gone" Apr 12 16:30:13 terror volumio5-onboarding[1991]: time=2026-04-12T16:30:13.604+10:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02 @ 0x2800630" state=STATUS_STOPPED positionMs=0 volume=100 Apr 12 16:30:14 terror volumio[1233]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 16:30:14 terror volumio[1233]: Error: read ETIMEDOUT Apr 12 16:30:14 terror volumio[1233]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:217:20) { Apr 12 16:30:14 terror volumio[1233]: errno: -110, Apr 12 16:30:14 terror volumio[1233]: code: 'ETIMEDOUT', Apr 12 16:30:14 terror volumio[1233]: syscall: 'read' Apr 12 16:30:14 terror volumio[1233]: } Apr 12 16:30:14 terror volumio[1233]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 16:30:14 terror sudo[5358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 16:29' Apr 12 16:30:14 terror sudo[5358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"