-- Logs begin at Fri 2025-02-28 07:47:54 CST, end at Fri 2025-02-28 22:02:57 CST. -- Feb 28 22:01:00 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::ClearQueue Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::clearPlayQueue Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::addQueueItems Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::addQueueItems Feb 28 22:01:00 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:01:00 volumio volumio[28791]: info: Adding Item to queue: music-library/INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:00 volumio volumio[28791]: info: Using cached record of: music-library/INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::volumioPlay Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::play index 0 Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::play index undefined Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::startPlaybackTimer Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:01:00 volumio volumio[28791]: info: Feb 28 22:01:00 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand stop took 1 milliseconds Feb 28 22:01:00 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand clear Feb 28 22:01:00 volumio volumio[28791]: info: Feb 28 22:01:00 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:01:00 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand status took 1 milliseconds Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand clear took 1 milliseconds Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/1/天亮以前说再见-何野.mp3" Feb 28 22:01:00 volumio volumio[28791]: error: updateQueue error: null Feb 28 22:01:00 volumio volumio[28791]: info: Feb 28 22:01:00 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:01:00 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:01:00 volumio volumio[28791]: info: ------------------------------ 0ms Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand add "INTERNAL/1/天亮以前说再见-何野.mp3" took 0 milliseconds Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand play Feb 28 22:01:00 volumio volumio[28791]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 28 22:01:00 volumio volumio[28791]: info: ------------------------------ 2ms Feb 28 22:01:00 volumio volumio[28791]: info: ------------------------------ 1ms Feb 28 22:01:00 volumio volumio[28791]: info: Feb 28 22:01:00 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand play took 6 milliseconds Feb 28 22:01:00 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:00 volumio volumio[28791]: info: Feb 28 22:01:00 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand status took 2 milliseconds Feb 28 22:01:00 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand status took 0 milliseconds Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:00 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:00 volumio volumio[28791]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:00 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::syncState stateService play Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus stop Feb 28 22:01:00 volumio volumio[28791]: info: ------------------------------ 4ms Feb 28 22:01:00 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 28 22:01:00 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:00 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:00 volumio volumio[28791]: verbose: STATE SERVICE {"status":"play","position":0,"seek":853,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:00 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::syncState stateService play Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus play Feb 28 22:01:00 volumio volumio[28791]: info: Received an update from plugin. extracting info from payload Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:00 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:00 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:00 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:00 volumio volumio[28791]: info: ------------------------------ 4ms Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stPlaybackTimer Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::serviceStop Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::serviceStop Feb 28 22:01:17 volumio volumio[28791]: info: ControllerMpd::stop Feb 28 22:01:17 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: Airplay started streaming, receiving metadatas Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio shairport-sync[31188]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 28 22:01:17 volumio shairport-sync[31188]: Dload Upload Total Spent Left Speed Feb 28 22:01:17 volumio volumio[28791]: info: Feb 28 22:01:17 volumio volumio[28791]: ---------------------------- Client requests Start Airplay PlaybackRoutine Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Feb 28 22:01:17 volumio volumio[28791]: info: Airplay playback start Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioStop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:17 volumio shairport-sync[31188]: [158B blob data] Feb 28 22:01:17 volumio volumio[28791]: info: Feb 28 22:01:17 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:17 volumio volumio[28791]: info: sendMpdCommand stop took 21 milliseconds Feb 28 22:01:17 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:17 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:17 volumio volumio[28791]: info: sendMpdCommand status took 1 milliseconds Feb 28 22:01:17 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:17 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:17 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 28 22:01:17 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:17 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:17 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::syncState stateService stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus stop Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:17 volumio volumio[28791]: info: No code Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:17 volumio volumio[28791]: info: ------------------------------ 5ms Feb 28 22:01:17 volumio volumio[28791]: info: Updating volume from AirPlay: -20; 33% Feb 28 22:01:17 volumio volumio[28791]: info: VolumeController::SetAlsaVolume33 Feb 28 22:01:17 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:17 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:17 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:18 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:19 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:22 volumio volumio[28791]: info: Updating volume from AirPlay: -16.47; 45% Feb 28 22:01:22 volumio volumio[28791]: info: VolumeController::SetAlsaVolume45 Feb 28 22:01:22 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:22 volumio volumio[28791]: info: Updating volume from AirPlay: -14.8; 51% Feb 28 22:01:22 volumio volumio[28791]: info: VolumeController::SetAlsaVolume51 Feb 28 22:01:22 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:22 volumio volumio[28791]: info: Updating volume from AirPlay: -14.41; 52% Feb 28 22:01:22 volumio volumio[28791]: info: VolumeController::SetAlsaVolume52 Feb 28 22:01:22 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:22 volumio volumio[28791]: info: Updating volume from AirPlay: -12.06; 60% Feb 28 22:01:22 volumio volumio[28791]: info: VolumeController::SetAlsaVolume60 Feb 28 22:01:22 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:22 volumio volumio[28791]: info: Updating volume from AirPlay: -11.57; 61% Feb 28 22:01:22 volumio volumio[28791]: info: VolumeController::SetAlsaVolume61 Feb 28 22:01:22 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:22 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:23 volumio volumio[28791]: info: Updating volume from AirPlay: -9.71; 68% Feb 28 22:01:23 volumio volumio[28791]: info: VolumeController::SetAlsaVolume68 Feb 28 22:01:23 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:23 volumio volumio[28791]: info: Updating volume from AirPlay: -4.9; 84% Feb 28 22:01:23 volumio volumio[28791]: info: VolumeController::SetAlsaVolume84 Feb 28 22:01:23 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:23 volumio volumio[28791]: info: Updating volume from AirPlay: -3.63; 88% Feb 28 22:01:23 volumio volumio[28791]: info: VolumeController::SetAlsaVolume88 Feb 28 22:01:23 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:23 volumio volumio[28791]: info: Updating volume from AirPlay: 0; 100% Feb 28 22:01:23 volumio volumio[28791]: info: VolumeController::SetAlsaVolume100 Feb 28 22:01:23 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:23 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:26 volumio volumio[28791]: info: Updating volume from AirPlay: -5; 83% Feb 28 22:01:26 volumio volumio[28791]: info: VolumeController::SetAlsaVolume83 Feb 28 22:01:26 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:26 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:26 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:27 volumio volumio[28791]: info: Updating volume from AirPlay: -5.39; 82% Feb 28 22:01:27 volumio volumio[28791]: info: VolumeController::SetAlsaVolume82 Feb 28 22:01:27 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:27 volumio volumio[28791]: info: Updating volume from AirPlay: -5.88; 80% Feb 28 22:01:27 volumio volumio[28791]: info: VolumeController::SetAlsaVolume80 Feb 28 22:01:27 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:27 volumio volumio[28791]: info: Updating volume from AirPlay: -6.86; 77% Feb 28 22:01:27 volumio volumio[28791]: info: VolumeController::SetAlsaVolume77 Feb 28 22:01:27 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:27 volumio volumio[28791]: info: Updating volume from AirPlay: -7.21; 76% Feb 28 22:01:27 volumio volumio[28791]: info: VolumeController::SetAlsaVolume76 Feb 28 22:01:27 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:27 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:32 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:35 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::ClearQueue Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::serviceStop Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::serviceStop Feb 28 22:01:35 volumio volumio[28791]: info: Airplay Stop Feb 28 22:01:35 volumio volumio[28791]: info: Stopping Airplay Playback and sending pause command to client via USR2 Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::clearPlayQueue Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::addQueueItems Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::addQueueItems Feb 28 22:01:35 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:01:35 volumio volumio[28791]: info: Adding Item to queue: music-library/INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:35 volumio volumio[28791]: info: Using cached record of: music-library/INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioPlay Feb 28 22:01:35 volumio volumio[28791]: verbose: UNSET VOLATILE: Service: airplay_emulation Feb 28 22:01:35 volumio volumio[28791]: info: Stopping Airplay Playback and sending pause command to client via USR2 Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::play index 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::stPlaybackTimer Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::serviceStop Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::serviceStop Feb 28 22:01:35 volumio volumio[28791]: info: ControllerMpd::stop Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:01:35 volumio sudo[31283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 31188 Feb 28 22:01:35 volumio sudo[31283]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand stop took 2 milliseconds Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::play index undefined Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::startPlaybackTimer Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:01:35 volumio sudo[31283]: pam_unix(sudo:session): session closed for user root Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand stop took 1 milliseconds Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand clear Feb 28 22:01:35 volumio volumio[28791]: info: Feb 28 22:01:35 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:01:35 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand clear took 1 milliseconds Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/1/天亮以前说再见-何野.mp3" Feb 28 22:01:35 volumio volumio[28791]: info: Shairport-Sync paused with USR2 Feb 28 22:01:35 volumio volumio[28791]: error: updateQueue error: null Feb 28 22:01:35 volumio volumio[28791]: info: Feb 28 22:01:35 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:01:35 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:01:35 volumio volumio[28791]: info: ------------------------------ 1ms Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand add "INTERNAL/1/天亮以前说再见-何野.mp3" took 1 milliseconds Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand play Feb 28 22:01:35 volumio volumio[28791]: info: ------------------------------ 1ms Feb 28 22:01:35 volumio volumio[28791]: info: Feb 28 22:01:35 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:35 volumio sudo[31286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 31188 Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand play took 2 milliseconds Feb 28 22:01:35 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:35 volumio sudo[31286]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:01:35 volumio volumio[28791]: info: Feb 28 22:01:35 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand status took 2 milliseconds Feb 28 22:01:35 volumio sudo[31286]: pam_unix(sudo:session): session closed for user root Feb 28 22:01:35 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand clearerror took 3 milliseconds Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand status took 1 milliseconds Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:35 volumio volumio[28791]: info: Shairport-Sync paused with USR2 Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 28 22:01:35 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:35 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:35 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:35 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::syncState stateService pause Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus stop Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:35 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:35 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::syncState stateService pause Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus stop Feb 28 22:01:35 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:35 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:35 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:35 volumio volumio[28791]: info: ------------------------------ 16ms Feb 28 22:01:35 volumio volumio[28791]: info: ------------------------------ 15ms Feb 28 22:01:36 volumio volumio[28791]: info: Restarting Shairport-Sync after stop Feb 28 22:01:36 volumio volumio[28791]: info: Restarting Shairport-Sync after stop Feb 28 22:01:36 volumio sudo[31289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 28 22:01:36 volumio sudo[31289]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:01:36 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 28 22:01:36 volumio shairport-sync[31188]: {"time":1740751277585,"response":"startAirplayPlayback Success"} Feb 28 22:01:36 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 28 22:01:36 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 28 22:01:36 volumio sudo[31292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 28 22:01:36 volumio sudo[31292]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:01:36 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 28 22:01:36 volumio sudo[31289]: pam_unix(sudo:session): session closed for user root Feb 28 22:01:36 volumio volumio[28791]: info: Shairport-Sync retarted Feb 28 22:01:36 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 28 22:01:36 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 28 22:01:36 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 28 22:01:36 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 28 22:01:36 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 28 22:01:36 volumio sudo[31292]: pam_unix(sudo:session): session closed for user root Feb 28 22:01:36 volumio volumio[28791]: info: Shairport-Sync retarted Feb 28 22:01:41 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::ClearQueue Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::clearPlayQueue Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::addQueueItems Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::addQueueItems Feb 28 22:01:41 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:01:41 volumio volumio[28791]: info: Adding Item to queue: music-library/INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:41 volumio volumio[28791]: info: Using cached record of: music-library/INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::volumioPlay Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::play index 0 Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::play index undefined Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::startPlaybackTimer Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/1/天亮以前说再见-何野.mp3 Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:01:41 volumio volumio[28791]: info: Feb 28 22:01:41 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand stop took 2 milliseconds Feb 28 22:01:41 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand clear Feb 28 22:01:41 volumio volumio[28791]: info: Feb 28 22:01:41 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:01:41 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand status took 0 milliseconds Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand clear took 0 milliseconds Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/1/天亮以前说再见-何野.mp3" Feb 28 22:01:41 volumio volumio[28791]: error: updateQueue error: null Feb 28 22:01:41 volumio volumio[28791]: info: Feb 28 22:01:41 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:01:41 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:01:41 volumio volumio[28791]: info: ------------------------------ 1ms Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand add "INTERNAL/1/天亮以前说再见-何野.mp3" took 1 milliseconds Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand play Feb 28 22:01:41 volumio volumio[28791]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 28 22:01:41 volumio volumio[28791]: info: ------------------------------ 2ms Feb 28 22:01:41 volumio volumio[28791]: info: ------------------------------ 1ms Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand play took 0 milliseconds Feb 28 22:01:41 volumio volumio[28791]: info: Feb 28 22:01:41 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:41 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:41 volumio volumio[28791]: info: Feb 28 22:01:41 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand status took 2 milliseconds Feb 28 22:01:41 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand status took 0 milliseconds Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:41 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:41 volumio volumio[28791]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:41 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::syncState stateService play Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus stop Feb 28 22:01:41 volumio volumio[28791]: info: ------------------------------ 3ms Feb 28 22:01:41 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 28 22:01:41 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:01:41 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:41 volumio volumio[28791]: verbose: STATE SERVICE {"status":"play","position":0,"seek":853,"duration":240,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"天亮以前说再见","artist":"何野","album":"天亮以前说再见","uri":"INTERNAL/1/天亮以前说再见-何野.mp3","trackType":"mp3"} Feb 28 22:01:41 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::syncState stateService play Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus play Feb 28 22:01:41 volumio volumio[28791]: info: Received an update from plugin. extracting info from payload Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:41 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:41 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:41 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:41 volumio volumio[28791]: info: ------------------------------ 5ms Feb 28 22:01:53 volumio volumio[28791]: info: CoreCommandRouter::volumioGetState Feb 28 22:01:53 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:58 volumio volumio[28791]: info: VolumeController::SetAlsaVolume0 Feb 28 22:01:58 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:58 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:58 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:58 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:01:59 volumio volumio[28791]: info: VolumeController::SetAlsaVolume67 Feb 28 22:01:59 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:01:59 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:01:59 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:01:59 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:02 volumio volumio[28791]: info: VolumeController::SetAlsaVolume94 Feb 28 22:02:02 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:02 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:02 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:02 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:02 volumio volumio[28791]: info: VolumeController::SetAlsaVolume100 Feb 28 22:02:02 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:02 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:02 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:02 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:04 volumio volumio[28791]: info: VolumeController::SetAlsaVolume74 Feb 28 22:02:04 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:04 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:04 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:04 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:05 volumio volumio[28791]: info: VolumeController::SetAlsaVolume42 Feb 28 22:02:05 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:05 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:05 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:05 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:06 volumio volumio[28791]: info: VolumeController::SetAlsaVolume29 Feb 28 22:02:06 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:06 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:06 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:06 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:08 volumio volumio[28791]: info: VolumeController::SetAlsaVolume100 Feb 28 22:02:08 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:08 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:08 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:08 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 28 22:02:13 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 28 22:02:21 volumio volumio[28791]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::volumioGetState Feb 28 22:02:21 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Feb 28 22:02:21 volumio sudo[31437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 28 22:02:21 volumio sudo[31437]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:02:21 volumio volumio[28791]: info: Restoring Previous Volume level: 100 false true Feb 28 22:02:21 volumio volumio[28791]: info: VolumeController::SetAlsaVolume100 Feb 28 22:02:21 volumio sudo[31437]: pam_unix(sudo:session): session closed for user root Feb 28 22:02:21 volumio sudo[31441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 28 22:02:21 volumio sudo[31441]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:02:21 volumio volumio[28791]: info: Volume configurations have been set Feb 28 22:02:21 volumio systemd[1]: Stopping Music Player Daemon... Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 28 22:02:21 volumio volumio[28791]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 28 22:02:21 volumio volumio[28791]: info: Disabling external Volume Control Feb 28 22:02:21 volumio systemd[1]: mpd.service: Succeeded. Feb 28 22:02:21 volumio systemd[1]: Stopped Music Player Daemon. Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:21 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:21 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:21 volumio volumio[28791]: info: MPD Permissions set Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 28 22:02:21 volumio systemd[1]: Starting Music Player Daemon... Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 28 22:02:21 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:21 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:21 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:21 volumio sudo[31448]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 28 22:02:21 volumio sudo[31448]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 28 22:02:21 volumio sudo[31448]: pam_unix(sudo:session): session closed for user root Feb 28 22:02:21 volumio mpd[31465]: Feb 28 22:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 28 22:02:21 volumio systemd[1]: Started Music Player Daemon. Feb 28 22:02:21 volumio sudo[31441]: pam_unix(sudo:session): session closed for user root Feb 28 22:02:21 volumio volumio[28791]: error: updateQueue error: null Feb 28 22:02:25 volumio volumio[28791]: info: VolumeController::SetAlsaVolume100 Feb 28 22:02:25 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:25 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:25 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:25 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:29 volumio volumio[28791]: info: CoreCommandRouter::volumioPause Feb 28 22:02:29 volumio volumio[28791]: info: CoreStateMachine::pause Feb 28 22:02:29 volumio volumio[28791]: info: CoreStateMachine::stPlaybackTimer Feb 28 22:02:29 volumio volumio[28791]: info: CoreStateMachine::servicePause Feb 28 22:02:29 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:29 volumio volumio[28791]: info: CoreCommandRouter::servicePause Feb 28 22:02:29 volumio volumio[28791]: info: ControllerMpd::pause Feb 28 22:02:29 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand pause Feb 28 22:02:29 volumio volumio[28791]: info: sendMpdCommand pause took 0 milliseconds Feb 28 22:02:30 volumio volumio[28791]: info: CoreCommandRouter::volumioPause Feb 28 22:02:30 volumio volumio[28791]: info: CoreStateMachine::pause Feb 28 22:02:33 volumio volumio[28791]: info: CoreCommandRouter::volumioGetState Feb 28 22:02:33 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:34 volumio volumio[28791]: info: CoreCommandRouter::volumioPlay Feb 28 22:02:34 volumio volumio[28791]: info: CoreStateMachine::play index undefined Feb 28 22:02:34 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:02:34 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:34 volumio volumio[28791]: info: CoreStateMachine::startPlaybackTimer Feb 28 22:02:34 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:34 volumio volumio[28791]: info: ControllerMpd::resume Feb 28 22:02:34 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand play Feb 28 22:02:34 volumio volumio[28791]: info: sendMpdCommand play took 0 milliseconds Feb 28 22:02:36 volumio volumio[28791]: info: CoreCommandRouter::volumioPlay Feb 28 22:02:36 volumio volumio[28791]: info: CoreStateMachine::play index undefined Feb 28 22:02:36 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:02:36 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:36 volumio volumio[28791]: info: CoreStateMachine::startPlaybackTimer Feb 28 22:02:36 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:36 volumio volumio[28791]: info: ControllerMpd::resume Feb 28 22:02:36 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand play Feb 28 22:02:36 volumio volumio[28791]: info: sendMpdCommand play took 1 milliseconds Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:38 volumio volumio[28791]: info: Retrieving Cloud Streaming UI Feb 28 22:02:38 volumio volumio[28791]: info: Getting Tidal Cloud Configuration Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:38 volumio volumio[28791]: info: Getting Qobuz Cloud Configuration Feb 28 22:02:38 volumio volumio[28791]: info: Asking plugin for UI Config Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:38 volumio volumio[28791]: info: Getting Spotify Cloud Configuration Feb 28 22:02:38 volumio volumio[28791]: info: Asking plugin for UI Config Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:38 volumio volumio[28791]: info: Saving Spotify Acccount Feb 28 22:02:38 volumio volumio[28791]: info: Got Tidal Cloud Configuration Feb 28 22:02:38 volumio volumio[28791]: info: Got it Feb 28 22:02:38 volumio volumio[28791]: info: Got it Feb 28 22:02:38 volumio volumio[28791]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 28 22:02:38 volumio volumio[28791]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::volumioGetBrowseSources Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::volumioGetBrowseSources Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::volumioGetBrowseSources Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 28 22:02:38 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 28 22:02:42 volumio volumio[28791]: info: CoreCommandRouter::volumioGetState Feb 28 22:02:42 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:46 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 28 22:02:46 volumio volumio[28791]: info: CURURI: artists:// Feb 28 22:02:46 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:02:48 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 28 22:02:48 volumio volumio[28791]: info: CURURI: artists://S.H.E Feb 28 22:02:48 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:02:48 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:02:48 volumio volumio[28791]: info: Preloading song: music-library/INTERNAL/1/一眼万年-S.H.E.mp3 Feb 28 22:02:48 volumio volumio[28791]: info: Exploding uri music-library/INTERNAL/1/一眼万年-S.H.E.mp3 in service mpd Feb 28 22:02:48 volumio volumio[28791]: info: ALBUMART /albumart?cacheid=933&web=S.H.E/Forever%20%E6%96%B0%E6%AD%8C%2B%E7%B2%BE%E9%80%89/extralarge&path=%2Fmnt%2FINTERNAL%2F1%2F%E4%B8%80%E7%9C%BC%E4%B8%87%E5%B9%B4-S.H.E.mp3&metadata=false Feb 28 22:02:48 volumio volumio[28791]: info: URI /mnt/INTERNAL/1/一眼万年-S.H.E.mp3 Feb 28 22:02:52 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::ClearQueue Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::stPlaybackTimer Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::serviceStop Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::serviceStop Feb 28 22:02:52 volumio volumio[28791]: info: ControllerMpd::stop Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::clearPlayQueue Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::addQueueItems Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::addQueueItems Feb 28 22:02:52 volumio volumio[28791]: info: Preload queue cleared Feb 28 22:02:52 volumio volumio[28791]: info: Adding Item to queue: artists://S.H.E/Forever%20%E6%96%B0%E6%AD%8C%2B%E7%B2%BE%E9%80%89 Feb 28 22:02:52 volumio volumio[28791]: info: Exploding uri artists://S.H.E/Forever%20%E6%96%B0%E6%AD%8C%2B%E7%B2%BE%E9%80%89 in service mpd Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand stop took 3 milliseconds Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioPushQueue Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::saveQueue Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::updateTrackBlock Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrackBlock Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioPlay Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::play index 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::stop Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::play index undefined Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::startPlaybackTimer Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/1/一眼万年-S.H.E.mp3 Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand stop took 0 milliseconds Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand clear Feb 28 22:02:52 volumio volumio[28791]: info: Feb 28 22:02:52 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:02:52 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand clear took 1 milliseconds Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/1/一眼万年-S.H.E.mp3" Feb 28 22:02:52 volumio volumio[28791]: error: updateQueue error: null Feb 28 22:02:52 volumio volumio[28791]: info: Feb 28 22:02:52 volumio volumio[28791]: ---------------------------- MPD announces system playlist update Feb 28 22:02:52 volumio volumio[28791]: info: Ignoring MPD Status Update Feb 28 22:02:52 volumio volumio[28791]: info: ------------------------------ 0ms Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand add "INTERNAL/1/一眼万年-S.H.E.mp3" took 0 milliseconds Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand play Feb 28 22:02:52 volumio volumio[28791]: info: ------------------------------ 1ms Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand play took 0 milliseconds Feb 28 22:02:52 volumio volumio[28791]: info: Feb 28 22:02:52 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:02:52 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:02:52 volumio volumio[28791]: info: Feb 28 22:02:52 volumio volumio[28791]: ---------------------------- MPD announces state update: player Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand status took 6 milliseconds Feb 28 22:02:52 volumio volumio[28791]: info: ControllerMpd::getState Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand status Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand status took 1 milliseconds Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::parseState Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:02:52 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":269,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"一眼万年","artist":"S.H.E","album":"Forever 新歌+精选","uri":"INTERNAL/1/一眼万年-S.H.E.mp3","trackType":"mp3"} Feb 28 22:02:52 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::syncState stateService play Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus stop Feb 28 22:02:52 volumio volumio[28791]: info: ------------------------------ 8ms Feb 28 22:02:52 volumio volumio[28791]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 28 22:02:52 volumio volumio[28791]: verbose: ControllerMpd::parseTrackInfo Feb 28 22:02:52 volumio volumio[28791]: info: ControllerMpd::pushState Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::servicePushState Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: verbose: STATE SERVICE {"status":"play","position":0,"seek":853,"duration":269,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"一眼万年","artist":"S.H.E","album":"Forever 新歌+精选","uri":"INTERNAL/1/一眼万年-S.H.E.mp3","trackType":"mp3"} Feb 28 22:02:52 volumio volumio[28791]: verbose: CURRENT POSITION 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::syncState stateService play Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::syncState currentStatus play Feb 28 22:02:52 volumio volumio[28791]: info: Received an update from plugin. extracting info from payload Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:52 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:52 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:52 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:52 volumio volumio[28791]: info: ------------------------------ 5ms Feb 28 22:02:57 volumio volumio[28791]: info: VolumeController::SetAlsaVolume55 Feb 28 22:02:57 volumio volumio[28791]: info: CoreStateMachine::pushState Feb 28 22:02:57 volumio volumio[28791]: info: CorePlayQueue::getTrack 0 Feb 28 22:02:57 volumio volumio[28791]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 22:02:57 volumio volumio[28791]: info: CoreCommandRouter::volumioPushState Feb 28 22:02:57 volumio volumio[28791]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 28 22:02:57 volumio volumio[28791]: Error: connect ETIMEDOUT 199.16.156.71:80 Feb 28 22:02:57 volumio volumio[28791]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Feb 28 22:02:57 volumio volumio[28791]: errno: -110, Feb 28 22:02:57 volumio volumio[28791]: code: 'ETIMEDOUT', Feb 28 22:02:57 volumio volumio[28791]: syscall: 'connect', Feb 28 22:02:57 volumio volumio[28791]: address: '199.16.156.71', Feb 28 22:02:57 volumio volumio[28791]: port: 80 Feb 28 22:02:57 volumio volumio[28791]: } Feb 28 22:02:57 volumio volumio[28791]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 28 22:02:57 volumio sudo[31592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-28 22:01 Feb 28 22:02:57 volumio sudo[31592]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 12:15:38 PM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9e0e048b157c8fb0f19240808f3da58b"