-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sun 2026-03-29 18:53:52 CEST. -- Mar 29 18:52:00 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:52:01 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::ClearQueue Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::clearPlayQueue Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::addQueueItems Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::addQueueItems Mar 29 18:52:01 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:52:01 volumio-due volumio[1133]: info: Adding Item to queue: webeighties/2 Mar 29 18:52:01 volumio-due volumio[1133]: info: Using cached record of: webeighties/2 Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::updateTrackBlock Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::getTrackBlock Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPlay Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::play index 0 Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::play index undefined Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:01 volumio-due volumio[1133]: info: CoreStateMachine::startPlaybackTimer Mar 29 18:52:01 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:01 volumio-due volumio[1133]: info: [1774803121863] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/love/mp3-192/volumio Mar 29 18:52:01 volumio-due volumio[1133]: info: [1774803121863] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=85&count=2 Mar 29 18:52:02 volumio-due volumio[1133]: info: [1774803122079] [80s80s] received new event containing 2 songs. Mar 29 18:52:02 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand stop Mar 29 18:52:02 volumio-due volumio[1133]: info: sendMpdCommand stop took 1 milliseconds Mar 29 18:52:02 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand clear Mar 29 18:52:02 volumio-due volumio[1133]: info: Mar 29 18:52:02 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:02 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:02 volumio-due volumio[1133]: info: sendMpdCommand clear took 2 milliseconds Mar 29 18:52:02 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 29 18:52:02 volumio-due volumio[1133]: error: updateQueue error: null Mar 29 18:52:02 volumio-due volumio[1133]: info: ------------------------------ 2ms Mar 29 18:52:02 volumio-due volumio[1133]: info: sendMpdCommand consume 1 took 1 milliseconds Mar 29 18:52:02 volumio-due volumio[1133]: info: [1774803122084] [80s80s] adding url: http://streams.80s80s.de/love/mp3-192/volumio Mar 29 18:52:02 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/love/mp3-192/volumio" Mar 29 18:52:02 volumio-due volumio[1133]: info: Mar 29 18:52:02 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:02 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:02 volumio-due volumio[1133]: info: sendMpdCommand add "http://streams.80s80s.de/love/mp3-192/volumio" took 1 milliseconds Mar 29 18:52:02 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand play Mar 29 18:52:02 volumio-due volumio[1133]: info: ------------------------------ 4ms Mar 29 18:52:02 volumio-due volumio[1133]: info: sendMpdCommand play took 5 milliseconds Mar 29 18:52:02 volumio-due volumio[1133]: info: [1774803122094] [80s80s] Pushing the next song state: Madonna - Live to Tell Mar 29 18:52:02 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:02 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:02 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:02 volumio-due volumio[1133]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/30/1a/dd/301addb8-08b9-695b-815a-68818d10764f/source/600x600bb.jpg","name":"Madonna - Live to Tell","title":"Live to Tell","artist":"80s80s Love","album":"","streaming":true,"disableUiControls":true,"duration":"298","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 29 18:52:02 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:52:02 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService play Mar 29 18:52:02 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus stop Mar 29 18:52:02 volumio-due volumio[1133]: info: [1774803122095] [80s80s] PlayNextTrack API delay: 30 Mar 29 18:52:02 volumio-due volumio[1133]: info: [1774803122098] [80s80s] Setting timer to: 298000 milliseconds. Mar 29 18:52:02 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:02 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 1 Mar 29 18:52:04 volumio-due volumio[1133]: info: Mar 29 18:52:04 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:04 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 29 18:52:04 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 29 18:52:04 volumio-due volumio[1133]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 29 18:52:04 volumio-due volumio[1133]: info: Mar 29 18:52:04 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:04 volumio-due volumio[1133]: info: Mar 29 18:52:04 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:04 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:04 volumio-due volumio[1133]: info: Mar 29 18:52:04 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand status took 7 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:04 volumio-due volumio[1133]: info: Mar 29 18:52:04 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:04 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:04 volumio-due volumio[1133]: info: Mar 29 18:52:04 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand status took 5 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: info: ------------------------------ 6ms Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand status took 5 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:04 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:04 volumio-due volumio[1133]: info: ------------------------------ 19ms Mar 29 18:52:04 volumio-due volumio[1133]: info: ------------------------------ 9ms Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand status took 7 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:04 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:04 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:04 volumio-due volumio[1133]: info: ------------------------------ 15ms Mar 29 18:52:04 volumio-due volumio[1133]: info: ------------------------------ 14ms Mar 29 18:52:04 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 29 18:52:04 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:04 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:04 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:04 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:04 volumio-due volumio[1133]: info: ------------------------------ 12ms Mar 29 18:52:08 volumio-due volumiologrotate[614]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Mar 29 18:52:08 volumio-due volumiologrotate[614]: ls: cannot access 'DUE': No such file or directory Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioRemoveQueueItem Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::removeQueueItem Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::stPlaybackTimer Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::updateTrackBlock Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrackBlock Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::serviceStop Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::serviceStop Mar 29 18:52:20 volumio-due volumio[1133]: info: ControllerMpd::stop Mar 29 18:52:20 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand stop Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::removeQueueItem 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:52:20 volumio-due volumio[1133]: info: Mar 29 18:52:20 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:20 volumio-due volumio[1133]: info: sendMpdCommand stop took 29 milliseconds Mar 29 18:52:20 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:20 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/30/1a/dd/301addb8-08b9-695b-815a-68818d10764f/source/600x600bb.jpg","name":"Madonna - Live to Tell","title":"Live to Tell","artist":"80s80s Love","album":"","streaming":true,"disableUiControls":true,"duration":"298","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 29 18:52:20 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService stop Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus stop Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: No code Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: sendMpdCommand status took 23 milliseconds Mar 29 18:52:20 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:20 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:20 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 29 18:52:20 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:20 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: 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":"80s80s Love","artist":"80s80s Love","album":null,"uri":"http://streams.80s80s.de/love/mp3-192/volumio","trackType":""} Mar 29 18:52:20 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService stop Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus stop Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: No code Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:52:20 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:20 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:52:20 volumio-due volumio[1133]: info: ------------------------------ 43ms Mar 29 18:52:33 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::ClearQueue Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::clearPlayQueue Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::addQueueItems Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::addQueueItems Mar 29 18:52:33 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:52:33 volumio-due volumio[1133]: info: Adding Item to queue: webeighties/2 Mar 29 18:52:33 volumio-due volumio[1133]: info: Using cached record of: webeighties/2 Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::updateTrackBlock Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::getTrackBlock Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPlay Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::play index 0 Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::play index undefined Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:33 volumio-due volumio[1133]: info: CoreStateMachine::startPlaybackTimer Mar 29 18:52:33 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:33 volumio-due volumio[1133]: info: [1774803153987] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/love/mp3-192/volumio Mar 29 18:52:33 volumio-due volumio[1133]: info: [1774803153987] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=85&count=2 Mar 29 18:52:34 volumio-due volumio[1133]: info: [1774803154131] [80s80s] received new event containing 2 songs. Mar 29 18:52:34 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand stop Mar 29 18:52:34 volumio-due volumio[1133]: info: sendMpdCommand stop took 5 milliseconds Mar 29 18:52:34 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand clear Mar 29 18:52:34 volumio-due volumio[1133]: info: Mar 29 18:52:34 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:34 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:34 volumio-due volumio[1133]: info: sendMpdCommand clear took 1 milliseconds Mar 29 18:52:34 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 29 18:52:34 volumio-due volumio[1133]: error: updateQueue error: null Mar 29 18:52:34 volumio-due volumio[1133]: info: ------------------------------ 3ms Mar 29 18:52:34 volumio-due volumio[1133]: info: sendMpdCommand consume 1 took 2 milliseconds Mar 29 18:52:34 volumio-due volumio[1133]: info: [1774803154140] [80s80s] adding url: http://streams.80s80s.de/love/mp3-192/volumio Mar 29 18:52:34 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/love/mp3-192/volumio" Mar 29 18:52:34 volumio-due volumio[1133]: info: Mar 29 18:52:34 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:34 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:34 volumio-due volumio[1133]: info: sendMpdCommand add "http://streams.80s80s.de/love/mp3-192/volumio" took 23 milliseconds Mar 29 18:52:34 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand play Mar 29 18:52:34 volumio-due volumio[1133]: info: ------------------------------ 5ms Mar 29 18:52:34 volumio-due volumio[1133]: info: sendMpdCommand play took 10 milliseconds Mar 29 18:52:34 volumio-due volumio[1133]: info: [1774803154178] [80s80s] Pushing the next song state: Madonna - Live to Tell Mar 29 18:52:34 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:34 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:34 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:34 volumio-due volumio[1133]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/30/1a/dd/301addb8-08b9-695b-815a-68818d10764f/source/600x600bb.jpg","name":"Madonna - Live to Tell","title":"Live to Tell","artist":"80s80s Love","album":"","streaming":true,"disableUiControls":true,"duration":"298","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 29 18:52:34 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:52:34 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService play Mar 29 18:52:34 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus stop Mar 29 18:52:34 volumio-due volumio[1133]: info: [1774803154178] [80s80s] PlayNextTrack API delay: 30 Mar 29 18:52:34 volumio-due volumio[1133]: info: [1774803154179] [80s80s] Setting timer to: 298000 milliseconds. Mar 29 18:52:34 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:34 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 1 Mar 29 18:52:35 volumio-due volumio[1133]: info: Mar 29 18:52:35 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:35 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 29 18:52:35 volumio-due volumio[1133]: info: Mar 29 18:52:35 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:35 volumio-due volumio[1133]: info: sendMpdCommand status took 10 milliseconds Mar 29 18:52:35 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:35 volumio-due volumio[1133]: info: sendMpdCommand status took 3 milliseconds Mar 29 18:52:35 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:35 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:35 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:35 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:35 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:35 volumio-due volumio[1133]: info: ------------------------------ 22ms Mar 29 18:52:35 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:35 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:35 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:35 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:35 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:35 volumio-due volumio[1133]: info: ------------------------------ 7ms Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - {"Reload":{"result":"Ok"}} Mar 29 18:52:35 volumio-due volumio[1133]: info: FusionDsp - {"Reload":{"result":"Ok"}} Mar 29 18:52:35 volumio-due volumio[1133]: info: Mar 29 18:52:35 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:52:35 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:52:35 volumio-due volumio[1133]: info: Mar 29 18:52:35 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:52:35 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:52:35 volumio-due volumio[1133]: info: ------------------------------ 30ms Mar 29 18:52:35 volumio-due volumio[1133]: info: sendMpdCommand status took 29 milliseconds Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:52:35 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 29 18:52:35 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:52:35 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:52:35 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:52:35 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:52:35 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:52:35 volumio-due volumio[1133]: info: ------------------------------ 32ms Mar 29 18:53:05 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::ClearQueue Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::stPlaybackTimer Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::updateTrackBlock Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrackBlock Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::serviceStop Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::serviceStop Mar 29 18:53:05 volumio-due volumio[1133]: info: ControllerMpd::stop Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand stop Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::clearPlayQueue Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::addQueueItems Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::addQueueItems Mar 29 18:53:05 volumio-due volumio[1133]: info: Preload queue cleared Mar 29 18:53:05 volumio-due volumio[1133]: info: Adding Item to queue: webeighties/3 Mar 29 18:53:05 volumio-due volumio[1133]: info: Exploding uri webeighties/3 in service 80s80s Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185669] [80s80s] explodeUri: webeighties/3 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushQueue Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::saveQueue Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::updateTrackBlock Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrackBlock Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPlay Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::play index 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::stop Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::play index undefined Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::startPlaybackTimer Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185682] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/party/mp3-192/volumio Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185682] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=252&count=2 Mar 29 18:53:05 volumio-due volumio[1133]: info: Mar 29 18:53:05 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand stop took 32 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/30/1a/dd/301addb8-08b9-695b-815a-68818d10764f/source/600x600bb.jpg","name":"Madonna - Live to Tell","title":"Live to Tell","artist":"80s80s Love","album":"","streaming":true,"disableUiControls":true,"duration":"298","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 29 18:53:05 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService stop Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus stop Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:05 volumio-due volumio[1133]: info: No code Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand status took 34 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 35 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:53:05 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:53:05 volumio-due volumio[1133]: info: ------------------------------ 80ms Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185900] [80s80s] received new event containing 2 songs. Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand stop Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand stop took 2 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand clear Mar 29 18:53:05 volumio-due volumio[1133]: info: Mar 29 18:53:05 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:53:05 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand clear took 3 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 29 18:53:05 volumio-due volumio[1133]: error: updateQueue error: null Mar 29 18:53:05 volumio-due volumio[1133]: info: ------------------------------ 1ms Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand consume 1 took 1 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185907] [80s80s] adding url: http://streams.80s80s.de/party/mp3-192/volumio Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/party/mp3-192/volumio" Mar 29 18:53:05 volumio-due volumio[1133]: info: Mar 29 18:53:05 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:53:05 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand add "http://streams.80s80s.de/party/mp3-192/volumio" took 1 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand play Mar 29 18:53:05 volumio-due volumio[1133]: info: ------------------------------ 5ms Mar 29 18:53:05 volumio-due volumio[1133]: info: sendMpdCommand play took 1 milliseconds Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185912] [80s80s] Pushing the next song state: The Cure - Boys Don't Cry Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music125/v4/c6/9b/84/c69b8426-c75a-3432-d67b-facdbb844bb1/source/600x600bb.jpg","name":"The Cure - Boys Don't Cry","title":"Boys Don't Cry","artist":"80s80s Party","album":"","streaming":true,"disableUiControls":true,"duration":"149","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 29 18:53:05 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService play Mar 29 18:53:05 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus stop Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185914] [80s80s] PlayNextTrack API delay: 30 Mar 29 18:53:05 volumio-due volumio[1133]: info: [1774803185923] [80s80s] Setting timer to: 149000 milliseconds. Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:05 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 1 Mar 29 18:53:07 volumio-due volumio[1133]: info: Mar 29 18:53:07 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:53:07 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 29 18:53:07 volumio-due volumio[1133]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 29 18:53:07 volumio-due volumio[1133]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 29 18:53:07 volumio-due volumio[1133]: info: Mar 29 18:53:07 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:53:07 volumio-due volumio[1133]: info: Mar 29 18:53:07 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:53:07 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:53:07 volumio-due volumio[1133]: info: Mar 29 18:53:07 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand status took 9 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:53:07 volumio-due volumio[1133]: info: Mar 29 18:53:07 volumio-due volumio[1133]: ---------------------------- MPD announces system playlist update Mar 29 18:53:07 volumio-due volumio[1133]: info: Ignoring MPD Status Update Mar 29 18:53:07 volumio-due volumio[1133]: info: Mar 29 18:53:07 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand status took 5 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: info: ------------------------------ 6ms Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand status took 4 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:07 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:53:07 volumio-due volumio[1133]: info: ------------------------------ 22ms Mar 29 18:53:07 volumio-due volumio[1133]: info: ------------------------------ 10ms Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand status took 9 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 8 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:07 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:07 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:53:07 volumio-due volumio[1133]: info: ------------------------------ 22ms Mar 29 18:53:07 volumio-due volumio[1133]: info: ------------------------------ 21ms Mar 29 18:53:07 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 29 18:53:07 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:53:07 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:07 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:07 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:53:07 volumio-due volumio[1133]: info: ------------------------------ 20ms Mar 29 18:53:08 volumio-due volumiologrotate[614]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Mar 29 18:53:08 volumio-due volumiologrotate[614]: ls: cannot access 'DUE': No such file or directory Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 29 18:53:28 volumio-due volumio[1133]: info: Getting Alsa Cards List without I2S DAC Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: Invalid card number. Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Mar 29 18:53:28 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 29 18:53:43 volumio-due volumio[1133]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Mar 29 18:53:43 volumio-due volumio[1133]: info: Preparing to save Alsa Options, stopping services first Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::volumioGetState Mar 29 18:53:43 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPause Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::pause Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::stPlaybackTimer Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::servicePause Mar 29 18:53:43 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::servicePause Mar 29 18:53:43 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand pause Mar 29 18:53:43 volumio-due volumio[1133]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI Out"},"i2s":true,"i2sid":{"value":"hifiberry-dac","label":"HiFiBerry DAC"}} Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:43 volumio-due volumio[1133]: info: Enabling I2S DAC: HiFiBerry DAC Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:43 volumio-due sudo[8791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Mar 29 18:53:43 volumio-due sudo[8791]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:43 volumio-due sudo[8791]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:43 volumio-due volumio[1133]: info: No Overlays Loaded Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:43 volumio-due sudo[8796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dac Mar 29 18:53:43 volumio-due sudo[8796]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:43 volumio-due kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status Mar 29 18:53:43 volumio-due kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible Mar 29 18:53:43 volumio-due kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller Mar 29 18:53:43 volumio-due kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status Mar 29 18:53:43 volumio-due volumio[1133]: warn: Unable to locate the device HDMI Out a reboot may be required. Mar 29 18:53:43 volumio-due sudo[8796]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:43 volumio-due volumio[1133]: Invalid card number. Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 29 18:53:43 volumio-due volumio[1133]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10 Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 29 18:53:43 volumio-due volumio[1133]: info: Disabling external Volume Control Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Mar 29 18:53:43 volumio-due volumio[1133]: info: Preparing to generate the ALSA configuration file Mar 29 18:53:43 volumio-due volumio[1133]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Mar 29 18:53:43 volumio-due volumio[1133]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 29 18:53:43 volumio-due volumio[1133]: info: Reading ALSA contributions from plugins. Mar 29 18:53:43 volumio-due volumio[1133]: info: Mar 29 18:53:43 volumio-due volumio[1133]: ---------------------------- MPD announces state update: player Mar 29 18:53:43 volumio-due volumio[1133]: info: sendMpdCommand pause took 332 milliseconds Mar 29 18:53:43 volumio-due volumio[1133]: info: ControllerMpd::getState Mar 29 18:53:43 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand status Mar 29 18:53:43 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:43 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:43 volumio-due volumio[1133]: verbose: STATE SERVICE {"status":"pause","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music125/v4/c6/9b/84/c69b8426-c75a-3432-d67b-facdbb844bb1/source/600x600bb.jpg","name":"The Cure - Boys Don't Cry","title":"Boys Don't Cry","artist":"80s80s Party","album":"","streaming":true,"disableUiControls":true,"duration":"149","seek":38449,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 29 18:53:43 volumio-due volumio[1133]: verbose: CURRENT POSITION 0 Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::syncState stateService pause Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::syncState currentStatus pause Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:43 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:43 volumio-due volumio[1133]: info: CoreStateMachine::stPlaybackTimer Mar 29 18:53:43 volumio-due volumio[1133]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 29 18:53:43 volumio-due volumio[1133]: info: I2S Param [object Object] successfully enabled Mar 29 18:53:43 volumio-due volumio[1133]: info: sendMpdCommand status took 51 milliseconds Mar 29 18:53:43 volumio-due volumio[1133]: verbose: ControllerMpd::parseState Mar 29 18:53:43 volumio-due volumio[1133]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 29 18:53:44 volumio-due volumio[1133]: info: sendMpdCommand playlistinfo took 25 milliseconds Mar 29 18:53:44 volumio-due volumio[1133]: verbose: ControllerMpd::parseTrackInfo Mar 29 18:53:44 volumio-due volumio[1133]: info: ControllerMpd::pushState Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::servicePushState Mar 29 18:53:44 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:44 volumio-due volumio[1133]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 29 18:53:44 volumio-due volumio[1133]: info: ------------------------------ 78ms Mar 29 18:53:44 volumio-due volumio[1133]: info: VolumeController:: Volume=undefined Mute =false Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:44 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 29 18:53:44 volumio-due volumio[1133]: info: Getting Alsa Cards List without I2S DAC Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: Invalid card number. Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 29 18:53:44 volumio-due volumio[1133]: info: Asound.conf file unchanged, so no further update is needed Mar 29 18:53:44 volumio-due volumio[1133]: info: Output device has changed, restarting MPD Mar 29 18:53:44 volumio-due sudo[8842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 29 18:53:44 volumio-due sudo[8842]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:44 volumio-due sudo[8842]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:44 volumio-due volumio[1133]: info: Output device has changed, restarting Shairport Sync Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:44 volumio-due sudo[8845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 29 18:53:44 volumio-due sudo[8845]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:44 volumio-due systemd[1]: musicservicesshield.service: Succeeded. Mar 29 18:53:44 volumio-due systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 29 18:53:44 volumio-due systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 29 18:53:44 volumio-due systemd[1]: Stopping Music Player Daemon... Mar 29 18:53:44 volumio-due systemd[1]: mpd.service: Succeeded. Mar 29 18:53:44 volumio-due volumio[1133]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 29 18:53:44 volumio-due systemd[1]: Stopped Music Player Daemon. Mar 29 18:53:44 volumio-due volumio[1133]: info: MPD Permissions set Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due systemd[1]: Starting Music Player Daemon... Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 29 18:53:44 volumio-due volumio[1133]: info: Starting Shairport Sync Mar 29 18:53:44 volumio-due sudo[8850]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 29 18:53:44 volumio-due sudo[8850]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:44 volumio-due volumio[1133]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Mar 29 18:53:44 volumio-due volumio[1133]: info: CoreCommandRouter::volumioGetState Mar 29 18:53:44 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:44 volumio-due volumio[1133]: info: mpdhttpout --- Volumio set on pause Mar 29 18:53:44 volumio-due sudo[8850]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:44 volumio-due sudo[8864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 29 18:53:44 volumio-due sudo[8864]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:44 volumio-due systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 29 18:53:44 volumio-due systemd[1]: shairport-sync.service: Succeeded. Mar 29 18:53:44 volumio-due systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 29 18:53:44 volumio-due systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 29 18:53:44 volumio-due sudo[8864]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:44 volumio-due volumio[1133]: info: Shairport-Sync Started Mar 29 18:53:45 volumio-due mpd[8866]: Mar 29 18:53 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 29 18:53:45 volumio-due systemd[1]: Started Music Player Daemon. Mar 29 18:53:45 volumio-due sudo[8845]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:45 volumio-due volumio[1133]: error: updateQueue error: null Mar 29 18:53:45 volumio-due systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 29 18:53:45 volumio-due volumio[8966]: cset: --> shielding system active with Mar 29 18:53:45 volumio-due volumio[8966]: cset: "system" cpuset of CPUSPEC(1-3) with 223 tasks running Mar 29 18:53:45 volumio-due volumio[8966]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 29 18:53:45 volumio-due systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 29 18:53:46 volumio-due volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 29 18:53:46 volumio-due sudo[9144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 29 18:53:46 volumio-due sudo[9144]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:46 volumio-due systemd[1]: musicservicesshield.service: Succeeded. Mar 29 18:53:46 volumio-due systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 29 18:53:46 volumio-due systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 29 18:53:46 volumio-due systemd[1]: Stopping Music Player Daemon... Mar 29 18:53:46 volumio-due systemd[1]: mpd.service: Succeeded. Mar 29 18:53:46 volumio-due systemd[1]: Stopped Music Player Daemon. Mar 29 18:53:46 volumio-due systemd[1]: Starting Music Player Daemon... Mar 29 18:53:46 volumio-due sudo[9153]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 29 18:53:46 volumio-due sudo[9153]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 29 18:53:46 volumio-due sudo[9153]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:47 volumio-due mpd[9171]: Mar 29 18:53 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 29 18:53:47 volumio-due systemd[1]: Started Music Player Daemon. Mar 29 18:53:47 volumio-due sudo[9144]: pam_unix(sudo:session): session closed for user root Mar 29 18:53:47 volumio-due volumio[1133]: error: updateQueue error: null Mar 29 18:53:47 volumio-due systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 29 18:53:47 volumio-due volumio[1133]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Mar 29 18:53:47 volumio-due volumio[1133]: info: CoreStateMachine::getcurrentVolume Mar 29 18:53:47 volumio-due volumio[1133]: info: CoreCommandRouter::volumioRetrievevolume Mar 29 18:53:47 volumio-due volumio[1133]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 29 18:53:48 volumio-due volumio[1133]: info: VolumeController:: Volume=undefined Mute =false Mar 29 18:53:48 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:48 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:48 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:48 volumio-due volumio[1133]: info: CoreStateMachine::updateTrackBlock Mar 29 18:53:48 volumio-due volumio[1133]: info: CorePlayQueue::getTrackBlock Mar 29 18:53:48 volumio-due volumio[1133]: info: CoreCommandRouter::volumioRetrievevolume Mar 29 18:53:48 volumio-due volumio[1133]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 29 18:53:48 volumio-due volumio[1133]: info: VolumeController:: Volume=undefined Mute =false Mar 29 18:53:48 volumio-due volumio[1133]: info: CoreStateMachine::pushState Mar 29 18:53:48 volumio-due volumio[1133]: info: CorePlayQueue::getTrack 0 Mar 29 18:53:48 volumio-due volumio[1133]: info: CoreCommandRouter::volumioPushState Mar 29 18:53:48 volumio-due volumio[9271]: cset: --> shielding system active with Mar 29 18:53:48 volumio-due volumio[9271]: cset: "system" cpuset of CPUSPEC(1-3) with 221 tasks running Mar 29 18:53:48 volumio-due volumio[9271]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 29 18:53:48 volumio-due systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 29 18:53:52 volumio-due volumio[1133]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Mar 29 18:53:52 volumio-due volumio[1133]: info: PLUGIN onReboot : networkfs Mar 29 18:53:52 volumio-due volumio[1133]: info: PLUGIN onReboot : audiophonicsonoff Mar 29 18:53:52 volumio-due volumio[1133]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 18:53:52 volumio-due volumio[1133]: TypeError: Cannot read property 'writeSync' of undefined Mar 29 18:53:52 volumio-due volumio[1133]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Mar 29 18:53:52 volumio-due volumio[1133]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Mar 29 18:53:52 volumio-due volumio[1133]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Mar 29 18:53:52 volumio-due volumio[1133]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 29 18:53:52 volumio-due volumio[1133]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 29 18:53:52 volumio-due volumio[1133]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Mar 29 18:53:52 volumio-due volumio[1133]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22) Mar 29 18:53:52 volumio-due volumio[1133]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:870:33) Mar 29 18:53:52 volumio-due volumio[1133]: at Socket.emit (events.js:315:20) Mar 29 18:53:52 volumio-due volumio[1133]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 29 18:53:52 volumio-due volumio[1133]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 29 18:53:52 volumio-due volumio[1133]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 18:53:52 volumio-due sudo[9987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-29 18:52 Mar 29 18:53:52 volumio-due sudo[9987]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"