-- Logs begin at Thu 2019-02-14 04:11:59 CST, end at Sat 2024-10-12 20:49:49 CDT. -- Oct 12 20:48:22 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::stPlaybackTimer Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:22 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:22 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::serviceStop Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::serviceStop Oct 12 20:48:22 serena volumio[11172]: info: [1728784102318] ControllerWebradio::stop Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:48:22 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:22 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99234019 Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:48:22 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:48:22 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:48:22 serena volumio[11172]: info: [1728784102331] ControllerWebradio::clearAddPlayTrack Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:48:22 serena volumio[11172]: info: Oct 12 20:48:22 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand stop took 28 milliseconds Oct 12 20:48:22 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand stop took 15 milliseconds Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:48:22 serena volumio[11172]: info: Oct 12 20:48:22 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:22 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand status took 3 milliseconds Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand clear took 4 milliseconds Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99234019" Oct 12 20:48:22 serena volumio[11172]: error: updateQueue error: null Oct 12 20:48:22 serena volumio[11172]: info: ------------------------------ 3ms Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:22 serena volumio[11172]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 12 20:48:22 serena volumio[11172]: info: ------------------------------ 8ms Oct 12 20:48:22 serena volumio[11172]: info: Oct 12 20:48:22 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:22 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99234019" took 434 milliseconds Oct 12 20:48:22 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:48:22 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:48:22 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:22 serena volumio[11172]: info: sendMpdCommand play took 2 milliseconds Oct 12 20:48:23 serena volumio[11172]: info: Oct 12 20:48:23 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:23 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:23 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:23 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 12 20:48:23 serena volumio[11172]: info: sendMpdCommand status took 3 milliseconds Oct 12 20:48:23 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:23 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:23 serena volumio[11172]: info: sendMpdCommand clearerror took 1 milliseconds Oct 12 20:48:23 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:48:23 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:23 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:23 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:23 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:23 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:23 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:23 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:23 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:23 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:23 serena volumio[11172]: 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":"classicrockvinyl","artist":"Classic Rock Vinyl","album":null,"uri":"http://listen.shoutcast.com/classicrockvinyl","trackType":""} Oct 12 20:48:23 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:23 serena volumio[11172]: info: CoreStateMachine::syncState stateService stop Oct 12 20:48:23 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:48:23 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:23 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:23 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:23 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:23 serena volumio[11172]: info: No code Oct 12 20:48:23 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:23 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:23 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:23 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:23 serena volumio[11172]: info: ------------------------------ 21ms Oct 12 20:48:26 serena volumio[11172]: info: CoreCommandRouter::volumioStop Oct 12 20:48:26 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:26 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:33 serena volumio[11172]: error: error Oct 12 20:48:38 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 12 20:48:38 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:41 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:48:41 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:41 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99502708 Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:48:41 serena volumio[11172]: info: [1728784121169] ControllerWebradio::clearAddPlayTrack Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand stop took 5 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:41 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand clear took 1 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99502708" Oct 12 20:48:41 serena volumio[11172]: error: updateQueue error: null Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:41 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99502708" took 51 milliseconds Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand play took 2 milliseconds Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream","artist":"(#1 - 69/250) Classic Hits 109 - 70s Hits!","album":null,"uri":"http://144.217.79.175:6980/stream","trackType":""} Oct 12 20:48:41 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 7ms Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream","artist":"(#1 - 69/250) Classic Hits 109 - 70s Hits!","album":null,"uri":"http://144.217.79.175:6980/stream","trackType":""} Oct 12 20:48:41 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:48:41 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 27ms Oct 12 20:48:41 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:48:41 serena kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Oct 12 20:48:41 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:41 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:41 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:41 serena volumio[11172]: info: Oct 12 20:48:41 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 3ms Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand status took 1 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bay City Rollers - You Made Me Believe In Magic","artist":"Classic Hits 109 - 70s Hits!","album":null,"uri":"http://144.217.79.175:6980/stream","trackType":""} Oct 12 20:48:41 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:48:41 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 19ms Oct 12 20:48:41 serena volumio[11172]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 12 20:48:41 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:41 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:41 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:41 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bay City Rollers - You Made Me Believe In Magic","artist":"Classic Hits 109 - 70s Hits!","album":null,"uri":"http://144.217.79.175:6980/stream","trackType":""} Oct 12 20:48:41 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:48:41 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:41 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:41 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: ------------------------------ 32ms Oct 12 20:48:41 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:48:41 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:48:43 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 20:48:43 serena volumio[11172]: info: Received Get System Info Oct 12 20:48:43 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 20:48:43 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 20:48:43 serena volumio[11172]: info: Discovery: Getting this device information Oct 12 20:48:43 serena volumio[11172]: info: CoreCommandRouter::volumioGetState Oct 12 20:48:43 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 20:48:49 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::stPlaybackTimer Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:49 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:49 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::serviceStop Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::serviceStop Oct 12 20:48:49 serena volumio[11172]: info: [1728784129330] ControllerWebradio::stop Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:48:49 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:49 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99466613 Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:48:49 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:48:49 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:48:49 serena volumio[11172]: info: [1728784129341] ControllerWebradio::clearAddPlayTrack Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:48:49 serena volumio[11172]: info: Oct 12 20:48:49 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand stop took 19 milliseconds Oct 12 20:48:49 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand stop took 8 milliseconds Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:48:49 serena volumio[11172]: info: Oct 12 20:48:49 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:49 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand status took 6 milliseconds Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand clear took 5 milliseconds Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99466613" Oct 12 20:48:49 serena volumio[11172]: error: updateQueue error: null Oct 12 20:48:49 serena volumio[11172]: info: ------------------------------ 6ms Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:49 serena volumio[11172]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 12 20:48:49 serena volumio[11172]: info: ------------------------------ 13ms Oct 12 20:48:49 serena volumio[11172]: info: Oct 12 20:48:49 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:49 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99466613" took 46 milliseconds Oct 12 20:48:49 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:48:49 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:48:49 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:49 serena volumio[11172]: info: sendMpdCommand play took 1 milliseconds Oct 12 20:48:50 serena volumio[11172]: info: Oct 12 20:48:50 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:50 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:50 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:50 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 12 20:48:50 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:48:50 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:50 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:50 serena volumio[11172]: info: sendMpdCommand clearerror took 1 milliseconds Oct 12 20:48:50 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:48:50 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:50 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:50 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:50 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:50 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:50 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:50 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:50 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:50 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:50 serena volumio[11172]: 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":"(#1 - 36/200) 70s Great Hits","album":null,"uri":"https://176.31.248.14:35508/","trackType":"14:35508/"} Oct 12 20:48:50 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:50 serena volumio[11172]: info: CoreStateMachine::syncState stateService stop Oct 12 20:48:50 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:48:50 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:50 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:50 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:50 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:50 serena volumio[11172]: info: No code Oct 12 20:48:50 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:50 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:50 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:50 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:50 serena volumio[11172]: info: ------------------------------ 23ms Oct 12 20:48:52 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:48:52 serena volumio[11172]: info: Preload queue cleared Oct 12 20:48:52 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99466613 Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:48:52 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:48:52 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:48:52 serena volumio[11172]: info: [1728784132812] ControllerWebradio::clearAddPlayTrack Oct 12 20:48:52 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:48:52 serena volumio[11172]: info: sendMpdCommand stop took 2 milliseconds Oct 12 20:48:52 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:48:52 serena volumio[11172]: info: Oct 12 20:48:52 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:52 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:52 serena volumio[11172]: info: sendMpdCommand clear took 1 milliseconds Oct 12 20:48:52 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99466613" Oct 12 20:48:52 serena volumio[11172]: error: updateQueue error: null Oct 12 20:48:52 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:52 serena volumio[11172]: info: Oct 12 20:48:52 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:48:52 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:48:52 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99466613" took 48 milliseconds Oct 12 20:48:52 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:48:52 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:48:52 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:48:52 serena volumio[11172]: info: sendMpdCommand play took 2 milliseconds Oct 12 20:48:53 serena volumio[11172]: info: Oct 12 20:48:53 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:48:53 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:48:53 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:48:53 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 12 20:48:53 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:48:53 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:48:53 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:48:53 serena volumio[11172]: info: sendMpdCommand clearerror took 1 milliseconds Oct 12 20:48:53 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:48:53 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:48:53 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:48:53 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:48:53 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:53 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:48:53 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:53 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:53 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:53 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:48:53 serena volumio[11172]: 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":"(#1 - 33/200) 70s Great Hits","album":null,"uri":"https://176.31.248.14:35508/","trackType":"14:35508/"} Oct 12 20:48:53 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:48:53 serena volumio[11172]: info: CoreStateMachine::syncState stateService stop Oct 12 20:48:53 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:48:53 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:53 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:53 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:53 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:53 serena volumio[11172]: info: No code Oct 12 20:48:53 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:48:53 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:48:53 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:48:53 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:48:53 serena volumio[11172]: info: ------------------------------ 27ms Oct 12 20:49:01 serena volumio[11172]: info: Preload queue cleared Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:49:01 serena volumio[11172]: info: Preload queue cleared Oct 12 20:49:01 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99509176 Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:49:01 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:49:01 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:49:01 serena volumio[11172]: info: [1728784141059] ControllerWebradio::clearAddPlayTrack Oct 12 20:49:01 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:49:01 serena volumio[11172]: info: sendMpdCommand stop took 1 milliseconds Oct 12 20:49:01 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:49:01 serena volumio[11172]: info: Oct 12 20:49:01 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:01 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:01 serena volumio[11172]: info: sendMpdCommand clear took 0 milliseconds Oct 12 20:49:01 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99509176" Oct 12 20:49:01 serena volumio[11172]: error: updateQueue error: null Oct 12 20:49:01 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:49:01 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99509176" took 45 milliseconds Oct 12 20:49:01 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:49:01 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:49:01 serena volumio[11172]: info: Oct 12 20:49:01 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:01 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:01 serena volumio[11172]: info: sendMpdCommand play took 1 milliseconds Oct 12 20:49:01 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:49:02 serena volumio[11172]: info: Oct 12 20:49:02 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:02 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:02 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:02 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 12 20:49:02 serena volumio[11172]: info: sendMpdCommand status took 6 milliseconds Oct 12 20:49:02 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:02 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:02 serena volumio[11172]: info: sendMpdCommand clearerror took 3 milliseconds Oct 12 20:49:02 serena volumio[11172]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 20:49:02 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:02 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:02 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:02 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:02 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:02 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:02 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:02 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:02 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:02 serena volumio[11172]: 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":"radio.mp3","artist":"(#1 - 12/750) Best 70s","album":null,"uri":"https://c4.auracast.net:8040/radio.mp3","trackType":"mp3"} Oct 12 20:49:02 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:02 serena volumio[11172]: info: CoreStateMachine::syncState stateService stop Oct 12 20:49:02 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:49:02 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:02 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:02 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:02 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:02 serena volumio[11172]: info: No code Oct 12 20:49:02 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:02 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:02 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:02 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:02 serena volumio[11172]: info: ------------------------------ 25ms Oct 12 20:49:06 serena volumio[11172]: info: Preload queue cleared Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:49:06 serena volumio[11172]: info: Preload queue cleared Oct 12 20:49:06 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1729607 Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:49:06 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:49:06 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:49:06 serena volumio[11172]: info: [1728784146812] ControllerWebradio::clearAddPlayTrack Oct 12 20:49:06 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:49:06 serena volumio[11172]: info: sendMpdCommand stop took 1 milliseconds Oct 12 20:49:06 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:49:06 serena volumio[11172]: info: Oct 12 20:49:06 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:06 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:06 serena volumio[11172]: info: sendMpdCommand clear took 1 milliseconds Oct 12 20:49:06 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1729607" Oct 12 20:49:06 serena volumio[11172]: error: updateQueue error: null Oct 12 20:49:06 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:49:06 serena volumio[11172]: info: Oct 12 20:49:06 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:06 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:06 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1729607" took 47 milliseconds Oct 12 20:49:06 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:49:06 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:49:06 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:49:06 serena volumio[11172]: info: sendMpdCommand play took 1 milliseconds Oct 12 20:49:08 serena volumio[11172]: info: Oct 12 20:49:08 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:08 serena volumio[11172]: info: Oct 12 20:49:08 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand status took 1 milliseconds Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:08 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:08 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70s_128","artist":"1.FM - Absolute 70's Pop (www.1.fm)","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:08 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:49:08 serena volumio[11172]: info: ------------------------------ 10ms Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:08 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:08 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70s_128","artist":"1.FM - Absolute 70's Pop (www.1.fm)","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:08 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:49:08 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:08 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:08 serena kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Oct 12 20:49:08 serena volumio[11172]: info: ------------------------------ 25ms Oct 12 20:49:08 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: Oct 12 20:49:08 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:08 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:08 serena volumio[11172]: info: Oct 12 20:49:08 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:08 serena volumio[11172]: info: Oct 12 20:49:08 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:08 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:08 serena volumio[11172]: info: Oct 12 20:49:08 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:08 serena volumio[11172]: info: ------------------------------ 3ms Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand status took 3 milliseconds Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:08 serena volumio[11172]: info: ------------------------------ 6ms Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand status took 6 milliseconds Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:08 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:08 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":346,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Queen - Bohemian Rhapsody","artist":"1.FM - Absolute 70's Pop Radio","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:08 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:49:08 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: ------------------------------ 21ms Oct 12 20:49:08 serena volumio[11172]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 12 20:49:08 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:08 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:08 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:08 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1237,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Queen - Bohemian Rhapsody","artist":"1.FM - Absolute 70's Pop Radio","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:08 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:49:08 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:08 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:08 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: ------------------------------ 37ms Oct 12 20:49:08 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:08 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:09 serena volumio[11172]: info: Preload queue cleared Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::ClearQueue Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::stPlaybackTimer Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:09 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:09 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::serviceStop Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::serviceStop Oct 12 20:49:09 serena volumio[11172]: info: [1728784149301] ControllerWebradio::stop Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::clearPlayQueue Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::addQueueItems Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::addQueueItems Oct 12 20:49:09 serena volumio[11172]: info: Preload queue cleared Oct 12 20:49:09 serena volumio[11172]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1729607 Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::volumioPushQueue Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::saveQueue Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::updateTrackBlock Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::getTrackBlock Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::volumioPlay Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::play index 0 Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::stop Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::play index undefined Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::startPlaybackTimer Oct 12 20:49:09 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:49:09 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 20:49:09 serena volumio[11172]: info: [1728784149310] ControllerWebradio::clearAddPlayTrack Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 20:49:09 serena volumio[11172]: info: Oct 12 20:49:09 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand stop took 15 milliseconds Oct 12 20:49:09 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand stop took 6 milliseconds Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 20:49:09 serena volumio[11172]: info: Oct 12 20:49:09 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:09 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand clear took 2 milliseconds Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1729607" Oct 12 20:49:09 serena volumio[11172]: error: updateQueue error: null Oct 12 20:49:09 serena volumio[11172]: info: ------------------------------ 3ms Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:09 serena volumio[11172]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 12 20:49:09 serena volumio[11172]: info: ------------------------------ 6ms Oct 12 20:49:09 serena volumio[11172]: info: Oct 12 20:49:09 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:09 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1729607" took 48 milliseconds Oct 12 20:49:09 serena volumio[11172]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 20:49:09 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand play Oct 12 20:49:09 serena volumio[11172]: info: ------------------------------ 2ms Oct 12 20:49:09 serena volumio[11172]: info: sendMpdCommand play took 1 milliseconds Oct 12 20:49:10 serena volumio[11172]: info: Oct 12 20:49:10 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:10 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:10 serena volumio[11172]: info: Oct 12 20:49:10 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:10 serena volumio[11172]: info: sendMpdCommand status took 2 milliseconds Oct 12 20:49:10 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:10 serena volumio[11172]: info: sendMpdCommand status took 1 milliseconds Oct 12 20:49:10 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:10 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:10 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:10 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70s_128","artist":"1.FM - Absolute 70's Pop (www.1.fm)","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:10 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus stop Oct 12 20:49:10 serena volumio[11172]: info: ------------------------------ 7ms Oct 12 20:49:10 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:10 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:10 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:10 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70s_128","artist":"1.FM - Absolute 70's Pop (www.1.fm)","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:10 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:49:10 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:10 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: ------------------------------ 18ms Oct 12 20:49:10 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: Oct 12 20:49:10 serena volumio[11172]: ---------------------------- MPD announces system playlist update Oct 12 20:49:10 serena volumio[11172]: info: Ignoring MPD Status Update Oct 12 20:49:10 serena volumio[11172]: info: Oct 12 20:49:10 serena volumio[11172]: ---------------------------- MPD announces state update: player Oct 12 20:49:10 serena volumio[11172]: info: ControllerMpd::getState Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand status Oct 12 20:49:10 serena volumio[11172]: info: ------------------------------ 6ms Oct 12 20:49:10 serena volumio[11172]: info: sendMpdCommand status took 6 milliseconds Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::parseState Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 20:49:10 serena volumio[11172]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 20:49:10 serena volumio[11172]: verbose: ControllerMpd::parseTrackInfo Oct 12 20:49:10 serena volumio[11172]: info: ControllerMpd::pushState Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::servicePushState Oct 12 20:49:10 serena volumio[11172]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:10 serena volumio[11172]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1237,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Queen - Bohemian Rhapsody","artist":"1.FM - Absolute 70's Pop Radio","album":null,"uri":"http://185.33.21.112:80/70s_128","trackType":""} Oct 12 20:49:10 serena volumio[11172]: verbose: CURRENT POSITION 0 Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::syncState stateService play Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::syncState currentStatus play Oct 12 20:49:10 serena volumio[11172]: info: Received an update from plugin. extracting info from payload Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: CoreStateMachine::pushState Oct 12 20:49:10 serena volumio[11172]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output update for this device Oct 12 20:49:10 serena volumio[11172]: info: MRS: Pushing multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: ------------------------------ 25ms Oct 12 20:49:10 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:10 serena volumio[11172]: info: MRS: Updating multiroomSync output Oct 12 20:49:23 serena volumio[11172]: error: error Oct 12 20:49:33 serena volumio[11172]: Searching all installed plugins Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 12 20:49:33 serena volumio[11172]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: 80s80s , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: radio_paradise , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumio-livemusicarchive , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: volumio-phishin , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 12 20:49:33 serena volumio[11172]: info: CoreCommandRouter::executeOnPlugin: smart_inputs , search Oct 12 20:49:33 serena volumio[11172]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin smart_inputs Oct 12 20:49:33 serena volumio[11172]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 20:49:33 serena volumio[11172]: SyntaxError: Unexpected end of JSON input Oct 12 20:49:33 serena volumio[11172]: at JSON.parse () Oct 12 20:49:33 serena volumio[11172]: at Socket. (/data/plugins/music_service/volumio-livemusicarchive/index.js:1068:25) Oct 12 20:49:33 serena volumio[11172]: at Socket.emit (events.js:327:22) Oct 12 20:49:33 serena volumio[11172]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 12 20:49:33 serena volumio[11172]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 12 20:49:33 serena volumio[11172]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 20:49:34 serena sudo[12238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-12 20:48 Oct 12 20:49:34 serena sudo[12238]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 20:49:34 serena sudo[12238]: pam_unix(sudo:session): session closed for user root Oct 12 20:49:34 serena vtcs[11570]: [2024-10-12 20:49:34.377] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Oct 12 20:49:34 serena volumio-remote-updater[624]: [2024-10-12 20:49:34] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 20:49:34 serena volumio-remote-updater[624]: [2024-10-12 20:49:34] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 20:49:34 serena go-librespot[11327]: time="2024-10-12T20:49:34-05:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Oct 12 20:49:34 serena systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 20:49:34 serena ntfs-3g[11215]: Unmounting /dev/sda2 (4TB_Removable) Oct 12 20:49:34 serena systemd[1]: media-4TB_Removable.mount: Succeeded. Oct 12 20:49:34 serena systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 20:49:34 serena systemd[1]: Started dynamicswap service. Oct 12 20:49:34 serena systemd[1]: dynamicswap.service: Succeeded. Oct 12 20:49:34 serena systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 12 20:49:34 serena systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Oct 12 20:49:34 serena systemd[1]: Started dynamicswap service. Oct 12 20:49:34 serena systemd[1]: Stopped Volumio Backend Module. Oct 12 20:49:34 serena systemd[1]: Started Volumio Backend Module. Oct 12 20:49:34 serena systemd[1]: dynamicswap.service: Succeeded. Oct 12 20:49:35 serena volumio[12251]: info: ------------------------------------------- Oct 12 20:49:35 serena volumio[12251]: info: ----- Volumio3 ---- Oct 12 20:49:35 serena volumio[12251]: info: ------------------------------------------- Oct 12 20:49:35 serena volumio[12251]: info: ----- System startup ---- Oct 12 20:49:35 serena volumio[12251]: info: ------------------------------------------- Oct 12 20:49:36 serena volumio[12251]: info: MYVOLUMIO Environment detected Oct 12 20:49:36 serena volumio[12251]: info: Plugin folders cleanup Oct 12 20:49:36 serena volumio[12251]: info: Scanning into folder /volumio/app/plugins/ Oct 12 20:49:36 serena volumio[12251]: info: Scanning category audio_interface Oct 12 20:49:36 serena volumio[12251]: info: Scanning category miscellanea Oct 12 20:49:36 serena volumio[12251]: info: Scanning category music_service Oct 12 20:49:36 serena volumio[12251]: info: Scanning category plugins.json Oct 12 20:49:36 serena volumio[12251]: info: Scanning category system_controller Oct 12 20:49:36 serena volumio[12251]: info: Scanning category user_interface Oct 12 20:49:36 serena volumio[12251]: info: Scanning into folder /data/plugins/ Oct 12 20:49:36 serena volumio[12251]: info: Scanning category music_service Oct 12 20:49:36 serena volumio[12251]: info: Scanning category system_controller Oct 12 20:49:36 serena volumio[12251]: info: Scanning category user_interface Oct 12 20:49:36 serena volumio[12251]: info: Plugin folders cleanup completed Oct 12 20:49:36 serena volumio[12251]: info: ------------------------------------------- Oct 12 20:49:36 serena volumio[12251]: info: ----- Core plugins startup ---- Oct 12 20:49:36 serena volumio[12251]: info: ------------------------------------------- Oct 12 20:49:36 serena volumio[12251]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 20:49:36 serena volumio[12251]: info: Adding plugin upnp to MyMusic Plugins Oct 12 20:49:36 serena volumio[12251]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 20:49:36 serena volumio[12251]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 20:49:36 serena volumio[12251]: info: Loading plugins from folder /data/plugins/ Oct 12 20:49:36 serena volumio[12251]: info: Loading plugin "system"... Oct 12 20:49:36 serena volumio[12251]: info: Loading plugin "appearance"... Oct 12 20:49:36 serena volumio[12251]: info: Loading plugin "network"... Oct 12 20:49:36 serena volumio[12251]: info: Refreshing Cached IP Addresses Oct 12 20:49:36 serena sudo[12278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 20:49:36 serena volumio[12251]: info: Loading plugin "services"... Oct 12 20:49:36 serena sudo[12278]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 20:49:36 serena volumio[12251]: info: Loading plugin "alsa_controller"... Oct 12 20:49:36 serena sudo[12278]: pam_unix(sudo:session): session closed for user root Oct 12 20:49:36 serena sudo[12280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 20:49:36 serena sudo[12280]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 20:49:36 serena sudo[12280]: pam_unix(sudo:session): session closed for user root Oct 12 20:49:37 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 20:49:37 serena volumio[12251]: info: Loading plugin "wizard"... Oct 12 20:49:37 serena volumio[12251]: info: Loading plugin "networkfs"... Oct 12 20:49:37 serena volumio[12251]: info: Starting Udev Watcher for removable devices Oct 12 20:49:37 serena volumio[12251]: info: Ignoring mount for partition: boot Oct 12 20:49:37 serena volumio[12251]: info: Ignoring mount for partition: volumio Oct 12 20:49:37 serena volumio[12251]: info: Ignoring mount for partition: volumio_data Oct 12 20:49:37 serena volumio[12251]: error: Cannot associate FS Label, not mounting Oct 12 20:49:37 serena volumio[12251]: info: Mounting Device 4TB_Removable Oct 12 20:49:37 serena sudo[12289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda2 /mnt/USB/4TB_Removable -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 12 20:49:37 serena sudo[12289]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 20:49:39 serena volumio-remote-updater[624]: [2024-10-12 20:49:39] [connect] Successful connection Oct 12 20:49:45 serena ntfs-3g[12295]: Version 2017.3.23AR.3 integrated FUSE 28 Oct 12 20:49:45 serena ntfs-3g[12295]: Mounted /dev/sda2 (Read-Write, label "4TB_Removable", NTFS 3.1) Oct 12 20:49:45 serena ntfs-3g[12295]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 12 20:49:45 serena ntfs-3g[12295]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda2,blkdev,blksize=4096 Oct 12 20:49:45 serena ntfs-3g[12295]: Global ownership and permissions enforced, configuration type 7 Oct 12 20:49:45 serena sudo[12289]: pam_unix(sudo:session): session closed for user root Oct 12 20:49:45 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "volumio_command_line_client"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "upnp"... Oct 12 20:49:45 serena volumio[12251]: info: [1728784185035] Starting Upmpd Daemon Oct 12 20:49:45 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "my_music"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "mpd"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "upnp_browser"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "alarm-clock"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "airplay_emulation"... Oct 12 20:49:45 serena volumio[12251]: info: Starting Shairport Sync Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "last_100"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "webradio"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "i2s_dacs"... Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "volumiodiscovery"... Oct 12 20:49:45 serena volumio[12251]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 20:49:45 serena volumio[12251]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 20:49:45 serena volumio[12251]: *** WARNING *** For more information see Oct 12 20:49:45 serena node[12251]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 20:49:45 serena volumio[12251]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 20:49:45 serena volumio[12251]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 20:49:45 serena volumio[12251]: *** WARNING *** For more information see Oct 12 20:49:45 serena node[12251]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 20:49:45 serena node[12251]: *** WARNING *** For more information see Oct 12 20:49:45 serena node[12251]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 20:49:45 serena node[12251]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 20:49:45 serena node[12251]: *** WARNING *** For more information see Oct 12 20:49:45 serena volumio[12251]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 20:49:45 serena volumio[12251]: info: Discovery: Started advertising with name: Serena Oct 12 20:49:45 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 20:49:45 serena volumio[12251]: info: Loading plugin "spop"... Oct 12 20:49:46 serena volumio[12251]: info: Loading plugin "now_playing"... Oct 12 20:49:46 serena volumio[12251]: info: Loading plugin "outputs"... Oct 12 20:49:46 serena volumio[12251]: info: Loading plugin "albumart"... Oct 12 20:49:46 serena volumio[12251]: info: Plugin example_plugin is not enabled Oct 12 20:49:46 serena volumio[12251]: info: Loading plugin "inputs"... Oct 12 20:49:46 serena volumio[12251]: info: Loading plugin "updater_comm"... Oct 12 20:49:46 serena volumio[12251]: info: Plugin mpdemulation is not enabled Oct 12 20:49:46 serena volumio[12251]: info: Loading plugin "rest_api"... Oct 12 20:49:47 serena volumio[12251]: info: Loading plugin "websocket"... Oct 12 20:49:47 serena volumio[12251]: info: Starting Socket.io Server version 2.3.0 Oct 12 20:49:47 serena volumio[12251]: info: Loading plugin "80s80s"... Oct 12 20:49:47 serena volumio[12251]: Forking 3 albumart workers Oct 12 20:49:47 serena volumio[12251]: info: Applying required configuration parameters for plugin 80s80s Oct 12 20:49:47 serena volumio[12251]: info: [1728784187205] [80s80s] API delay: 30 Oct 12 20:49:47 serena volumio[12251]: info: Loading plugin "radio_paradise"... Oct 12 20:49:47 serena volumio[12251]: info: Applying required configuration parameters for plugin radio_paradise Oct 12 20:49:47 serena volumio[12251]: info: [1728784187407] [RadioParadise] API delay: 5 Oct 12 20:49:47 serena volumio[12251]: info: Loading plugin "volumio-livemusicarchive"... Oct 12 20:49:47 serena volumio[12251]: info: Applying required configuration parameters for plugin volumio-livemusicarchive Oct 12 20:49:47 serena volumio[12251]: info: Loading plugin "volumio-phishin"... Oct 12 20:49:47 serena volumio[12251]: Starting albumart workers Oct 12 20:49:47 serena volumio[12251]: Starting albumart workers Oct 12 20:49:47 serena volumio[12251]: Starting albumart workers Oct 12 20:49:48 serena volumio[12251]: info: Applying required configuration parameters for plugin volumio-phishin Oct 12 20:49:48 serena volumio[12251]: info: Loading plugin "backup_restore"... Oct 12 20:49:48 serena volumio[12251]: info: Applying required configuration parameters for plugin backup_restore Oct 12 20:49:48 serena volumio[12251]: info: Loading plugin "Systeminfo"... Oct 12 20:49:48 serena volumio[12251]: info: Loading i18n strings for locale en Oct 12 20:49:48 serena volumio[12251]: Updating browse sources language Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::initPlayerControls Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 20:49:48 serena volumio[12251]: Express server listening on port 3000 Oct 12 20:49:48 serena volumio[12251]: [Metrics] WebUI: 13s 259.90ms Oct 12 20:49:48 serena volumio[12251]: info: CoreStateMachine::resetVolumioState Oct 12 20:49:48 serena volumio[12251]: info: CoreStateMachine::getcurrentVolume Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 20:49:48 serena volumio[12251]: info: CoreStateMachine::pushState Oct 12 20:49:48 serena volumio[12251]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.244 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Edg/129.0.0.0 Engine version: 3 Transport: polling Total Clients: 1 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.244 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Edg/129.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.75 UA: Mozilla/5.0 (Linux; Android 14; SM-S916U Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.75 UA: Mozilla/5.0 (Linux; Android 14; SM-S916U Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.244 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Edg/129.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.75 UA: Mozilla/5.0 (Linux; Android 14; SM-S916U Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213:3000 from 192.168.10.191 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213:3000 from 192.168.10.191 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213:3000 from 192.168.10.49 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.244 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Edg/129.0.0.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 12 20:49:48 serena volumio[12251]: verbose: New Socket.io Connection to 192.168.10.213 from 192.168.10.75 UA: Mozilla/5.0 (Linux; Android 14; SM-S916U Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/129.0.6668.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 20:49:48 serena volumio[12251]: info: Discovery: Getting this device information Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::volumioGetState Oct 12 20:49:48 serena volumio[12251]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 20:49:48 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 20:49:48 serena volumio[12251]: info: Reloading queue from file Oct 12 20:49:49 serena volumio[12251]: info: CoreStateMachine::setRepeat false single undefined Oct 12 20:49:49 serena volumio[12251]: info: CoreStateMachine::pushState Oct 12 20:49:49 serena volumio[12251]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:49 serena volumio[12251]: info: CoreStateMachine::setRandom false Oct 12 20:49:49 serena volumio[12251]: info: CoreStateMachine::pushState Oct 12 20:49:49 serena volumio[12251]: info: CorePlayQueue::getTrack 0 Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::volumioPushState Oct 12 20:49:49 serena volumio[12251]: info: Setting Device type: Raspberry PI Oct 12 20:49:49 serena volumio[12251]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 20:49:49 serena volumio[12251]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Oct 12 20:49:49 serena volumio[12251]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 20:49:49 serena volumio[12251]: Searching all installed plugins Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: , search Oct 12 20:49:49 serena volumio[12251]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 12 20:49:49 serena volumio[12251]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 20:49:49 serena volumio[12251]: TypeError: Cannot read property 'then' of undefined Oct 12 20:49:49 serena volumio[12251]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1582:17) Oct 12 20:49:49 serena volumio[12251]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1083:32) Oct 12 20:49:49 serena volumio[12251]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Oct 12 20:49:49 serena volumio[12251]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Oct 12 20:49:49 serena volumio[12251]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:485:44) Oct 12 20:49:49 serena volumio[12251]: at Socket.emit (events.js:315:20) Oct 12 20:49:49 serena volumio[12251]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 12 20:49:49 serena volumio[12251]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 12 20:49:49 serena volumio[12251]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 20:49:49 serena sudo[12370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-12 20:48 Oct 12 20:49:49 serena sudo[12370]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"