Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand update Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand update took 5 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 3 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatetrue Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 37 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 2 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 1 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 1 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 1 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatetrue Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatetrue Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 71ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 37ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 37ms Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: info: MPD Database updated - AlbumList cache refreshed Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: database Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: MPD Database updated - AlbumList cache refreshed Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: database Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: MPD Database updated - AlbumList cache refreshed Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: database Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: Dec 09 19:27:02 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 12 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 12 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 12 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 34ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 34ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 39 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 39 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 39 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 53ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 54ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 56 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 56 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: info: sendMpdCommand status took 56 milliseconds Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:02 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:02 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 71ms Dec 09 19:27:02 volumio-hp volumio[1117]: info: ------------------------------ 70ms Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:02 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 09 19:27:07 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 09 19:27:11 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 09 19:27:13 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioGetState Dec 09 19:27:13 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:18 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 09 19:27:18 volumio-hp volumio[1117]: info: CURURI: albums:// Dec 09 19:27:18 volumio-hp volumio[1117]: info: listAlbums - loading Albums from cache Dec 09 19:27:18 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:27:23 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 09 19:27:23 volumio-hp volumio[1117]: info: CURURI: music-library Dec 09 19:27:23 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:27:23 volumio-hp go-librespot[1895]: time="2025-12-09T19:27:23+01:00" level=trace msg="sent dealer ping" Dec 09 19:27:23 volumio-hp go-librespot[1895]: time="2025-12-09T19:27:23+01:00" level=trace msg="received dealer pong" Dec 09 19:27:24 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 09 19:27:24 volumio-hp volumio[1117]: info: CURURI: music-library/INTERNAL Dec 09 19:27:24 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand update Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand update took 2 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 1 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 0 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatetrue Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 169ms Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: MPD Database updated - AlbumList cache refreshed Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: database Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 3 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 3 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 2 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 2 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 37ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 36ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: MPD Database updated - AlbumList cache refreshed Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: database Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: MPD Database updated - AlbumList cache refreshed Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: database Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: Dec 09 19:27:32 volumio-hp volumio[1117]: ---------------------------- MPD announces state update: update Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::getState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 44 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 43 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 43 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 59ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 59ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 26 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 26 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 26 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 38ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 38ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 40 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 40 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: info: sendMpdCommand status took 38 milliseconds Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: Command Router : Notfying DB Updatefalse Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::Close All Modals sent Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: verbose: ControllerMpd::parseState Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ControllerMpd::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::servicePushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:27:32 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:27:32 volumio-hp volumio[1117]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 58ms Dec 09 19:27:32 volumio-hp volumio[1117]: info: ------------------------------ 58ms Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:32 volumio-hp volumio[1117]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 09 19:27:34 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 09 19:27:34 volumio-hp volumio[1117]: info: CURURI: music-library/INTERNAL Dec 09 19:27:34 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:27:50 volumio-hp kernel: usb 2-4.4: new high-speed USB device number 5 using xhci_hcd Dec 09 19:27:50 volumio-hp kernel: usb 2-4.4: New USB device found, idVendor=2972, idProduct=0047, bcdDevice= 1.24 Dec 09 19:27:50 volumio-hp kernel: usb 2-4.4: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Dec 09 19:27:50 volumio-hp kernel: usb 2-4.4: Product: FiiO K7 Dec 09 19:27:50 volumio-hp kernel: usb 2-4.4: Manufacturer: GuangZhou FiiO Electronics Co.,Ltd Dec 09 19:27:53 volumio-hp go-librespot[1895]: time="2025-12-09T19:27:53+01:00" level=trace msg="received accesspoint ping" Dec 09 19:27:53 volumio-hp go-librespot[1895]: time="2025-12-09T19:27:53+01:00" level=trace msg="received accesspoint pong ack" Dec 09 19:27:53 volumio-hp go-librespot[1895]: time="2025-12-09T19:27:53+01:00" level=trace msg="sent dealer ping" Dec 09 19:27:53 volumio-hp go-librespot[1895]: time="2025-12-09T19:27:53+01:00" level=trace msg="received dealer pong" Dec 09 19:27:54 volumio-hp kernel: usbcore: registered new interface driver snd-usb-audio Dec 09 19:27:54 volumio-hp volumio[1117]: info: Dec 09 19:27:54 volumio-hp volumio[1117]: ---------------------------- USB Audio Device Attached Dec 09 19:27:54 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Dec 09 19:28:00 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioGetState Dec 09 19:28:00 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 09 19:28:03 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 09 19:28:06 volumio-hp volumio[1117]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 09 19:28:06 volumio-hp volumio[1117]: info: Preparing to save Alsa Options, stopping services first Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioGetState Dec 09 19:28:06 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPause Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreStateMachine::pause Dec 09 19:28:06 volumio-hp volumio[1117]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"FiiO K7"}} Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 09 19:28:06 volumio-hp volumio[1117]: info: Device 5 does not have any Mixer Control Available Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 09 19:28:06 volumio-hp volumio[1117]: info: Updating Volume Controller Parameters: Device: 5 Name: FiiO K7 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 09 19:28:06 volumio-hp volumio[1117]: info: Disabling external Volume Control Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:28:06 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:28:06 volumio-hp volumio[1117]: info: Preparing to generate the ALSA configuration file Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 09 19:28:06 volumio-hp volumio[1117]: info: Asound.conf file written Dec 09 19:28:06 volumio-hp sudo[2511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 09 19:28:06 volumio-hp sudo[2511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp sudo[2511]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:06 volumio-hp volumio[1117]: info: Output device has changed, restarting MPD Dec 09 19:28:06 volumio-hp volumio[1117]: info: Output device has changed, restarting Shairport Sync Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 19:28:06 volumio-hp sudo[2517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 19:28:06 volumio-hp sudo[2517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp sudo[2517]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:06 volumio-hp sudo[2519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 19:28:06 volumio-hp sudo[2519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp volumio[1117]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 19:28:06 volumio-hp volumio[1117]: info: Output device has changed, restarting MPD Dec 09 19:28:06 volumio-hp systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 09 19:28:06 volumio-hp volumio[1117]: info: Output device has changed, restarting Shairport Sync Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 19:28:06 volumio-hp sudo[2527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 09 19:28:06 volumio-hp sudo[2527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp sudo[2527]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:06 volumio-hp sudo[2529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 09 19:28:06 volumio-hp sudo[2529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp volumio[1117]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 09 19:28:06 volumio-hp volumio[1117]: info: MPD Permissions set Dec 09 19:28:06 volumio-hp volumio[1117]: info: MPD Permissions set Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 09 19:28:06 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 09 19:28:06 volumio-hp volumio[1117]: info: Starting Shairport Sync Dec 09 19:28:06 volumio-hp systemd[1]: mpd.service: Deactivated successfully. Dec 09 19:28:06 volumio-hp systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 09 19:28:06 volumio-hp systemd[1]: mpd.service: Consumed 1.270s CPU time. Dec 09 19:28:06 volumio-hp systemd[1]: mpd.socket: Deactivated successfully. Dec 09 19:28:06 volumio-hp systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 09 19:28:06 volumio-hp systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 09 19:28:06 volumio-hp volumio[1117]: info: Starting Shairport Sync Dec 09 19:28:06 volumio-hp sudo[2553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 19:28:06 volumio-hp sudo[2553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp sudo[2557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 09 19:28:06 volumio-hp sudo[2557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:06 volumio-hp systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 09 19:28:06 volumio-hp systemd[1]: Starting mpd.service - Music Player Daemon... Dec 09 19:28:06 volumio-hp systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 09 19:28:06 volumio-hp systemd[1]: shairport-sync.service: Deactivated successfully. Dec 09 19:28:06 volumio-hp systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 19:28:06 volumio-hp systemd[1]: shairport-sync.service: Consumed 2.096s CPU time. Dec 09 19:28:06 volumio-hp systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 09 19:28:06 volumio-hp sudo[2557]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:06 volumio-hp volumio[1117]: info: Shairport-Sync Started Dec 09 19:28:06 volumio-hp sudo[2553]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:06 volumio-hp volumio[1117]: info: Shairport-Sync Started Dec 09 19:28:06 volumio-hp sudo[2559]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 09 19:28:06 volumio-hp sudo[2559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 09 19:28:06 volumio-hp sudo[2559]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:07 volumio-hp mpd[2576]: 2025-12-09T19:28:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 09 19:28:07 volumio-hp systemd[1]: Started mpd.service - Music Player Daemon. Dec 09 19:28:07 volumio-hp sudo[2519]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:07 volumio-hp sudo[2529]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:07 volumio-hp volumio[1117]: error: MPD error: The expression evaluated to a falsy value: Dec 09 19:28:07 volumio-hp volumio[1117]: assert.ok(self.idling) Dec 09 19:28:07 volumio-hp volumio[1117]: error: The expression evaluated to a falsy value: Dec 09 19:28:07 volumio-hp volumio[1117]: assert.ok(self.idling) Dec 09 19:28:07 volumio-hp volumio[1117]: error: updateQueue error: null Dec 09 19:28:09 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioGetState Dec 09 19:28:09 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:28:10 volumio-hp sudo[2584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 19:28:10 volumio-hp sudo[2584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:10 volumio-hp systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 19:28:10 volumio-hp systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 19:28:10 volumio-hp systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 19:28:10 volumio-hp sudo[2587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 09 19:28:10 volumio-hp sudo[2587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 09 19:28:10 volumio-hp systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 19:28:10 volumio-hp sudo[2584]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:10 volumio-hp mpd_monitor.sh[2589]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 19:28:10 volumio-hp volumio[1117]: info: Successfully started MPD Monitor Dec 09 19:28:10 volumio-hp systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 09 19:28:10 volumio-hp systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 09 19:28:10 volumio-hp systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 09 19:28:10 volumio-hp systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 09 19:28:10 volumio-hp sudo[2587]: pam_unix(sudo:session): session closed for user root Dec 09 19:28:10 volumio-hp mpd_monitor.sh[2591]: MPD Monitor Service: Starting MPD Monitor Service Dec 09 19:28:10 volumio-hp volumio[1117]: info: Successfully started MPD Monitor Dec 09 19:28:10 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 09 19:28:10 volumio-hp volumio[1117]: info: CoreStateMachine::getcurrentVolume Dec 09 19:28:10 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioRetrievevolume Dec 09 19:28:10 volumio-hp volumio[1117]: info: CoreStateMachine::pushState Dec 09 19:28:10 volumio-hp volumio[1117]: info: CorePlayQueue::getTrack 0 Dec 09 19:28:10 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushState Dec 09 19:28:14 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 09 19:28:14 volumio-hp volumio[1117]: info: CURURI: music-library/INTERNAL/Dire Straits Dec 09 19:28:14 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:28:16 volumio-hp volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 09 19:28:16 volumio-hp volumio[1117]: info: CURURI: music-library/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US) Dec 09 19:28:16 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:28:23 volumio-hp go-librespot[1895]: time="2025-12-09T19:28:23+01:00" level=trace msg="sent dealer ping" Dec 09 19:28:23 volumio-hp go-librespot[1895]: time="2025-12-09T19:28:23+01:00" level=trace msg="received dealer pong" Dec 09 19:28:25 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:28:25 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 09 19:28:25 volumio-hp volumio[1117]: info: CoreStateMachine::ClearQueue Dec 09 19:28:25 volumio-hp volumio[1117]: info: CoreStateMachine::stop Dec 09 19:28:25 volumio-hp volumio[1117]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 09 19:28:25 volumio-hp volumio[1117]: info: CorePlayQueue::clearPlayQueue Dec 09 19:28:25 volumio-hp volumio[1117]: info: CorePlayQueue::saveQueue Dec 09 19:28:25 volumio-hp volumio[1117]: info: CoreCommandRouter::volumioPushQueue Dec 09 19:28:25 volumio-hp volumio[1117]: info: CoreStateMachine::addQueueItems Dec 09 19:28:25 volumio-hp volumio[1117]: info: CorePlayQueue::addQueueItems Dec 09 19:28:25 volumio-hp volumio[1117]: info: Preload queue cleared Dec 09 19:28:25 volumio-hp volumio[1117]: info: Adding Item to queue: music-library/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US) Dec 09 19:28:25 volumio-hp volumio[1117]: info: Exploding uri music-library/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US) in service mpd Dec 09 19:28:25 volumio-hp volumio[1117]: info: ALBUMART /albumart?cacheid=822&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FDire%20Straits%2FDire%20Straits%20-%20Brother%20In%20Arms%20(US)%2FDire%20Straits%20-%20Brother%20In%20Arms%20-%20LP%20-%20Side%201.flac&metadata=false Dec 09 19:28:25 volumio-hp volumio[1117]: info: URI /mnt/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US)/Dire Straits - Brother In Arms - LP - Side 1.flac Dec 09 19:28:25 volumio-hp volumio[1117]: info: ALBUMART /albumart?cacheid=822&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FDire%20Straits%2FDire%20Straits%20-%20Brother%20In%20Arms%20(US)%2FDire%20Straits%20-%20Brother%20In%20Arms%20-%20LP%20-%20Side%202.flac&metadata=false Dec 09 19:28:25 volumio-hp volumio[1117]: info: URI /mnt/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US)/Dire Straits - Brother In Arms - LP - Side 2.flac Dec 09 19:28:25 volumio-hp volumio[1117]: info: ALBUMART /albumart?cacheid=822&web=Dire%20Straits/Brother%20In%20Arms/extralarge&path=%2Fmnt%2FINTERNAL%2FDire%20Straits%2FDire%20Straits%20-%20Brother%20In%20Arms%20(US)%2FDire%20Straits%20-%20Brother%20In%20Arms%20-%20LP%20.cue&metadata=false Dec 09 19:28:25 volumio-hp volumio[1117]: info: URI /mnt/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US)/Dire Straits - Brother In Arms - LP .cue Dec 09 19:28:25 volumio-hp volumio[1117]: info: ALBUMART /albumart?cacheid=822&web=Dire%20Straits/Brother%20In%20Arms/extralarge&path=%2Fmnt%2FINTERNAL%2FDire%20Straits%2FDire%20Straits%20-%20Brother%20In%20Arms%20(US)%2FDire%20Straits%20-%20Brother%20In%20Arms%20-%20LP%20.cue&metadata=false Dec 09 19:28:25 volumio-hp volumio[1117]: info: URI /mnt/INTERNAL/Dire Straits/Dire Straits - Brother In Arms (US)/Dire Straits - Brother In Arms - LP .cue Dec 09 19:28:25 volumio-hp volumio[1117]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 19:28:25 volumio-hp volumio[1117]: Error: Unable to resolve or reject the same promise twice Dec 09 19:28:25 volumio-hp volumio[1117]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Dec 09 19:28:25 volumio-hp volumio[1117]: at /volumio/app/plugins/music_service/mpd/index.js:2587:21 Dec 09 19:28:25 volumio-hp volumio[1117]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Dec 09 19:28:25 volumio-hp volumio[1117]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Dec 09 19:28:25 volumio-hp volumio[1117]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Dec 09 19:28:25 volumio-hp volumio[1117]: at Socket.emit (node:events:514:28) Dec 09 19:28:25 volumio-hp volumio[1117]: at addChunk (node:internal/streams/readable:343:12) Dec 09 19:28:25 volumio-hp volumio[1117]: at readableAddChunk (node:internal/streams/readable:312:11) Dec 09 19:28:25 volumio-hp volumio[1117]: at Readable.push (node:internal/streams/readable:253:10) Dec 09 19:28:25 volumio-hp volumio[1117]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Dec 09 19:28:25 volumio-hp volumio[1117]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 09 19:28:25 volumio-hp sudo[2659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-09 19:27' Dec 09 19:28:25 volumio-hp sudo[2659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 12:15:37 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="3ca59a0b3ec3a926fd3274a2fb539106"