Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand update Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: Aug 25 11:52:03 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand update took 8 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: Aug 25 11:52:03 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: Aug 25 11:52:03 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: Aug 25 11:52:03 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 17 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 14 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 14 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 12 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 12 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 9 milliseconds Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:03 volumio volumio[2304]: info: ------------------------------ 170ms Aug 25 11:52:03 volumio volumio[2304]: info: ------------------------------ 167ms Aug 25 11:52:03 volumio volumio[2304]: info: ------------------------------ 163ms Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: Aug 25 11:52:03 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: Aug 25 11:52:03 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 165 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 162 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 5 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 5 milliseconds Aug 25 11:52:03 volumio volumio[2304]: info: sendMpdCommand status took 4 milliseconds Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:03 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:03 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:03 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:03 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:03 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:03 volumio volumio[2304]: info: ------------------------------ 285ms Aug 25 11:52:03 volumio volumio[2304]: info: ------------------------------ 125ms Aug 25 11:52:04 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:04 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:04 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:04 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:04 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:04 volumio volumio[2304]: info: sendMpdCommand status took 146 milliseconds Aug 25 11:52:04 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:04 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:04 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:04 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:04 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:04 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:04 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:04 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:04 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:04 volumio volumio[2304]: info: ------------------------------ 157ms Aug 25 11:52:04 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand rescan Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: Aug 25 11:52:05 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand rescan took 6 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: Aug 25 11:52:05 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: Aug 25 11:52:05 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: Aug 25 11:52:05 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 17 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 15 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 15 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 12 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 12 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 10 milliseconds Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:05 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:05 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:05 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:05 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:05 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:05 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:05 volumio volumio[2304]: info: ------------------------------ 163ms Aug 25 11:52:05 volumio volumio[2304]: info: ------------------------------ 160ms Aug 25 11:52:05 volumio volumio[2304]: info: ------------------------------ 155ms Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: Aug 25 11:52:05 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: Aug 25 11:52:05 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:05 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 159 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 157 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 8 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 7 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 7 milliseconds Aug 25 11:52:05 volumio volumio[2304]: info: sendMpdCommand status took 5 milliseconds Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:05 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:05 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 283ms Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 131ms Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 130ms Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand rescan Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: Aug 25 11:52:06 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand rescan took 4 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: Aug 25 11:52:06 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: Aug 25 11:52:06 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: Aug 25 11:52:06 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 9 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 8 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 7 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 7 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 7 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 6 milliseconds Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatetrue Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 148ms Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 147ms Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 146ms Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: Aug 25 11:52:06 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: Aug 25 11:52:06 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 146 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 146 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 5 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 4 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:06 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:06 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:06 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:06 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:06 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 270ms Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 129ms Aug 25 11:52:06 volumio volumio[2304]: info: ------------------------------ 127ms Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:06 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:07 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 25 11:52:07 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Aug 25 11:52:07 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand rescan Aug 25 11:52:07 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:07 volumio volumio[2304]: info: Aug 25 11:52:07 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:07 volumio volumio[2304]: info: sendMpdCommand rescan took 4 milliseconds Aug 25 11:52:07 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:07 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:07 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:07 volumio volumio[2304]: info: Aug 25 11:52:07 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:07 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:07 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:07 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:07 volumio volumio[2304]: info: sendMpdCommand status took 2 milliseconds Aug 25 11:52:07 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 78ms Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 86 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 85 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 9 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 8 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 208ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 131ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 126ms Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 19 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 18 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 17 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 17 milliseconds Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 104ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 102ms Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand rescan Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand rescan took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 5 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 4 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 4 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 4 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 2 milliseconds Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 115ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 113ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 112ms Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: Aug 25 11:52:08 volumio volumio[2304]: ---------------------------- MPD announces state update: update Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::getState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::sendMpdCommand status Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 115 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 114 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 2 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: info: sendMpdCommand status took 3 milliseconds Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: Command Router : Notfying DB Updatefalse Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::Close All Modals sent Aug 25 11:52:08 volumio volumio[2304]: verbose: ControllerMpd::parseState Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ControllerMpd::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::servicePushState Aug 25 11:52:08 volumio volumio[2304]: info: CoreStateMachine::pushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: CoreCommandRouter::volumioPushState Aug 25 11:52:08 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:08 volumio volumio[2304]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 208ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 98ms Aug 25 11:52:08 volumio volumio[2304]: info: ------------------------------ 97ms Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:08 volumio volumio[2304]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Aug 25 11:52:11 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:11 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:15 volumio volumio[2304]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 25 11:52:15 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 25 11:52:15 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Aug 25 11:52:15 volumio sudo[4506]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Aug 25 11:52:15 volumio sudo[4506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:15 volumio sudo[4511]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:52:15 volumio sudo[4511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:15 volumio sudo[4517]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:52:15 volumio sudo[4517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:15 volumio sudo[4511]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:15 volumio sudo[4506]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:15 volumio sudo[4517]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:15 volumio sudo[4523]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:52:15 volumio sudo[4523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:15 volumio sudo[4529]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 11:52:15 volumio sudo[4523]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:15 volumio sudo[4529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:15 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 25 11:52:15 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 25 11:52:15 volumio sudo[4534]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:15 volumio sudo[4534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:15 volumio sudo[4529]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:15 volumio sudo[4534]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:15 volumio sudo[4540]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 25 11:52:15 volumio sudo[4540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:17 volumio sudo[4540]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:17 volumio volumio[2304]: info: Received Get System Info Aug 25 11:52:17 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:52:17 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:52:17 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:52:17 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:17 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:17 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:52:17 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:52:17 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:52:18 volumio volumio5-onboarding[2603]: time=2026-08-25T11:52:18.552+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:52:32 volumio ntpd[1137]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:52:32 volumio ntpd[1137]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 25 11:52:32 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:52:32 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:52:32 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:52:32 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:52:32 volumio ntpd[1137]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Aug 25 11:52:33 volumio ntpd[1137]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:52:33 volumio ntpd[1137]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 2400:e920:0:5::14 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 2001:df4:bac0::e35b:f223 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 2401:5b60:0:2::21 Aug 25 11:52:33 volumio ntpd[1137]: DNS: Pool skipping: 2400:d760:0:ff09::123 Aug 25 11:52:33 volumio ntpd[1137]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Aug 25 11:52:34 volumio ntpd[1137]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:52:34 volumio ntpd[1137]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 25 11:52:34 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:52:34 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:52:34 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:52:34 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:52:34 volumio ntpd[1137]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Aug 25 11:52:35 volumio ntpd[1137]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:52:35 volumio ntpd[1137]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 25 11:52:35 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:52:35 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:52:35 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:52:35 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:52:35 volumio ntpd[1137]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 25 11:52:42 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Aug 25 11:52:42 volumio volumio[2304]: info: Saving new wireless network Aug 25 11:52:42 volumio volumio[2304]: error: Not saving Password for network Quynh Phuong: shorter than 8 chars Aug 25 11:52:42 volumio sudo[4618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Aug 25 11:52:42 volumio sudo[4618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:42 volumio sudo[4618]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:42 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Aug 25 11:52:42 volumio sudo[4622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Aug 25 11:52:42 volumio sudo[4622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:42 volumio systemd[1]: Stopping wireless.service - Wireless Services... Aug 25 11:52:42 volumio systemd[1]: wireless.service: Killing process 3428 (wpa_supplicant) with signal SIGKILL. Aug 25 11:52:42 volumio systemd[1]: wireless.service: Deactivated successfully. Aug 25 11:52:42 volumio systemd[1]: Stopped wireless.service - Wireless Services. Aug 25 11:52:42 volumio systemd[1]: wireless.service: Consumed 2.340s CPU time. Aug 25 11:52:42 volumio kernel: wlan0: deauthenticating from f4:f2:6d:fe:be:48 by local choice (Reason: 3=DEAUTH_LEAVING) Aug 25 11:52:42 volumio systemd[1]: Starting wireless.service - Wireless Services... Aug 25 11:52:42 volumio dhcpcd[1054]: wlan0: carrier lost Aug 25 11:52:42 volumio avahi-daemon[3585]: Withdrawing address record for 192.168.0.100 on wlan0. Aug 25 11:52:42 volumio avahi-daemon[3585]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.100. Aug 25 11:52:42 volumio avahi-daemon[3585]: Interface wlan0.IPv4 no longer relevant for mDNS. Aug 25 11:52:42 volumio dhcpcd[1054]: wlan0: deleting route to 192.168.0.0/24 Aug 25 11:52:42 volumio volumio[2304]: info: Discovery: A device disappeared from network Aug 25 11:52:42 volumio dhcpcd[1054]: wlan0: deleting default route via 192.168.0.1 Aug 25 11:52:43 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 25 11:52:43 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Aug 25 11:52:43 volumio systemd[1]: welcome.service: Deactivated successfully. Aug 25 11:52:43 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 25 11:52:43 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 25 11:52:43 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 25 11:52:43 volumio welcome[4660]: Resolved ip:[0] Aug 25 11:52:43 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 25 11:52:43 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 25 11:52:43 volumio wireless.js[4627]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Aug 25 11:52:43 volumio wireless.js[4627]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Aug 25 11:52:43 volumio sudo[4682]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 25 11:52:43 volumio sudo[4682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:43 volumio sudo[4682]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:43 volumio sudo[4684]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 25 11:52:43 volumio sudo[4684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:43 volumio sudo[4684]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:43 volumio wireless.js[4627]: WIRELESS.JS - INFO: Cleaning previous... Aug 25 11:52:43 volumio sudo[4687]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 25 11:52:43 volumio sudo[4687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:43 volumio kernel: iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM Aug 25 11:52:43 volumio kernel: iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM Aug 25 11:52:43 volumio kernel: iwlwifi 0000:01:00.0: FW already configured (0) - re-configuring Aug 25 11:52:43 volumio sudo[4687]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:43 volumio wireless.js[4627]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 25 11:52:43 volumio wireless.js[4627]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 2ms Aug 25 11:52:43 volumio wireless.js[4627]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: a0:af:bd:86:13:6b) Aug 25 11:52:43 volumio sudo[4695]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 25 11:52:43 volumio sudo[4695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:43 volumio sudo[4695]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:43 volumio sudo[4703]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 25 11:52:43 volumio sudo[4703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:43 volumio sudo[4708]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:43 volumio sudo[4708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:43 volumio sudo[4708]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:44 volumio volumio[2304]: info: Received Get System Info Aug 25 11:52:44 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:52:44 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:52:44 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:52:44 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:44 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:44 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:52:44 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:52:44 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:52:44 volumio ntpd[1137]: IO: Deleting interface #4 wlan0, 192.168.0.100#123, interface stats: received=0, sent=16, dropped=0, active_time=268 secs Aug 25 11:52:44 volumio ntpd[1137]: PROTO: 45.252.250.189 unlink local addr 192.168.0.100 -> Aug 25 11:52:44 volumio ntpd[1137]: PROTO: 103.221.223.143 unlink local addr 192.168.0.100 -> Aug 25 11:52:44 volumio ntpd[1137]: PROTO: 160.22.74.161 unlink local addr 192.168.0.100 -> Aug 25 11:52:44 volumio ntpd[1137]: PROTO: 103.186.65.246 unlink local addr 192.168.0.100 -> Aug 25 11:52:44 volumio sudo[4712]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:44 volumio sudo[4712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:44 volumio sudo[4712]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:45 volumio volumio5-onboarding[2603]: time=2026-08-25T11:52:45.044+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:52:45 volumio sudo[4716]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:45 volumio sudo[4716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:45 volumio sudo[4716]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:46 volumio sudo[4720]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:46 volumio sudo[4720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:46 volumio sudo[4720]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:47 volumio sudo[4703]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:47 volumio wireless.js[4627]: WIRELESS.JS - INFO: Start wireless flow Aug 25 11:52:47 volumio wireless.js[4627]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Aug 25 11:52:47 volumio sudo[4726]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 25 11:52:47 volumio sudo[4726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:47 volumio sudo[4726]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:47 volumio sudo[4728]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 25 11:52:47 volumio sudo[4728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:47 volumio sudo[4728]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:47 volumio wireless.js[4627]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Aug 25 11:52:47 volumio wireless.js[4627]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: a0:af:bd:86:13:6b, USB: false) Aug 25 11:52:47 volumio wpa_supplicant[4734]: Successfully initialized wpa_supplicant Aug 25 11:52:47 volumio kernel: iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM Aug 25 11:52:47 volumio kernel: iwlwifi 0000:01:00.0: Applying debug destination EXTERNAL_DRAM Aug 25 11:52:47 volumio kernel: iwlwifi 0000:01:00.0: FW already configured (0) - re-configuring Aug 25 11:52:47 volumio wpa_supplicant[4738]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=WORLD Aug 25 11:52:47 volumio sudo[4741]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 25 11:52:47 volumio sudo[4741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:47 volumio sudo[4741]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:47 volumio sudo[4747]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:47 volumio sudo[4747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:47 volumio sudo[4747]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:48 volumio volumio[2304]: info: Received Get System Info Aug 25 11:52:48 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:52:48 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:52:48 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:52:48 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:48 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:48 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:52:48 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:52:48 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:52:48 volumio wireless.js[4627]: WIRELESS.JS - INFO: DHCP IP fallback Aug 25 11:52:48 volumio wireless.js[4627]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Aug 25 11:52:48 volumio wireless.js[4627]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Aug 25 11:52:48 volumio sudo[4755]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:48 volumio sudo[4755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:48 volumio sudo[4755]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:49 volumio volumio5-onboarding[2603]: time=2026-08-25T11:52:49.073+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:52:49 volumio wireless.js[4627]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> SCANNING (duration: 0ms) Aug 25 11:52:49 volumio sudo[4765]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:49 volumio sudo[4765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:49 volumio sudo[4765]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:50 volumio sudo[4775]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:50 volumio sudo[4775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:50 volumio sudo[4775]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:51 volumio volumio[2304]: info: Volumio Network Manager: Network status updated: 0 Aug 25 11:52:51 volumio wpa_supplicant[4738]: wlan0: SME: Trying to authenticate with f4:f2:6d:fe:be:48 (SSID='Hung' freq=2427 MHz) Aug 25 11:52:51 volumio kernel: wlan0: authenticate with f4:f2:6d:fe:be:48 (local address=a0:af:bd:86:13:6b) Aug 25 11:52:51 volumio kernel: wlan0: send auth to f4:f2:6d:fe:be:48 (try 1/3) Aug 25 11:52:51 volumio wpa_supplicant[4738]: wlan0: Trying to associate with f4:f2:6d:fe:be:48 (SSID='Hung' freq=2427 MHz) Aug 25 11:52:51 volumio kernel: wlan0: authenticated Aug 25 11:52:51 volumio kernel: wlan0: associate with f4:f2:6d:fe:be:48 (try 1/3) Aug 25 11:52:51 volumio kernel: wlan0: RX AssocResp from f4:f2:6d:fe:be:48 (capab=0x431 status=0 aid=1) Aug 25 11:52:51 volumio wpa_supplicant[4738]: wlan0: Associated with f4:f2:6d:fe:be:48 Aug 25 11:52:51 volumio wpa_supplicant[4738]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 25 11:52:51 volumio kernel: wlan0: associated Aug 25 11:52:51 volumio sudo[4796]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:51 volumio sudo[4796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:51 volumio sudo[4796]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:51 volumio wireless.js[4627]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> 4WAY_HANDSHAKE (duration: 2563ms) Aug 25 11:52:51 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:51 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:52 volumio volumio[2304]: info: Received Get System Info Aug 25 11:52:52 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:52:52 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:52:52 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:52:52 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:52 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:52 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:52:52 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:52:52 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:52:52 volumio volumio[2304]: info: Discovery: Networking Restart detected, restarting advertisement and browsing Aug 25 11:52:52 volumio volumio[2304]: info: Discovery: Restarting Advertising Aug 25 11:52:52 volumio volumio[2304]: info: Discovery: Stopping existing advertisement Aug 25 11:52:52 volumio volumio[2304]: info: Discovery: Restarting Browsing Aug 25 11:52:52 volumio sudo[4806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:52 volumio sudo[4806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:52 volumio sudo[4806]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:53 volumio volumio5-onboarding[2603]: time=2026-08-25T11:52:53.095+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:52:53 volumio volumio[2304]: info: Discovery: A device disappeared from network Aug 25 11:52:53 volumio sudo[4816]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:53 volumio sudo[4816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:53 volumio sudo[4816]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:54 volumio kernel: wlan0: disassociated from f4:f2:6d:fe:be:48 (Reason: 2=PREV_AUTH_NOT_VALID) Aug 25 11:52:54 volumio dhcpcd[1054]: wlan0: carrier lost Aug 25 11:52:54 volumio wpa_supplicant[4738]: wlan0: CTRL-EVENT-DISCONNECTED bssid=f4:f2:6d:fe:be:48 reason=2 Aug 25 11:52:54 volumio wpa_supplicant[4738]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect Aug 25 11:52:54 volumio wpa_supplicant[4738]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Hung" auth_failures=1 duration=10 reason=WRONG_KEY Aug 25 11:52:54 volumio sudo[4833]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:54 volumio sudo[4833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:54 volumio sudo[4833]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:54 volumio wireless.js[4627]: WIRELESS.JS - INFO: WpaStateMachine: State transition: 4WAY_HANDSHAKE -> SCANNING (duration: 3095ms) Aug 25 11:52:55 volumio volumio[2304]: info: Received Get System Info Aug 25 11:52:55 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:52:55 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:52:55 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:52:55 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:55 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:55 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:52:55 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:52:55 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:52:55 volumio sudo[4843]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:55 volumio sudo[4843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:55 volumio sudo[4843]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:55 volumio volumio5-onboarding[2603]: time=2026-08-25T11:52:55.902+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:52:56 volumio wpa_supplicant[4738]: wlan0: SME: Trying to authenticate with c0:25:e9:a2:bf:0c (SSID='TP-LINK_BF0C' freq=2417 MHz) Aug 25 11:52:56 volumio kernel: wlan0: authenticate with c0:25:e9:a2:bf:0c (local address=a0:af:bd:86:13:6b) Aug 25 11:52:56 volumio kernel: wlan0: send auth to c0:25:e9:a2:bf:0c (try 1/3) Aug 25 11:52:56 volumio wpa_supplicant[4738]: wlan0: Trying to associate with c0:25:e9:a2:bf:0c (SSID='TP-LINK_BF0C' freq=2417 MHz) Aug 25 11:52:56 volumio kernel: wlan0: authenticated Aug 25 11:52:56 volumio kernel: wlan0: associate with c0:25:e9:a2:bf:0c (try 1/3) Aug 25 11:52:56 volumio kernel: wlan0: RX AssocResp from c0:25:e9:a2:bf:0c (capab=0x411 status=0 aid=1) Aug 25 11:52:56 volumio kernel: wlan0: associated Aug 25 11:52:56 volumio wpa_supplicant[4738]: wlan0: Associated with c0:25:e9:a2:bf:0c Aug 25 11:52:56 volumio wpa_supplicant[4738]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 25 11:52:56 volumio wpa_supplicant[4738]: wlan0: WPA: Key negotiation completed with c0:25:e9:a2:bf:0c [PTK=CCMP GTK=CCMP] Aug 25 11:52:56 volumio wpa_supplicant[4738]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:25:e9:a2:bf:0c completed [id=4 id_str=] Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: carrier acquired Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: connected to Access Point: TP-LINK_BF0C Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: IAID bd:86:13:6b Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: soliciting a DHCP lease Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: offered 192.168.0.109 from 192.168.0.1 Aug 25 11:52:56 volumio wireless.js[4627]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> COMPLETED (duration: 1540ms) Aug 25 11:52:56 volumio wireless.js[4627]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Aug 25 11:52:56 volumio wireless.js[4627]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to c0:25:e9:a2:bf:0c Aug 25 11:52:56 volumio wireless.js[4627]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: soliciting an IPv6 router Aug 25 11:52:56 volumio volumio[2304]: info: Received Get System Info Aug 25 11:52:56 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:52:56 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:52:56 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:52:56 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:56 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:56 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:52:56 volumio sudo[4858]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:56 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:52:56 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:52:56 volumio sudo[4858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:56 volumio sudo[4858]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:56 volumio dhcpcd[1054]: wlan0: probing address 192.168.0.109/24 Aug 25 11:52:57 volumio sudo[4861]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Aug 25 11:52:57 volumio sudo[4861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:52:57 volumio sudo[4861]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:57 volumio dhcpcd[1054]: control_free: No such file or directory Aug 25 11:52:57 volumio dhcpcd[1054]: ps_ctl_dispatch: cannot handle another client Aug 25 11:52:57 volumio volumio5-onboarding[2603]: time=2026-08-25T11:52:57.545+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:52:57 volumio volumio[2304]: info: Discovery: Started advertising with name: Volumio Aug 25 11:52:57 volumio sudo[4867]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:57 volumio sudo[4867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:57 volumio sudo[4867]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:58 volumio volumio[2304]: info: Discovery: adding 3d1e162c-4b7a-4e11-a9e3-b6a0e6e63e4d Aug 25 11:52:58 volumio volumio[2304]: info: Discovery: Found device Volumio Aug 25 11:52:58 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:58 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:58 volumio volumio[2304]: info: Discovery: this is already registered, 3d1e162c-4b7a-4e11-a9e3-b6a0e6e63e4d Aug 25 11:52:58 volumio volumio[2304]: info: Discovery: Found device Volumio Aug 25 11:52:58 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:52:58 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:52:58 volumio sudo[4873]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:58 volumio sudo[4873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:58 volumio sudo[4873]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:59 volumio wireless.js[4627]: WIRELESS.JS - INFO: Start ap Aug 25 11:52:59 volumio wireless.js[4627]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 25 11:52:59 volumio systemd[1]: Started wireless.service - Wireless Services. Aug 25 11:52:59 volumio sudo[4622]: pam_unix(sudo:session): session closed for user root Aug 25 11:52:59 volumio sudo[4883]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:52:59 volumio sudo[4883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:52:59 volumio sudo[4883]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:00 volumio wireless.js[4627]: WIRELESS.JS - INFO: trying... Aug 25 11:53:00 volumio sudo[4894]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 25 11:53:00 volumio sudo[4894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:00 volumio sudo[4894]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:00 volumio sudo[4897]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:00 volumio sudo[4897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:53:00 volumio sudo[4897]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:00 volumio wireless.js[4627]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 25 11:53:00 volumio sudo[4901]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:00 volumio sudo[4901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:00 volumio sudo[4901]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:01 volumio wireless.js[4627]: WIRELESS.JS - INFO: trying... Aug 25 11:53:01 volumio sudo[4917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 25 11:53:01 volumio sudo[4917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:01 volumio sudo[4917]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:01 volumio sudo[4929]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:01 volumio sudo[4929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:53:01 volumio sudo[4929]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:01 volumio wireless.js[4627]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Aug 25 11:53:01 volumio dhcpcd[1054]: wlan0: leased 192.168.0.109 for 7200 seconds Aug 25 11:53:01 volumio dhcpcd[1054]: wlan0: adding route to 192.168.0.0/24 Aug 25 11:53:01 volumio dhcpcd[1054]: wlan0: adding default route via 192.168.0.1 Aug 25 11:53:01 volumio avahi-daemon[3585]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.109. Aug 25 11:53:01 volumio avahi-daemon[3585]: New relevant interface wlan0.IPv4 for mDNS. Aug 25 11:53:01 volumio avahi-daemon[3585]: Registering new address record for 192.168.0.109 on wlan0.IPv4. Aug 25 11:53:01 volumio sudo[4933]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:01 volumio sudo[4933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:01 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 25 11:53:01 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Aug 25 11:53:01 volumio sudo[4933]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:01 volumio systemd[1]: welcome.service: Deactivated successfully. Aug 25 11:53:01 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 25 11:53:01 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 25 11:53:01 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 25 11:53:01 volumio welcome[4942]: Resolved ip:[1] 192.168.0.109 Aug 25 11:53:01 volumio sudo[4949]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:01 volumio sudo[4949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:01 volumio sudo[4949]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:01 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 25 11:53:01 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Aug 25 11:53:02 volumio volumio[2304]: info: Received Get System Info Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Getting this device information Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:53:02 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 25 11:53:02 volumio wireless.js[4627]: WIRELESS.JS - INFO: trying... Aug 25 11:53:02 volumio sudo[4983]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 25 11:53:02 volumio sudo[4983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:02 volumio sudo[4983]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:02 volumio sudo[4986]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:02 volumio sudo[4986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:53:02 volumio sudo[4986]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:02 volumio wireless.js[4627]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.0.109, ipV6 is undefined Aug 25 11:53:02 volumio wireless.js[4627]: WIRELESS.JS - INFO: Connected to SSID: TP-LINK_BF0C Aug 25 11:53:02 volumio wireless.js[4627]: WIRELESS.JS - INFO: It's done! AP Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: this is already registered, 3d1e162c-4b7a-4e11-a9e3-b6a0e6e63e4d Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Found device Volumio Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:53:02 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: this is already registered, 3d1e162c-4b7a-4e11-a9e3-b6a0e6e63e4d Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Found device Volumio Aug 25 11:53:02 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:53:02 volumio volumio[2304]: info: CorePlayQueue::getTrack 0 Aug 25 11:53:02 volumio wireless.js[4627]: WIRELESS.JS - INFO: Restarting avahi-daemon... Aug 25 11:53:02 volumio sudo[4991]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Aug 25 11:53:02 volumio sudo[4991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 25 11:53:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 25 11:53:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 25 11:53:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 25 11:53:02 volumio systemd[1]: shairport-sync.service: Consumed 6.559s CPU time. Aug 25 11:53:02 volumio avahi-daemon[3585]: Got SIGTERM, quitting. Aug 25 11:53:02 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 25 11:53:02 volumio avahi-daemon[3585]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.109. Aug 25 11:53:02 volumio avahi-daemon[3585]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 25 11:53:02 volumio volumio5-onboarding[2603]: time=2026-08-25T11:53:02.717+07:00 level=WARN msg="disconnected from Avahi daemon, trying to reconnect" component=discovery/localnet error="avahi: Daemon connection failed" Aug 25 11:53:02 volumio avahi-daemon[3585]: avahi-daemon 0.8 exiting. Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Restarting Browsing Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Browse raised the following error Error: dns service error: unknown Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Restarting Browsing Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Restart already pending, ignoring duplicate call Aug 25 11:53:02 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Aug 25 11:53:02 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 25 11:53:02 volumio volumio[2304]: error: Discovery: Advertisement error: Error: dns service error: unknown Aug 25 11:53:02 volumio volumio[2304]: error: Discovery: advertisement error: Error: dns service error: unknown Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Advertisement raised the following error Error: dns service error: unknown Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Stopping Advertising Immediately Aug 25 11:53:02 volumio volumio[2304]: info: Discovery: Stopping existing advertisement Aug 25 11:53:02 volumio dbus-daemon[1019]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.49' (uid=0 pid=1703 comm="/usr/sbin/smbd --foreground --no-process-group") Aug 25 11:53:02 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 25 11:53:02 volumio avahi-daemon[4994]: Process 3585 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Aug 25 11:53:02 volumio avahi-daemon[4994]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Aug 25 11:53:02 volumio avahi-daemon[4994]: Successfully dropped root privileges. Aug 25 11:53:02 volumio avahi-daemon[4994]: avahi-daemon 0.8 starting up. Aug 25 11:53:02 volumio dbus-daemon[1019]: [system] Successfully activated service 'org.freedesktop.Avahi' Aug 25 11:53:02 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 25 11:53:02 volumio avahi-daemon[4994]: Successfully called chroot(). Aug 25 11:53:02 volumio avahi-daemon[4994]: Successfully dropped remaining capabilities. Aug 25 11:53:02 volumio avahi-daemon[4994]: No service file found in /etc/avahi/services. Aug 25 11:53:02 volumio avahi-daemon[4994]: *** WARNING: Detected another IPv4 mDNS stack running on this host. This makes mDNS unreliable and is thus not recommended. *** Aug 25 11:53:02 volumio avahi-daemon[4994]: *** WARNING: Detected another IPv6 mDNS stack running on this host. This makes mDNS unreliable and is thus not recommended. *** Aug 25 11:53:02 volumio avahi-daemon[4994]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.109. Aug 25 11:53:02 volumio avahi-daemon[4994]: New relevant interface wlan0.IPv4 for mDNS. Aug 25 11:53:02 volumio avahi-daemon[4994]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 25 11:53:02 volumio avahi-daemon[4994]: New relevant interface lo.IPv4 for mDNS. Aug 25 11:53:02 volumio avahi-daemon[4994]: Network interface enumeration completed. Aug 25 11:53:02 volumio avahi-daemon[4994]: Registering new address record for 192.168.0.109 on wlan0.IPv4. Aug 25 11:53:02 volumio avahi-daemon[4994]: Registering new address record for 127.0.0.1 on lo.IPv4. Aug 25 11:53:02 volumio sudo[4991]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 25 11:53:02 volumio sudo[5000]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:02 volumio sudo[5000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:02 volumio sudo[5000]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:02 volumio wireless.js[4627]: WIRELESS.JS - INFO: Notified systemd about wireless ready Aug 25 11:53:02 volumio sudo[5004]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:02 volumio sudo[5004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:02 volumio sudo[5004]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:03 volumio avahi-daemon[4994]: Server startup complete. Host name is volumio.local. Local service cookie is 3654656604. Aug 25 11:53:03 volumio ntpd[1137]: IO: Listen normally on 5 wlan0 192.168.0.109:123 Aug 25 11:53:03 volumio ntpd[1137]: IO: new interface(s) found: waking up resolver Aug 25 11:53:03 volumio ntpd[1137]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:53:03 volumio sudo[5026]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:03 volumio sudo[5026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:03 volumio sudo[5026]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:03 volumio sudo[5030]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:03 volumio sudo[5030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:03 volumio sudo[5030]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:03 volumio ntpd[1137]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Aug 25 11:53:03 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:53:03 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:53:03 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:53:03 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:53:03 volumio ntpd[1137]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Aug 25 11:53:04 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Aug 25 11:53:04 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Aug 25 11:53:04 volumio sudo[5036]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:04 volumio sudo[5036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:04 volumio sudo[5036]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:04 volumio sudo[5040]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:04 volumio sudo[5040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:04 volumio sudo[5040]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:04 volumio volumio5-onboarding[2603]: time=2026-08-25T11:53:04.648+07:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 25 11:53:04 volumio ntpd[1137]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:53:04 volumio ntpd[1137]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool taking: 115.165.161.155 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool skipping: 2001:df4:bac0::e35b:f223 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool skipping: 2400:e920:0:5::14 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool skipping: 2401:5b60:0:2::21 Aug 25 11:53:04 volumio ntpd[1137]: DNS: Pool taking: 2400:6ea0:0:509c::a Aug 25 11:53:04 volumio ntpd[1137]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Aug 25 11:53:04 volumio sudo[5048]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:04 volumio sudo[5048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:04 volumio sudo[5048]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:04 volumio sudo[5055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:04 volumio sudo[5055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:04 volumio sudo[5055]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:05 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:05 volumio volumio[2304]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::ClearQueue Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::stop Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::clearPlayQueue Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::saveQueue Aug 25 11:53:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPushQueue Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::addQueueItems Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::addQueueItems Aug 25 11:53:05 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6CTdPSNvUYw7UjerVIkUia Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6CTdPSNvUYw7UjerVIkUia Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7bFFUPBiF15n8m8RziqS4o Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7bFFUPBiF15n8m8RziqS4o Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6ELX356o21U28T73ZxruUj Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6ELX356o21U28T73ZxruUj Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:11T61UpoNbbcewOMl1kcWN Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:11T61UpoNbbcewOMl1kcWN Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4pZi0VxU2C8zuxCYfEtFuL Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4pZi0VxU2C8zuxCYfEtFuL Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4nyoalDFgUaZOzIKqj3aS5 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4nyoalDFgUaZOzIKqj3aS5 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2JZH5Rwp2WCAWzm3hXYzQf Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2JZH5Rwp2WCAWzm3hXYzQf Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7fCeYpR02Q8JVuD88hJZVT Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7fCeYpR02Q8JVuD88hJZVT Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6zwC3vsCniAGu6WpOkg6qV Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6zwC3vsCniAGu6WpOkg6qV Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6mKMGpkgP2cH5gmqILWe7b Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6mKMGpkgP2cH5gmqILWe7b Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0Gi23nmOQ0eaPASq2VoMOW Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0Gi23nmOQ0eaPASq2VoMOW Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1GvilcxzSotX6bFHuwCJiz Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1GvilcxzSotX6bFHuwCJiz Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6nInHlewtrNKguNKlXt0Ur Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6nInHlewtrNKguNKlXt0Ur Aug 25 11:53:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPushQueue Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::saveQueue Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::updateTrackBlock Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::getTrackBlock Aug 25 11:53:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPlay Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::play index 12 Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::addQueueItems Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::addQueueItems Aug 25 11:53:05 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:05kwQNmIvly0VZy3AkfMzs Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:05kwQNmIvly0VZy3AkfMzs Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2Pwou3Q2Cf59RxdX2V6MgV Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2Pwou3Q2Cf59RxdX2V6MgV Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6Zoi4ue74UdUeYmHXItXnf Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6Zoi4ue74UdUeYmHXItXnf Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:73RcFjiDtStfP3GCW44vJu Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:73RcFjiDtStfP3GCW44vJu Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4CUvVaAYuXtvYURLFz7EIL Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4CUvVaAYuXtvYURLFz7EIL Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:30EHnrqApdYTgIwKkRFNOh Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:30EHnrqApdYTgIwKkRFNOh Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5wYQC7AuxV8ROALWcbVNxc Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5wYQC7AuxV8ROALWcbVNxc Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4HjBeRYorM50d1rCrl853a Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4HjBeRYorM50d1rCrl853a Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4TmcmTzr88j02kCDh19VNt Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4TmcmTzr88j02kCDh19VNt Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:08jkdXOFyR5SDVmPAwVDhz Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:08jkdXOFyR5SDVmPAwVDhz Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1ApIGNgp1azc0qB61x4GzG Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1ApIGNgp1azc0qB61x4GzG Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7CuYlxVy87LrB2pQOP6i9z Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7CuYlxVy87LrB2pQOP6i9z Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5ss0vVhjoxD7Dvmnq30yyT Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5ss0vVhjoxD7Dvmnq30yyT Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0pSTK0qekDyWdGvbDuuCfC Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0pSTK0qekDyWdGvbDuuCfC Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0Pmhn5IxN2ovBy9rYkguKS Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0Pmhn5IxN2ovBy9rYkguKS Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:55Eo6NDkVhSRBonrT16kXM Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:55Eo6NDkVhSRBonrT16kXM Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2e6uyFP80Vuaz7V7bDWD0e Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2e6uyFP80Vuaz7V7bDWD0e Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7aBUKC55ymgBw7M5gdppte Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7aBUKC55ymgBw7M5gdppte Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4QalnBNnw9uK1dj543nf76 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4QalnBNnw9uK1dj543nf76 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6u3he5hPpYDoNNacBUR7vX Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6u3he5hPpYDoNNacBUR7vX Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3T7XHOdRcyhKU3QCB6kZG3 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3T7XHOdRcyhKU3QCB6kZG3 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7roD87qxMavNuGydYSRtI2 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7roD87qxMavNuGydYSRtI2 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6GM4ZOBDcDroldUxI8GZ2B Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6GM4ZOBDcDroldUxI8GZ2B Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5XfGQZA0ioQAWUjlyJRcHc Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5XfGQZA0ioQAWUjlyJRcHc Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4ZIwFLm8C7MUe7JR1G9CGa Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4ZIwFLm8C7MUe7JR1G9CGa Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5GH5F5HsKGirC3qKwW0wEN Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5GH5F5HsKGirC3qKwW0wEN Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4MCP9l0QB9YN2LCkIy8mz4 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4MCP9l0QB9YN2LCkIy8mz4 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:08ULi904W2Po6pVj8nN7KC Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:08ULi904W2Po6pVj8nN7KC Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3y66li7DIrH7HLKIZzxR5H Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3y66li7DIrH7HLKIZzxR5H Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6PJ4rafx2ufoaPaTewsRfh Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6PJ4rafx2ufoaPaTewsRfh Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3Ids3RXurYBgySph53qWnB Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3Ids3RXurYBgySph53qWnB Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6Qwl74olNi1rl65FNxG5We Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6Qwl74olNi1rl65FNxG5We Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5u5AsK8JLgkr154QHZjJqh Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5u5AsK8JLgkr154QHZjJqh Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1xoadYaxtOp9gHDwgmPDuz Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1xoadYaxtOp9gHDwgmPDuz Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3UJ2gSPFPSkPKZghRI8y1e Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3UJ2gSPFPSkPKZghRI8y1e Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6f7M5UzYYeLFCMIBQhxk2J Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6f7M5UzYYeLFCMIBQhxk2J Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0OB5hTu7ELKeVoD6JVRo6m Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0OB5hTu7ELKeVoD6JVRo6m Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7zJ6yuuOnjjRqbKv1zfCAl Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7zJ6yuuOnjjRqbKv1zfCAl Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0e6fZkLArSmDIHnZcIua7t Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0e6fZkLArSmDIHnZcIua7t Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0CY9y1F7RcRSV3raHljdxu Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0CY9y1F7RcRSV3raHljdxu Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0r2JVOjI7H1jhXzXBOorKu Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0r2JVOjI7H1jhXzXBOorKu Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:63gCdrDtZlt1PMIGrzYEqt Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:63gCdrDtZlt1PMIGrzYEqt Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5KYv3kORBKUmVEoqbRRWxt Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5KYv3kORBKUmVEoqbRRWxt Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4CVxKSRLUxqUuj2z9vn4fS Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4CVxKSRLUxqUuj2z9vn4fS Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3gLRyMbg5nWLcuKD46Uz72 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3gLRyMbg5nWLcuKD46Uz72 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:498g7npirihKT5MPdVSfb0 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:498g7npirihKT5MPdVSfb0 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3DLtPObflLQBodZN8qGODT Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3DLtPObflLQBodZN8qGODT Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5bOh5gwwjMQfMwgusZS78M Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5bOh5gwwjMQfMwgusZS78M Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1J12HjUuXfJnaUdubTEzSR Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1J12HjUuXfJnaUdubTEzSR Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1r9gNSD1WUFscqTSA2Rcet Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1r9gNSD1WUFscqTSA2Rcet Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:36fgG6NiEuQXznNgf5y2Ck Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:36fgG6NiEuQXznNgf5y2Ck Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1DVYafsLmcQySKkJnY4RCs Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1DVYafsLmcQySKkJnY4RCs Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4VjLWbQhf8KUPMeuBO5H55 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4VjLWbQhf8KUPMeuBO5H55 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:31VNCmwspR7nVJ6kruUuJt Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:31VNCmwspR7nVJ6kruUuJt Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6TGwaBlfUGVoeZMBLzvXGP Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6TGwaBlfUGVoeZMBLzvXGP Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4BdB08vuS9r4HOoY7GkAxT Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4BdB08vuS9r4HOoY7GkAxT Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2a5hng9yXtbjtTVVm9UviC Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2a5hng9yXtbjtTVVm9UviC Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:06Jxxbxy5xMPI2M74t7xBa Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:06Jxxbxy5xMPI2M74t7xBa Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:1ordU9Ts6JNRalwVoXgJd6 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:1ordU9Ts6JNRalwVoXgJd6 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0GXZXSDFSbJjqdGifjSaig Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0GXZXSDFSbJjqdGifjSaig Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2qrpmvkxE0oz78ym1LEvXd Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2qrpmvkxE0oz78ym1LEvXd Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5oFEvbM7lGnx8jfAkuhVyo Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5oFEvbM7lGnx8jfAkuhVyo Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5kJMW3pK49PvQDtpVryHf5 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5kJMW3pK49PvQDtpVryHf5 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2Uw9vhm7aQKXFFsiu3Zw5f Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2Uw9vhm7aQKXFFsiu3Zw5f Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:40pWxpbXoBYGPCiofujjZ6 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:40pWxpbXoBYGPCiofujjZ6 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3ZbZtdEw9U0uZW4tZItIwq Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3ZbZtdEw9U0uZW4tZItIwq Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0kHgteR4TV4LO80wrasDSR Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0kHgteR4TV4LO80wrasDSR Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:44XA6tVReCIX8T1c3l9f75 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:44XA6tVReCIX8T1c3l9f75 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2z2Ji5HoUkiA4mxq5DOyTo Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2z2Ji5HoUkiA4mxq5DOyTo Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3HQbZvnDpBxdAjLf0UyG9E Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3HQbZvnDpBxdAjLf0UyG9E Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0s7RyyUlQfd8mnnboHe18n Aug 25 11:53:05 volumio ntpd[1137]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0s7RyyUlQfd8mnnboHe18n Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:66v7AvDs5gZfmkJgFMMtHL Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:66v7AvDs5gZfmkJgFMMtHL Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2ZBi1KpCR0grEWRNgySqwg Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2ZBi1KpCR0grEWRNgySqwg Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0wvpRHXXuImyrccNEPAXBo Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0wvpRHXXuImyrccNEPAXBo Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:7uUuftbcr94tzGOCJSM25u Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:7uUuftbcr94tzGOCJSM25u Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:317Lh6QCAz9JpWbV3oxrCf Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:317Lh6QCAz9JpWbV3oxrCf Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:2KadxdRVKWJy3ahMnlClhq Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:2KadxdRVKWJy3ahMnlClhq Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:3WtsdBj3zUIYGPcMHksbYV Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:3WtsdBj3zUIYGPcMHksbYV Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0t8g66pWghsU8MphjUQIdg Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0t8g66pWghsU8MphjUQIdg Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:4D1eaEIisnWCVPMnYuMh7q Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:4D1eaEIisnWCVPMnYuMh7q Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:05kwQNmIvly0VZy3AkfMzs Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:05kwQNmIvly0VZy3AkfMzs Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:5r6Rae4kq7CikBuoTaj6RF Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:5r6Rae4kq7CikBuoTaj6RF Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0JF65tQ1nQxBHFzs5IVn8o Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0JF65tQ1nQxBHFzs5IVn8o Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:0a32EBPjqAe47cYDPE5Ia5 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:0a32EBPjqAe47cYDPE5Ia5 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:6UO9nrihAk6sFGvVHDVTz8 Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:6UO9nrihAk6sFGvVHDVTz8 Aug 25 11:53:05 volumio volumio[2304]: info: Adding Item to queue: spotify:track:658p8QigkkePSvSm36MjtS Aug 25 11:53:05 volumio volumio[2304]: info: Using cached record of: spotify:track:658p8QigkkePSvSm36MjtS Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::stop Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 11:53:05 volumio volumio[2304]: info: CoreCommandRouter::volumioPushQueue Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::saveQueue Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::play index undefined Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::updateTrackBlock Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::getTrackBlock Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 12 Aug 25 11:53:05 volumio volumio[2304]: info: CoreStateMachine::startPlaybackTimer Aug 25 11:53:05 volumio volumio[2304]: info: CorePlayQueue::getTrack 12 Aug 25 11:53:05 volumio volumio[2304]: info: [1787633585745] ControllerSpotify::clearAddPlayTrack Aug 25 11:53:05 volumio volumio[2304]: info: Sending Spotify command with payload to local API: /player/play Aug 25 11:53:05 volumio ntpd[1137]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Aug 25 11:53:05 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:53:05 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:53:05 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:53:05 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:53:05 volumio ntpd[1137]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Aug 25 11:53:05 volumio sudo[5064]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:05 volumio sudo[5064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:05 volumio sudo[5064]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:05 volumio sudo[5068]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:05 volumio sudo[5068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:05 volumio sudo[5068]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:06 volumio ntpd[1137]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Aug 25 11:53:06 volumio sudo[5076]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:06 volumio sudo[5076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:06 volumio sudo[5076]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:06 volumio sudo[5080]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:06 volumio sudo[5080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:06 volumio sudo[5080]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:07 volumio ntpd[1137]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Aug 25 11:53:07 volumio ntpd[1137]: DNS: Pool skipping: 45.252.250.189 Aug 25 11:53:07 volumio ntpd[1137]: DNS: Pool skipping: 103.221.223.143 Aug 25 11:53:07 volumio ntpd[1137]: DNS: Pool skipping: 103.186.65.246 Aug 25 11:53:07 volumio ntpd[1137]: DNS: Pool skipping: 160.22.74.161 Aug 25 11:53:07 volumio ntpd[1137]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Aug 25 11:53:07 volumio volumio[2304]: info: Discovery: Restarting Advertising Aug 25 11:53:07 volumio sudo[5088]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:07 volumio sudo[5088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:07 volumio sudo[5088]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:07 volumio sudo[5092]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:07 volumio sudo[5092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:07 volumio sudo[5092]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:08 volumio sudo[5100]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:08 volumio sudo[5100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:08 volumio sudo[5100]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:08 volumio sudo[5104]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:08 volumio sudo[5104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:08 volumio sudo[5104]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:09 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Aug 25 11:53:09 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Aug 25 11:53:09 volumio volumio[2304]: info: Refreshing Cached IP Addresses Aug 25 11:53:09 volumio sudo[5110]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Aug 25 11:53:09 volumio sudo[5110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:09 volumio sudo[5112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 11:53:09 volumio sudo[5112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:09 volumio sudo[5115]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:09 volumio sudo[5115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:09 volumio sudo[5110]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:09 volumio sudo[5115]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:09 volumio systemd[1]: upmpdcli.service: Deactivated successfully. Aug 25 11:53:09 volumio sudo[5112]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:09 volumio sudo[5123]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:09 volumio sudo[5123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:09 volumio sudo[5123]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:09 volumio sudo[5127]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:09 volumio sudo[5127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:09 volumio sudo[5127]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:10 volumio sudo[5134]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:10 volumio sudo[5134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:10 volumio sudo[5134]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:10 volumio sudo[5138]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:10 volumio sudo[5138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:10 volumio sudo[5138]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:11 volumio volumio[2304]: info: Volumio Network Manager: Network status updated: 2 Aug 25 11:53:11 volumio sudo[5159]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:11 volumio sudo[5159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:11 volumio sudo[5159]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:11 volumio sudo[5163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:11 volumio sudo[5163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:11 volumio sudo[5163]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:12 volumio volumio[2304]: info: Discovery: Started advertising with name: Volumio Aug 25 11:53:12 volumio sudo[5171]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:12 volumio sudo[5171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:12 volumio sudo[5171]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:12 volumio sudo[5175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Aug 25 11:53:12 volumio sudo[5175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:12 volumio sudo[5175]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:13 volumio volumio[2304]: info: Discovery: this is already registered, 3d1e162c-4b7a-4e11-a9e3-b6a0e6e63e4d Aug 25 11:53:13 volumio volumio[2304]: info: Discovery: Found device Volumio Aug 25 11:53:13 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:53:13 volumio volumio[2304]: info: CorePlayQueue::getTrack 12 Aug 25 11:53:13 volumio volumio[2304]: info: Discovery: this is already registered, 3d1e162c-4b7a-4e11-a9e3-b6a0e6e63e4d Aug 25 11:53:13 volumio volumio[2304]: info: Discovery: Found device Volumio Aug 25 11:53:13 volumio volumio[2304]: info: CoreCommandRouter::volumioGetState Aug 25 11:53:13 volumio volumio[2304]: info: CorePlayQueue::getTrack 12 Aug 25 11:53:14 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 25 11:53:14 volumio volumio[2304]: info: In handleBrowseUri, curUri=spotify Aug 25 11:53:14 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:14 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:14 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:14 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:16 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 25 11:53:16 volumio volumio[2304]: info: In handleBrowseUri, curUri=spotify/playlists Aug 25 11:53:17 volumio volumio[2304]: info: Preload queue cleared Aug 25 11:53:19 volumio sudo[5189]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 25 11:53:19 volumio sudo[5189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:19 volumio sudo[5191]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 25 11:53:19 volumio sudo[5191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:19 volumio sudo[5191]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:19 volumio sudo[5189]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:19 volumio sudo[5196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 25 11:53:19 volumio sudo[5196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 25 11:53:24 volumio volumio[2304]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 25 11:53:24 volumio volumio[2304]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:43VBTnEG6KkSdLCKGcNZhB Aug 25 11:53:24 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Aug 25 11:53:24 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 25 11:53:24 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 25 11:53:24 volumio sudo[5196]: pam_unix(sudo:session): session closed for user root Aug 25 11:53:24 volumio volumio[2304]: info: Upmpdcli Daemon Started Aug 25 11:53:24 volumio upmpdcli[5232]: writing RSA key Aug 25 11:53:25 volumio volumio[2304]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 11:53:25 volumio volumio[2304]: TypeError: Cannot read properties of null (reading '0') Aug 25 11:53:25 volumio volumio[2304]: at /data/plugins/music_service/spop/index.js:2504:56 Aug 25 11:53:25 volumio volumio[2304]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Aug 25 11:53:25 volumio volumio[2304]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 11:53:25 volumio sudo[5254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-25 11:52' Aug 25 11:53:25 volumio sudo[5254]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"