Feb 11 21:33:01 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 11 21:33:01 volumiooe volumio[19953]: info: CURURI: artists://Zucchero%20Sugar%20Fornaciari Feb 11 21:33:01 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:01 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Preloading song: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 in service mpd Feb 11 21:33:01 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_01-Overdose%20(d'amore).mp3&metadata=false Feb 11 21:33:01 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 in service mpd Feb 11 21:33:01 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_02-Nice%20(Nietzsche)%20che%20dice.mp3&metadata=false Feb 11 21:33:01 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 in service mpd Feb 11 21:33:01 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_03-Il%20mare%20impetuoso%20al%20tramonto%20sal%C3%AC%20sulla%20Luna%20e%20dietro%20una%20tendina%20di%20stelle%20....mp3&metadata=false Feb 11 21:33:01 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 in service mpd Feb 11 21:33:01 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_04-Madre%20dolcissima.mp3&metadata=false Feb 11 21:33:01 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 in service mpd Feb 11 21:33:01 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_05-Diavolo%20in%20me.mp3&metadata=false Feb 11 21:33:01 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:01 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 in service mpd Feb 11 21:33:02 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_06-Iruben%20me.mp3&metadata=false Feb 11 21:33:02 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 Feb 11 21:33:02 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 in service mpd Feb 11 21:33:02 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_07-A%20wonderful%20world.mp3&metadata=false Feb 11 21:33:02 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 Feb 11 21:33:02 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 in service mpd Feb 11 21:33:02 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_08-Diamante.mp3&metadata=false Feb 11 21:33:02 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 Feb 11 21:33:02 volumiooe volumio[19953]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 in service mpd Feb 11 21:33:02 volumiooe volumio[19953]: info: ALBUMART /albumart?cacheid=418&web=Zucchero%20Sugar%20Fornaciari/Oro%20Incenso%20%26%20Birra/extralarge&path=%2Fmnt%2FNAS%2Fsyn213%2FMUSICA%2FZucchero%20Sugar%20Fornaciari%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra%2FZucchero%20Sugar%20Fornaciari_Oro%20Incenso%20%26%20Birra_09-Libera%20l'amore.mp3&metadata=false Feb 11 21:33:02 volumiooe volumio[19953]: info: URI /mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::ClearQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::stPlaybackTimer Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::updateTrackBlock Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrackBlock Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 0 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::serviceStop Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 0 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::serviceStop Feb 11 21:33:05 volumiooe volumio[19953]: info: ControllerMpd::stop Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::clearPlayQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::saveQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::addQueueItems Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::addQueueItems Feb 11 21:33:05 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.621+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=0 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.622+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/blink-182/blink-182_blink-182/blink-182_blink-182_03-I Miss You.m4a" title="I Miss You" Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::saveQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::updateTrackBlock Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrackBlock Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPlay Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::play index 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::addQueueItems Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::addQueueItems Feb 11 21:33:05 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::saveQueue Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::play index undefined Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::updateTrackBlock Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrackBlock Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::startPlaybackTimer Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::clearAddPlayTracks NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand stop Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand stop took 82 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand stop took 35 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand clear Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:05 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:05 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:05 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand status took 17 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand clear took 18 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand status took 16 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand status took 16 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand add "NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:05 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 11 21:33:05 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio[19953]: info: No code Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 11 21:33:05 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus stop Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio[19953]: info: No code Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:05 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:05 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.750+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=41 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.751+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.753+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=41 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.754+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.755+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=41 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.756+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.759+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=41 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.759+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.762+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=41 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.763+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.768+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=41 volume=57 Feb 11 21:33:05 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:05.769+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 111ms Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 111ms Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:05 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:05 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:05 volumiooe volumio[19953]: error: updateQueue error: null Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:05 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 108ms Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 104 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand add "NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" took 105 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 11ms Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 10ms Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:05 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand play Feb 11 21:33:05 volumiooe volumio[19953]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 130ms Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:05 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:05 volumiooe volumio[19953]: info: Feb 11 21:33:05 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:05 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 60ms Feb 11 21:33:05 volumiooe volumio[19953]: info: sendMpdCommand play took 55 milliseconds Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 54ms Feb 11 21:33:05 volumiooe volumio[19953]: info: ------------------------------ 53ms Feb 11 21:33:06 volumiooe volumio[19953]: info: Feb 11 21:33:06 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:06 volumiooe volumio[19953]: info: Feb 11 21:33:06 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:06 volumiooe volumio[19953]: info: Feb 11 21:33:06 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:06 volumiooe volumio[19953]: info: Feb 11 21:33:06 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand status took 5 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:06 volumiooe volumio[19953]: info: Feb 11 21:33:06 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:06 volumiooe volumio[19953]: info: Feb 11 21:33:06 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand status took 21 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand status took 19 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand status took 19 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 18 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand status took 11 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand status took 10 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Nice (Nietzsche) che dice","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3","trackType":"mp3"} Feb 11 21:33:06 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus stop Feb 11 21:33:06 volumiooe volumio[19953]: info: ------------------------------ 34ms Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:06 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Nice (Nietzsche) che dice","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3","trackType":"mp3"} Feb 11 21:33:06 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:06 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Nice (Nietzsche) che dice","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3","trackType":"mp3"} Feb 11 21:33:06 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:06 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Nice (Nietzsche) che dice","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3","trackType":"mp3"} Feb 11 21:33:06 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:06 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Nice (Nietzsche) che dice","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3","trackType":"mp3"} Feb 11 21:33:06 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:06 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Nice (Nietzsche) che dice","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3","trackType":"mp3"} Feb 11 21:33:06 volumiooe volumio[19953]: verbose: CURRENT POSITION 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:06 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:06 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:06 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.140+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.142+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.142+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.142+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.143+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.143+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.147+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.148+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.155+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.156+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.157+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.158+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.162+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.164+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.166+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.167+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.172+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.173+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.177+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=962 volume=57 Feb 11 21:33:06 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:06.179+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:06 volumiooe volumio[19953]: info: ------------------------------ 216ms Feb 11 21:33:06 volumiooe volumio[19953]: info: ------------------------------ 216ms Feb 11 21:33:06 volumiooe volumio[19953]: info: ------------------------------ 217ms Feb 11 21:33:06 volumiooe volumio[19953]: info: ------------------------------ 208ms Feb 11 21:33:06 volumiooe volumio[19953]: info: ------------------------------ 208ms Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:06 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 57 Feb 11 21:33:15 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:15.499+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-585.757851ms timeout=3s volume=58 Feb 11 21:33:19 volumiooe volumio[19953]: Upnp client error: Error: This socket has been ended by the other party Feb 11 21:33:19 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume58 Feb 11 21:33:19 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:19 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:19 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:19 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:19 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:19.631+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=14495 volume=58 Feb 11 21:33:19 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:19.632+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:19 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:19 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:19 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:19 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:24 volumiooe go-librespot[20141]: time="2026-02-11T21:33:24+01:00" level=trace msg="sent dealer ping" Feb 11 21:33:25 volumiooe go-librespot[20141]: time="2026-02-11T21:33:25+01:00" level=trace msg="received dealer pong" Feb 11 21:33:31 volumiooe volumio[19953]: info: No valid Plugin REST Endpoint Feb 11 21:33:35 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::ClearQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::stPlaybackTimer Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::updateTrackBlock Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrackBlock Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::serviceStop Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 1 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::serviceStop Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::stop Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::clearPlayQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::saveQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::addQueueItems Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::addQueueItems Feb 11 21:33:35 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_03-Il mare impetuoso al tramonto salì sulla Luna e dietro una tendina di stelle ....mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_04-Madre dolcissima.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.266+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=0 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.267+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_02-Nice (Nietzsche) che dice.mp3" title="Nice (Nietzsche) che dice" Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::saveQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::updateTrackBlock Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrackBlock Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPlay Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::play index 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::addQueueItems Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::addQueueItems Feb 11 21:33:35 volumiooe volumio[19953]: info: Preload queue cleared Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_06-Iruben me.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_07-A wonderful world.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_08-Diamante.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: Using cached record of: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_09-Libera l'amore.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::saveQueue Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::play index undefined Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::updateTrackBlock Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrackBlock Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::startPlaybackTimer Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::clearAddPlayTracks NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand stop Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand stop took 78 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand stop took 31 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand clear Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:35 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 30 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand clear took 29 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 28 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 28 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand add "NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: No code Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus stop Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: No code Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.403+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=38 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.403+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.405+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=38 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.406+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.408+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=38 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.409+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.412+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=38 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.412+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.416+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=38 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.416+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.420+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_STOPPED positionMs=38 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.422+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 128ms Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 128ms Feb 11 21:33:35 volumiooe volumio[19953]: error: updateQueue error: null Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:35 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 115ms Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 112 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand add "NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" took 111 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand play Feb 11 21:33:35 volumiooe volumio[19953]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 150ms Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:35 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:35 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:35 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 39ms Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand play took 35 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 34ms Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 32ms Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:35 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces system playlist update Feb 11 21:33:35 volumiooe volumio[19953]: info: Ignoring MPD Status Update Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 19ms Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 19ms Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 19 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 18 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 16 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: info: Feb 11 21:33:35 volumiooe volumio[19953]: ---------------------------- MPD announces state update: player Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::getState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand status Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 20 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 19 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 17 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 17 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 16 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand status took 15 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseState Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Diavolo in me","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3","trackType":"mp3"} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus stop Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Diavolo in me","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3","trackType":"mp3"} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:35 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Diavolo in me","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3","trackType":"mp3"} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:35 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 75ms Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.868+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=0 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.869+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.871+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=0 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.872+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.874+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=0 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.875+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.877+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=0 volume=58 Feb 11 21:33:35 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:35.878+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 164ms Feb 11 21:33:35 volumiooe volumio[19953]: info: ------------------------------ 164ms Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 138 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 138 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: info: sendMpdCommand playlistinfo took 136 milliseconds Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: verbose: ControllerMpd::parseTrackInfo Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Diavolo in me","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3","trackType":"mp3"} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:35 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Diavolo in me","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3","trackType":"mp3"} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:35 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: ControllerMpd::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::servicePushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Diavolo in me","artist":"Zucchero Sugar Fornaciari","album":"Oro Incenso & Birra","uri":"NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3","trackType":"mp3"} Feb 11 21:33:35 volumiooe volumio[19953]: verbose: CURRENT POSITION 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState stateService play Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::syncState currentStatus play Feb 11 21:33:35 volumiooe volumio[19953]: info: Received an update from plugin. extracting info from payload Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:35 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:33:36 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:33:36 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.003+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=0 volume=58 Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.004+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.006+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=0 volume=58 Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.007+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.008+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=848 volume=58 Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.008+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.010+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=848 volume=58 Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.011+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.013+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=848 volume=58 Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.013+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.016+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=848 volume=58 Feb 11 21:33:36 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:33:36.017+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:33:36 volumiooe volumio[19953]: info: ------------------------------ 246ms Feb 11 21:33:36 volumiooe volumio[19953]: info: ------------------------------ 244ms Feb 11 21:33:36 volumiooe volumio[19953]: info: ------------------------------ 239ms Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 58 Feb 11 21:33:36 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:33:37 volumiooe volumio[19953]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Roberto%20Ciotti/efc8396d-7c5f-459e-8861-391c2cb13150.jpg' Feb 11 21:33:49 volumiooe volumio[19953]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/SebastiAn/91332fac-0aa1-4ce6-8658-a0c8b49b3db2.jpg' Feb 11 21:33:54 volumiooe go-librespot[20141]: time="2026-02-11T21:33:54+01:00" level=trace msg="received accesspoint ping" Feb 11 21:33:54 volumiooe go-librespot[20141]: time="2026-02-11T21:33:54+01:00" level=trace msg="received accesspoint pong ack" Feb 11 21:33:54 volumiooe go-librespot[20141]: time="2026-02-11T21:33:54+01:00" level=trace msg="sent dealer ping" Feb 11 21:33:55 volumiooe go-librespot[20141]: time="2026-02-11T21:33:55+01:00" level=trace msg="received dealer pong" Feb 11 21:34:00 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:00.120+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-590.038485ms timeout=3s volume=59 Feb 11 21:34:00 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume59 Feb 11 21:34:00 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:34:00 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:34:00 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:34:00 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:00 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:00.151+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=24879 volume=59 Feb 11 21:34:00 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:00.152+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 59 Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 57 Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 59 Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 11 21:34:00 volumiooe volumio[19953]: info: Setting Spotify Volume from Volumio: 59 Feb 11 21:34:00 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:00.492+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-593.360326ms timeout=3s volume=60 Feb 11 21:34:00 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume60 Feb 11 21:34:00 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:34:00 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:34:00 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:34:00 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:00 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:00.520+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=25130 volume=60 Feb 11 21:34:00 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:00.521+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 59 Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 60 Feb 11 21:34:00 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 11 21:34:01 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:01.042+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-590.706694ms timeout=3s volume=61 Feb 11 21:34:01 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:01.399+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-589.974881ms timeout=3s volume=62 Feb 11 21:34:01 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:01.812+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-589.83659ms timeout=3s volume=63 Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.023+01:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.9.222:46904 @ 0x2c907e0" latency=-593.045532ms timeout=3s volume=64 Feb 11 21:34:04 volumiooe volumio[19953]: SPOTIFY: SETTING SPOTIFY VOLUME 59 Feb 11 21:34:04 volumiooe volumio[19953]: info: Sending Spotify command with payload to local API: /player/volume Feb 11 21:34:04 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume61 Feb 11 21:34:04 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume62 Feb 11 21:34:04 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume63 Feb 11 21:34:04 volumiooe volumio[19953]: info: VolumeController::SetAlsaVolume64 Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreStateMachine::pushState Feb 11 21:34:04 volumiooe volumio[19953]: info: CorePlayQueue::getTrack 4 Feb 11 21:34:04 volumiooe volumio[19953]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.859+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=29637 volume=64 Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.859+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.862+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=29637 volume=64 Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.862+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.864+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=29637 volume=64 Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.865+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.871+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" state=STATUS_PLAYING positionMs=29637 volume=64 Feb 11 21:34:04 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:04.872+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" id="mnt/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_05-Diavolo in me.mp3" title="Diavolo in me" Feb 11 21:34:05 volumiooe go-librespot[20141]: time="2026-02-11T21:34:05+01:00" level=debug msg="update volume requested to 38665/65535" Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: SPOTIFY VOLUME 59 Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: VOLUMIO VOLUME 64 Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 11 21:34:05 volumiooe volumio[19953]: info: Setting Spotify Volume from Volumio: 64 Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Feb 11 21:34:05 volumiooe volumio[19953]: SPOTIFY: RECEIVED VOLUMIO VOLUME 64 Feb 11 21:34:05 volumiooe volumio[19953]: Upnp client error: Error: This socket has been ended by the other party Feb 11 21:34:07 volumiooe volumio[19953]: SPOTIFY: SETTING SPOTIFY VOLUME 64 Feb 11 21:34:07 volumiooe volumio[19953]: info: Sending Spotify command with payload to local API: /player/volume Feb 11 21:34:07 volumiooe go-librespot[20141]: time="2026-02-11T21:34:07+01:00" level=debug msg="update volume requested to 41942/65535" Feb 11 21:34:10 volumiooe volumio[19953]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 21:34:10 volumiooe volumio[19953]: TypeError: Cannot read properties of null (reading 'slice') Feb 11 21:34:10 volumiooe volumio[19953]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 11 21:34:10 volumiooe volumio[19953]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 11 21:34:10 volumiooe volumio[19953]: at Object.onceWrapper (node:events:629:26) Feb 11 21:34:10 volumiooe volumio[19953]: at ClientRequest.emit (node:events:514:28) Feb 11 21:34:10 volumiooe volumio[19953]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 11 21:34:10 volumiooe volumio[19953]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 11 21:34:10 volumiooe volumio[19953]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 11 21:34:10 volumiooe volumio[19953]: at TLSSocket.emit (node:events:514:28) Feb 11 21:34:10 volumiooe volumio[19953]: at addChunk (node:internal/streams/readable:343:12) Feb 11 21:34:10 volumiooe volumio[19953]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 11 21:34:10 volumiooe volumio[19953]: at Readable.push (node:internal/streams/readable:253:10) Feb 11 21:34:10 volumiooe volumio[19953]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Feb 11 21:34:10 volumiooe volumio[19953]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 21:34:11 volumiooe sudo[20929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 21:33' Feb 11 21:34:11 volumiooe sudo[20929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:11 volumiooe sudo[20929]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:12 volumiooe volumio-remote-updater[753]: [2026-02-11 21:34:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 21:34:12 volumiooe volumio-remote-updater[753]: [2026-02-11 21:34:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 21:34:12 volumiooe go-librespot[20141]: time="2026-02-11T21:34:12+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Feb 11 21:34:12 volumiooe systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 11 21:34:12 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:12.051+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 11 21:34:12 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:12.062+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 11 21:34:12 volumiooe systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 11 21:34:12 volumiooe systemd[1]: volumio.service: Consumed 4min 41.286s CPU time. Feb 11 21:34:12 volumiooe systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 21:34:12 volumiooe systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 21:34:12 volumiooe systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Feb 11 21:34:12 volumiooe systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 11 21:34:12 volumiooe systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 11 21:34:12 volumiooe systemd[1]: volumio.service: Consumed 4min 41.286s CPU time. Feb 11 21:34:12 volumiooe systemd[1]: Started volumio.service - Volumio Backend Module. Feb 11 21:34:12 volumiooe systemd[1]: dynamicswap.service: Deactivated successfully. Feb 11 21:34:12 volumiooe go-librespot[20141]: time="2026-02-11T21:34:12+01:00" level=error msg="failed put state after volume change" error="context deadline exceeded" Feb 11 21:34:12 volumiooe go-librespot[20141]: time="2026-02-11T21:34:12+01:00" level=trace msg="emitting websocket event: volume" Feb 11 21:34:13 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:13.064+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 11 21:34:14 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:14.065+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 11 21:34:14 volumiooe volumio[20943]: info: ------------------------------------------- Feb 11 21:34:14 volumiooe volumio[20943]: info: ----- Volumio3 ---- Feb 11 21:34:14 volumiooe volumio[20943]: info: ------------------------------------------- Feb 11 21:34:14 volumiooe volumio[20943]: info: ----- System startup ---- Feb 11 21:34:14 volumiooe volumio[20943]: info: ------------------------------------------- Feb 11 21:34:17 volumiooe volumio-remote-updater[753]: [2026-02-11 21:34:17] [connect] Successful connection Feb 11 21:34:22 volumiooe volumio[20943]: info: MYVOLUMIO Environment detected Feb 11 21:34:22 volumiooe volumio[20943]: info: Plugin folders cleanup Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning into folder /volumio/app/plugins/ Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category audio_interface Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category miscellanea Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category music_service Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category plugins.json Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category system_controller Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category user_interface Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning into folder /data/plugins/ Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category music_service Feb 11 21:34:22 volumiooe volumio[20943]: info: Scanning category user_interface Feb 11 21:34:22 volumiooe volumio[20943]: info: Plugin folders cleanup completed Feb 11 21:34:22 volumiooe volumio[20943]: info: ------------------------------------------- Feb 11 21:34:22 volumiooe volumio[20943]: info: ----- Core plugins startup ---- Feb 11 21:34:22 volumiooe volumio[20943]: info: ------------------------------------------- Feb 11 21:34:22 volumiooe volumio[20943]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 21:34:22 volumiooe volumio[20943]: info: Adding plugin upnp to MyMusic Plugins Feb 11 21:34:22 volumiooe volumio[20943]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 21:34:22 volumiooe volumio[20943]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 21:34:22 volumiooe volumio[20943]: info: Loading plugins from folder /data/plugins/ Feb 11 21:34:22 volumiooe volumio[20943]: info: Loading plugin "system"... Feb 11 21:34:22 volumiooe volumio[20943]: info: Loading plugin "appearance"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "network"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Refreshing Cached IP Addresses Feb 11 21:34:24 volumiooe sudo[20971]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 21:34:24 volumiooe sudo[20971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:24 volumiooe sudo[20971]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:24 volumiooe sudo[20973]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 21:34:24 volumiooe sudo[20973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "services"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "volumio5onboarding"... Feb 11 21:34:24 volumiooe sudo[20973]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:24 volumiooe sudo[20981]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 21:34:24 volumiooe sudo[20981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "alsa_controller"... Feb 11 21:34:24 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "wizard"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "networkfs"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Cannot mount NAS syn213 at system boot, trial number 1 ,retrying in 5 seconds Feb 11 21:34:24 volumiooe volumio[20943]: info: Starting Udev Watcher for removable devices Feb 11 21:34:24 volumiooe volumio[20943]: info: Ignoring mount for partition: boot Feb 11 21:34:24 volumiooe volumio[20943]: info: Ignoring mount for partition: volumio Feb 11 21:34:24 volumiooe volumio[20943]: info: Ignoring mount for partition: volumio_data Feb 11 21:34:24 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "volumio_command_line_client"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "upnp"... Feb 11 21:34:24 volumiooe volumio[20943]: info: [1770842064806] Starting Upmpd Daemon Feb 11 21:34:24 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "my_music"... Feb 11 21:34:24 volumiooe volumio[20943]: info: Loading plugin "mpd"... Feb 11 21:34:24 volumiooe go-librespot[20141]: time="2026-02-11T21:34:24+01:00" level=trace msg="sent dealer ping" Feb 11 21:34:25 volumiooe go-librespot[20141]: time="2026-02-11T21:34:25+01:00" level=trace msg="received dealer pong" Feb 11 21:34:25 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:25.067+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:36298->127.0.0.1:3000: i/o timeout" Feb 11 21:34:25 volumiooe sudo[20981]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:25 volumiooe volumio[20943]: info: Loading plugin "upnp_browser"... Feb 11 21:34:25 volumiooe volumio5-onboarding[4054]: time=2026-02-11T21:34:25.746+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.9.222:46904 @ 0x2c907e0" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Feb 11 21:34:27 volumiooe volumio[20943]: info: Starting UPNP Browser Feb 11 21:34:27 volumiooe volumio[20943]: info: Loading plugin "alarm-clock"... Feb 11 21:34:27 volumiooe volumio[20943]: info: Plugin airplay_emulation is not enabled Feb 11 21:34:27 volumiooe volumio[20943]: info: Loading plugin "last_100"... Feb 11 21:34:27 volumiooe volumio[20943]: info: Loading plugin "webradio"... Feb 11 21:34:27 volumiooe volumio[20943]: info: Loading plugin "i2s_dacs"... Feb 11 21:34:27 volumiooe volumio[20943]: info: I2S DAC not set, start Auto-detection Feb 11 21:34:27 volumiooe volumio[20943]: info: Loading plugin "volumiodiscovery"... Feb 11 21:34:27 volumiooe volumio[20943]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 21:34:27 volumiooe volumio[20943]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 21:34:27 volumiooe volumio[20943]: *** WARNING *** For more information see Feb 11 21:34:27 volumiooe volumio[20943]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 21:34:27 volumiooe volumio[20943]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 21:34:27 volumiooe volumio[20943]: *** WARNING *** For more information see Feb 11 21:34:27 volumiooe node[20943]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 21:34:27 volumiooe node[20943]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 21:34:27 volumiooe node[20943]: *** WARNING *** For more information see Feb 11 21:34:27 volumiooe node[20943]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 21:34:27 volumiooe node[20943]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 21:34:27 volumiooe node[20943]: *** WARNING *** For more information see Feb 11 21:34:27 volumiooe volumio[20943]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 21:34:27 volumiooe volumio[20943]: info: Discovery: Started advertising with name: VolumioOE Feb 11 21:34:27 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 21:34:27 volumiooe volumio[20943]: info: Loading plugin "spop"... Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "outputs"... Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "albumart"... Feb 11 21:34:29 volumiooe volumio[20943]: info: Plugin example_plugin is not enabled Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "inputs"... Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "updater_comm"... Feb 11 21:34:29 volumiooe volumio-remote-updater[753]: [2026-02-11 21:34:29] [connect] Successful connection Feb 11 21:34:29 volumiooe volumio[20943]: info: Plugin mpdemulation is not enabled Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "rest_api"... Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "websocket"... Feb 11 21:34:29 volumiooe volumio[20943]: info: Starting Socket.io Server version 1.7.4 Feb 11 21:34:29 volumiooe volumio[20943]: info: Loading plugin "podcast"... Feb 11 21:34:30 volumiooe volumio[21006]: Forking 3 albumart workers Feb 11 21:34:30 volumiooe volumio[20943]: info: ControllerPodcast::constructor Feb 11 21:34:30 volumiooe volumio[20943]: info: Plugin Systeminfo is not enabled Feb 11 21:34:30 volumiooe volumio[20943]: info: Loading i18n strings for locale it Feb 11 21:34:30 volumiooe volumio[20943]: Updating browse sources language Feb 11 21:34:30 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:30 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 21:34:30 volumiooe volumio[20943]: info: CoreCommandRouter::initPlayerControls Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: Express server listening on port 3000 Feb 11 21:34:31 volumiooe volumio[20943]: [Metrics] WebUI: 16s 812.29ms Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::resetVolumioState Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::getcurrentVolume Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 21:34:31 volumiooe volumio[20943]: info: Cannot mount NAS syn213 at system boot, trial number 2 ,retrying in 5 seconds Feb 11 21:34:31 volumiooe volumio[20943]: info: Volumio Network Manager: Network status updated: 1 Feb 11 21:34:31 volumiooe volumio[20943]: info: VolumeController:: Volume=64 Mute =false Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::pushState Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::updateTrackBlock Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrackBlock Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 21:34:31 volumiooe volumio[21018]: Starting albumart workers Feb 11 21:34:31 volumiooe volumio[21017]: Starting albumart workers Feb 11 21:34:31 volumiooe volumio[21016]: Starting albumart workers Feb 11 21:34:31 volumiooe volumio[20943]: verbose: New Socket.io Connection to 192.168.9.195 from 192.168.9.222 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 11 21:34:31 volumiooe volumio[20943]: info: Reloading queue from file Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::setRepeat null single undefined Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::pushState Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::setRandom null Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::pushState Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:31 volumiooe volumio[20943]: info: Setting Device type: Raspberry PI Feb 11 21:34:31 volumiooe volumio[20943]: verbose: New Socket.io Connection to 192.168.9.195 from 192.168.9.222 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Feb 11 21:34:31 volumiooe volumio[20943]: verbose: New Socket.io Connection to 192.168.9.195 from 192.168.9.222 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 11 21:34:31 volumiooe volumio[20943]: info: VolumeController:: Volume=64 Mute =false Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreStateMachine::pushState Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioPushState Feb 11 21:34:31 volumiooe volumio[20943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 11 21:34:31 volumiooe volumio[20943]: info: Discovery: adding 3232e111-8adb-43b6-8b5e-7cba47643604 Feb 11 21:34:31 volumiooe volumio[20943]: info: Discovery: Found device VolumioOE Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:31 volumiooe volumio-remote-updater[753]: [2026-02-11 21:34:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770842069 101 Feb 11 21:34:31 volumiooe volumio[20943]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 11 21:34:31 volumiooe volumio[20943]: info: Discovery: Getting this device information Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:31 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:31 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 11 21:34:32 volumiooe volumio[20943]: info: Discovery: this is already registered, 3232e111-8adb-43b6-8b5e-7cba47643604 Feb 11 21:34:32 volumiooe volumio[20943]: info: Discovery: Found device VolumioOE Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:32 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:32 volumiooe volumio[20943]: verbose: New Socket.io Connection to 192.168.9.195 from 192.168.9.222 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Feb 11 21:34:32 volumiooe volumio[20943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Feb 11 21:34:32 volumiooe volumio[20943]: info: Completed loading Core Plugins Feb 11 21:34:32 volumiooe volumio[20943]: info: Preparing to generate the ALSA configuration file Feb 11 21:34:32 volumiooe volumio[20943]: verbose: New Socket.io Connection to 192.168.9.195:3000 from 192.168.9.222 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Feb 11 21:34:32 volumiooe volumio[20943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 11 21:34:32 volumiooe volumio[20943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Feb 11 21:34:32 volumiooe volumio[20943]: info: Asound.conf file unchanged, so no further update is needed Feb 11 21:34:32 volumiooe volumio[20943]: info: Output device has changed, restarting MPD Feb 11 21:34:32 volumiooe volumio[20943]: info: ___________ START PLUGINS ___________ Feb 11 21:34:32 volumiooe sudo[21073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 21:34:32 volumiooe sudo[21073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:32 volumiooe sudo[21073]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:32 volumiooe volumio[20943]: info: ControllerMpd::onStart: Initializing MPD Feb 11 21:34:32 volumiooe volumio[20943]: info: Creating MPD Configuration file Feb 11 21:34:32 volumiooe sudo[21075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 21:34:32 volumiooe sudo[21075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 21:34:32 volumiooe volumio[20943]: info: [1770842072364] CoreMusicLibrary::Adding element Server multimediali Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:32 volumiooe sudo[21083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 11 21:34:32 volumiooe sudo[21083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:32 volumiooe sudo[21085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 21:34:32 volumiooe sudo[21085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:32 volumiooe sudo[21085]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:32 volumiooe sudo[21088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 21:34:32 volumiooe volumio[20943]: info: UPNP Browser: Client initialized successfully Feb 11 21:34:32 volumiooe systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 11 21:34:32 volumiooe sudo[21088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:32 volumiooe sudo[21083]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 21:34:32 volumiooe volumio[20943]: info: [1770842072488] CoreMusicLibrary::Adding element Last_100 Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 21:34:32 volumiooe volumio[20943]: info: [1770842072503] CoreMusicLibrary::Adding element Webradio Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 21:34:32 volumiooe volumio[20943]: info: Initializing BBC Radios Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 21:34:32 volumiooe volumio[20943]: info: Creating Spotify config file Feb 11 21:34:32 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:33 volumiooe volumio[20943]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 21:34:33 volumiooe volumio[20943]: info: [1770842073723] CoreMusicLibrary::Adding element Podcast Feb 11 21:34:33 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:33 volumiooe volumio[20943]: Cannot find translation for source Podcast Feb 11 21:34:33 volumiooe volumio[20943]: info: Volumio Calling Home Feb 11 21:34:33 volumiooe volumio[20943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Feb 11 21:34:33 volumiooe volumio[20943]: info: Received Get System Info Feb 11 21:34:33 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 11 21:34:33 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 11 21:34:33 volumiooe volumio[20943]: info: Discovery: Getting this device information Feb 11 21:34:33 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:33 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:33 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 11 21:34:34 volumiooe volumio[20943]: error: Upnp client error: Error: This socket has been ended by the other party Feb 11 21:34:34 volumiooe volumio[20943]: info: MPD Permissions set Feb 11 21:34:34 volumiooe volumio[20943]: info: MPD Permissions set Feb 11 21:34:34 volumiooe volumio[20943]: info: Spotify config file written Feb 11 21:34:34 volumiooe sudo[21119]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 21:34:34 volumiooe sudo[21119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:34 volumiooe volumio[20943]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 11 21:34:34 volumiooe volumio[20943]: info: No need to fix Spotify hosts Feb 11 21:34:34 volumiooe systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 11 21:34:34 volumiooe systemd[1]: go-librespot-daemon.service: Killing process 20151 (go-librespot) with signal SIGKILL. Feb 11 21:34:34 volumiooe systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 11 21:34:34 volumiooe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 11 21:34:34 volumiooe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 11 21:34:34 volumiooe sudo[21119]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:34 volumiooe go-librespot[21121]: go-librespot daemon starting... Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=info msg="running go-librespot 0.6.2" Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=debug msg="app state loaded" Feb 11 21:34:34 volumiooe volumio[20943]: info: Volumio called home Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 21:34:34 volumiooe volumio[20943]: info: New Spotify access tokenBQBL79Fa3i... Feb 11 21:34:34 volumiooe volumio[20943]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:34 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:34 volumiooe systemd[1]: mpd.service: Deactivated successfully. Feb 11 21:34:34 volumiooe systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 11 21:34:34 volumiooe systemd[1]: mpd.service: Consumed 12.534s CPU time. Feb 11 21:34:34 volumiooe systemd[1]: mpd.socket: Deactivated successfully. Feb 11 21:34:34 volumiooe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 11 21:34:34 volumiooe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 11 21:34:34 volumiooe volumio[20943]: SPOTIFY: User informations: {"country":"IT","display_name":"tupulinoe","email":"ortu.enrico@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/tupulinoe"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/tupulinoe","id":"tupulinoe","images":[],"product":"premium","type":"user","uri":"spotify:user:tupulinoe"} Feb 11 21:34:34 volumiooe volumio[20943]: info: Spotify Successfully logged in Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 21:34:34 volumiooe volumio[20943]: info: [1770842074780] CoreMusicLibrary::Adding element Spotify Feb 11 21:34:34 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:34 volumiooe volumio[20943]: Cannot find translation for source Podcast Feb 11 21:34:34 volumiooe volumio[20943]: Cannot find translation for source Spotify Feb 11 21:34:34 volumiooe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 11 21:34:34 volumiooe systemd[1]: Starting mpd.service - Music Player Daemon... Feb 11 21:34:34 volumiooe sudo[21158]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 21:34:34 volumiooe sudo[21158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:34 volumiooe sudo[21158]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:34 volumiooe sudo[21161]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 21:34:34 volumiooe sudo[21161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:34 volumiooe sudo[21161]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 11 21:34:34 volumiooe go-librespot[21122]: time="2026-02-11T21:34:34+01:00" level=info msg="zeroconf server listening on port 46349" Feb 11 21:34:35 volumiooe sudo[21165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 21:34:35 volumiooe sudo[21165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="obtained new client token: AACz+Uqp0MsDWIehxNZdtHpYw1knk/wRarUkN9ir1x4oaYs1fv3DbltN7ZA4Qzx5eUOV1NsxGn8vgw57tsgd7WqP4tlnqY8qjNckbq0TwMaFH3Gt6zKaEB8qEdxIXmPAXY1/kgWx0HwhukFPXmvX4stpEuIPPT/xDP6tFD3MjYM9aeC74AhuChYpKSEgzuRRoWA42xC1ul+H60kBrfyGphRfqbgzTEN+u6CfHgIO5do8qrfjXYGijA==" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 11 21:34:35 volumiooe sudo[21165]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="completed keyexchange" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="completed challenge" Feb 11 21:34:35 volumiooe sudo[21160]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 21:34:35 volumiooe sudo[21160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 11 21:34:35 volumiooe volumio[20943]: info: Upmpdcli Daemon Started Feb 11 21:34:35 volumiooe sudo[21160]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=info msg="authenticated AP" username="tu*****oe" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=info msg="authenticated Login5" username="tu*****oe" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="initializing zeroconf session" username="tu*****oe" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="dealer connection opened" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=trace msg="starting accesspoint recv loop" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=trace msg="starting dealer recv loop" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=trace msg="received accesspoint ping" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="received connection id: OTcwYzU2NzktNmJk...OEU3MTRDQjkwMg==" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=trace msg="received accesspoint pong ack" Feb 11 21:34:35 volumiooe go-librespot[21122]: time="2026-02-11T21:34:35+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 11 21:34:36 volumiooe volumio[20943]: info: Cannot mount NAS syn213 at system boot, trial number 3 ,retrying in 5 seconds Feb 11 21:34:36 volumiooe volumio[20943]: verbose: New Socket.io Connection to 192.168.9.195 from 192.168.9.222 UA: Mozilla/5.0 (Linux; Android 13; DN2103 Build/TP1A.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.132 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetVisibleSources Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:36 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 11 21:34:36 volumiooe volumio[20943]: info: Received Get System Info Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 11 21:34:36 volumiooe volumio[20943]: info: Discovery: Getting this device information Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:36 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetState Feb 11 21:34:36 volumiooe volumio[20943]: info: CorePlayQueue::getTrack 0 Feb 11 21:34:36 volumiooe volumio[20943]: info: Listing playlists Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreCommandRouter::volumioGetQueue Feb 11 21:34:36 volumiooe volumio[20943]: info: CoreStateMachine::getQueue Feb 11 21:34:36 volumiooe volumio[20943]: info: CorePlayQueue::getQueue Feb 11 21:34:37 volumiooe volumio[20943]: info: go-librespot daemon successfully initialized Feb 11 21:34:39 volumiooe mpd[21168]: 2026-02-11T21:34:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 21:34:40 volumiooe volumio[20943]: info: Initializing connection to go-librespot Websocket Feb 11 21:34:40 volumiooe go-librespot[21122]: time="2026-02-11T21:34:40+01:00" level=debug msg="new websocket client" Feb 11 21:34:40 volumiooe volumio[20943]: info: Connection to go-librespot Websocket established Feb 11 21:34:41 volumiooe volumio[20943]: info: Cannot mount NAS syn213 at system boot, trial number 4 ,retrying in 5 seconds Feb 11 21:34:42 volumiooe volumio[20943]: info: Preload queue cleared Feb 11 21:34:42 volumiooe volumio[20943]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 11 21:34:42 volumiooe volumio[20943]: info: CoreStateMachine::ClearQueue Feb 11 21:34:42 volumiooe volumio[20943]: info: CoreStateMachine::stop Feb 11 21:34:42 volumiooe volumio[20943]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 11 21:34:42 volumiooe volumio[20943]: info: CorePlayQueue::clearPlayQueue Feb 11 21:34:42 volumiooe volumio[20943]: info: CorePlayQueue::saveQueue Feb 11 21:34:42 volumiooe volumio[20943]: info: CoreCommandRouter::volumioPushQueue Feb 11 21:34:42 volumiooe volumio[20943]: info: CoreStateMachine::addQueueItems Feb 11 21:34:42 volumiooe volumio[20943]: info: CorePlayQueue::addQueueItems Feb 11 21:34:42 volumiooe volumio[20943]: info: Preload queue cleared Feb 11 21:34:42 volumiooe volumio[20943]: info: Adding Item to queue: music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 Feb 11 21:34:42 volumiooe volumio[20943]: info: Exploding uri music-library/NAS/syn213/MUSICA/Zucchero Sugar Fornaciari/Zucchero Sugar Fornaciari_Oro Incenso & Birra/Zucchero Sugar Fornaciari_Oro Incenso & Birra_01-Overdose (d'amore).mp3 in service mpd Feb 11 21:34:42 volumiooe volumio[20943]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 21:34:42 volumiooe volumio[20943]: TypeError: Cannot read properties of undefined (reading 'then') Feb 11 21:34:42 volumiooe volumio[20943]: at ControllerMpd.scanFolder (/volumio/app/plugins/music_service/mpd/index.js:2541:19) Feb 11 21:34:42 volumiooe volumio[20943]: at ControllerMpd.explodeUri (/volumio/app/plugins/music_service/mpd/index.js:2339:21) Feb 11 21:34:42 volumiooe volumio[20943]: at CoreCommandRouter.explodeUriFromService (/volumio/app/index.js:1384:16) Feb 11 21:34:42 volumiooe volumio[20943]: at CorePlayQueue.explodeUriFromCache (/volumio/app/playqueue.js:123:24) Feb 11 21:34:42 volumiooe volumio[20943]: at CorePlayQueue.explodeUri (/volumio/app/playqueue.js:181:19) Feb 11 21:34:42 volumiooe volumio[20943]: at CorePlayQueue.addQueueItems (/volumio/app/playqueue.js:223:30) Feb 11 21:34:42 volumiooe volumio[20943]: at CoreStateMachine.addQueueItems (/volumio/app/statemachine.js:251:25) Feb 11 21:34:42 volumiooe volumio[20943]: at CoreCommandRouter.replaceAndPlay (/volumio/app/index.js:511:25) Feb 11 21:34:42 volumiooe volumio[20943]: at CoreCommandRouter.playItemsList (/volumio/app/index.js:484:17) Feb 11 21:34:42 volumiooe volumio[20943]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:142:33) Feb 11 21:34:42 volumiooe volumio[20943]: at Socket.emit (node:events:514:28) Feb 11 21:34:42 volumiooe volumio[20943]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Feb 11 21:34:42 volumiooe volumio[20943]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Feb 11 21:34:42 volumiooe volumio[20943]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 21:34:42 volumiooe systemd[1]: Started mpd.service - Music Player Daemon. Feb 11 21:34:42 volumiooe sudo[21075]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:42 volumiooe sudo[21088]: pam_unix(sudo:session): session closed for user root Feb 11 21:34:42 volumiooe sudo[21187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 21:33' Feb 11 21:34:42 volumiooe sudo[21187]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"