-- Logs begin at Thu 2019-02-14 04:12:00 CST, end at Fri 2024-10-25 06:00:21 CDT. -- Oct 25 05:59:00 musicstream volumio[1041]: info: [1729853940132] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:00 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:00 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:00 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:00 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:00 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:00 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:00 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:01 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:01 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:01 musicstream volumio[1041]: info: [1729853941815] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:01 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:01 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:01 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:01 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:01 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:01 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:01 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:02 musicstream volumio[1041]: info: [1729853942665] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:02 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:02 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:02 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:02 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:02 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:02 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 25 05:59:02 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:03 musicstream nmbd[708]: [2024/10/25 05:59:03.294199, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 25 05:59:03 musicstream nmbd[708]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.40 for name WORKGROUP<1d>. Oct 25 05:59:03 musicstream nmbd[708]: This response was from IP 10.0.0.42, reporting an IP address of 10.0.0.42. Oct 25 05:59:03 musicstream nmbd[708]: [2024/10/25 05:59:03.294539, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 25 05:59:03 musicstream nmbd[708]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.45 for name WORKGROUP<1d>. Oct 25 05:59:03 musicstream nmbd[708]: This response was from IP 10.0.0.42, reporting an IP address of 10.0.0.42. Oct 25 05:59:04 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:04 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:04 musicstream volumio[1041]: info: [1729853944744] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:04 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:04 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:04 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:04 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:04 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:04 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:04 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:05 musicstream volumio[1041]: info: [1729853945137] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:05 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:05 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:05 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:05 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:05 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:05 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:05 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946117] ControllerPandora::removeTrack Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946123] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=7249938399003032515 at queue index: 1 Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 37 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946168] ControllerPandora::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 18 Oct 25 05:59:06 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":35599,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Love So Soft","artist":"Kelly Clarkson","album":"Meaning of Life","uri":"http://t1-3.p-cdn.us/access/8873969377241491348.mp3?version=5&lid=921182580&token=PUYkLwfU6mN7IbGxqD%2BqmSV%2BNxmSSD0On4cEY7XVOXbdJ2UQ9J3zVPCyKHeUrVSZaQbAaJaIe%2F1j7exZCFQ1yWxYacdM%2F1V%2BaGw0Xlko8sqECuARJd87FKFCprz%2B1o37kqJmiCfiZpcybjtzktOTAWhT42lzFNQ%2B4r78RwW2xoDwzHKIYyZkHoHbrzTo5Eh7tZaiekBd6HoiiATbWR5nak6WSntMFAx4pl%2F8J6FaHhyacx7OXi9GgM1ntmvTy3R1Yr8qkYhUNhMOOfQeNL1IWI1ZlI6uG7MGQHzvVf9%2F%2FB%2FcaQXZo8OG9Nf22EZFYWmbCcTQn4R7C%2ByK7FxjYT6tlA%3D%3D","trackType":"mp3"} Oct 25 05:59:06 musicstream volumio[1041]: verbose: CURRENT POSITION 18 Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:06 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioNext Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::next Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946186] ControllerPandora::next Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946187] [Pandora] handleMediaButton: User chose "next" function Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946187] ControllerPandora::stop Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::stop Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand stop Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand stop took 5 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::clear Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand clear Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 31 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand clear took 30 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 14 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 12 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 11 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 10 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 8 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 6 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 6 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946226] ControllerPandora::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 18 Oct 25 05:59:06 musicstream volumio[1041]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Love So Soft","name":"Love So Soft","artist":"Kelly Clarkson","album":"Meaning of Life","albumart":"http://mediaserver-cont-sv5-2-v4v6.pandora.com/images/58/a7/c9/6e/7ad74c7c85ac45379678d160/1080W_1080H.jpg","realUri":"http://t1-3.p-cdn.us/access/8873969377241491348.mp3?version=5&lid=921182580&token=PUYkLwfU6mN7IbGxqD%2BqmSV%2BNxmSSD0On4cEY7XVOXbdJ2UQ9J3zVPCyKHeUrVSZaQbAaJaIe%2F1j7exZCFQ1yWxYacdM%2F1V%2BaGw0Xlko8sqECuARJd87FKFCprz%2B1o37kqJmiCfiZpcybjtzktOTAWhT42lzFNQ%2B4r78RwW2xoDwzHKIYyZkHoHbrzTo5Eh7tZaiekBd6HoiiATbWR5nak6WSntMFAx4pl%2F8J6FaHhyacx7OXi9GgM1ntmvTy3R1Yr8qkYhUNhMOOfQeNL1IWI1ZlI6uG7MGQHzvVf9%2F%2FB%2FcaQXZo8OG9Nf22EZFYWmbCcTQn4R7C%2ByK7FxjYT6tlA%3D%3D","isStreaming":true,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://t1-3.p-cdn.us/access/8873969377241491348.mp3?version=5&lid=921182580&token=PUYkLwfU6mN7IbGxqD%2BqmSV%2BNxmSSD0On4cEY7XVOXbdJ2UQ9J3zVPCyKHeUrVSZaQbAaJaIe%2F1j7exZCFQ1yWxYacdM%2F1V%2BaGw0Xlko8sqECuARJd87FKFCprz%2B1o37kqJmiCfiZpcybjtzktOTAWhT42lzFNQ%2B4r78RwW2xoDwzHKIYyZkHoHbrzTo5Eh7tZaiekBd6HoiiATbWR5nak6WSntMFAx4pl%2F8J6FaHhyacx7OXi9GgM1ntmvTy3R1Yr8qkYhUNhMOOfQeNL1IWI1ZlI6uG7MGQHzvVf9%2F%2FB%2FcaQXZo8OG9Nf22EZFYWmbCcTQn4R7C%2ByK7FxjYT6tlA%3D%3D","seek":0,"status":"stop"} Oct 25 05:59:06 musicstream volumio[1041]: verbose: CURRENT POSITION 18 Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService stop Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::play index undefined Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::startPlaybackTimer Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946244] ControllerPandora::clearAddPlayTrack Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::clear Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand clear Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 89ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 88ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 88ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 87ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 86ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 86ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 83ms Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 101ms Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 97 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand clear took 79 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 14ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 13ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 12ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 11ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 8ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 7ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 6ms Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:06 musicstream volumio[1041]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946327] ControllerPandora::checkForExpiredStations Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 136ms Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946328] ControllerPandora::removeTrack Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946328] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946330] ControllerPandora::appendTracksToMpd Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946331] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand addid Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand play Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:06 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 70ms Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand addid took 59 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand play took 59 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 57ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 56ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 54ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 52ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 50ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 48ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 46ms Oct 25 05:59:06 musicstream volumio[1041]: verbose: MPD COMMAND [object Object] Oct 25 05:59:06 musicstream volumio[1041]: verbose: MPD COMMAND [object Object] Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946394] ControllerPandora::pushState Oct 25 05:59:06 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:06 musicstream volumio[1041]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Don't Stop The Music","name":"Don't Stop The Music","artist":"Rihanna","album":"Good Girl Gone Bad","albumart":"http://mediaserver-cont-sv5-2-v4v6.pandora.com/images/a8/5b/1f/38/8d354feba0b2e35348d6475b/1080W_1080H.jpg","realUri":"http://audio-dc6-t1-1-v4v6.pandora.com/access/8216522551309287438.mp3?version=5&lid=921182580&token=PUYkLwfU6mNjzhHwkcn%2FFI3z6Jm3ZuW%2BVZRF3GXO3VJrzbVGwAqKBapm0rzR6y6JTKOloTZTIWOvmriQNHI0AS%2FlZ5zrUrmzcDQluXhZkM%2B4XMyZubyKvbF69NheW6ppAJxbFrYHegCSXTFCkRx%2FIKvEiN9UlIKjDL%2FMtDNnuHjJH9Xc4o%2F2swJIaNtUxwe%2B6rS6DV1Upprf7quOENIstGO9ilnRWZa6NDNHs%2BbHFaY61j8K3yxwacaq3iD3xSTJWzJNYvJEDSTmfXOSflTi7qfNSfW6rkdGQhW1Q%2F9diIi9W09NTJvQBzbhgbw9v3977I9sRRVMMwyNqljlkMhQVA%3D%3D","isStreaming":true,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-dc6-t1-1-v4v6.pandora.com/access/8216522551309287438.mp3?version=5&lid=921182580&token=PUYkLwfU6mNjzhHwkcn%2FFI3z6Jm3ZuW%2BVZRF3GXO3VJrzbVGwAqKBapm0rzR6y6JTKOloTZTIWOvmriQNHI0AS%2FlZ5zrUrmzcDQluXhZkM%2B4XMyZubyKvbF69NheW6ppAJxbFrYHegCSXTFCkRx%2FIKvEiN9UlIKjDL%2FMtDNnuHjJH9Xc4o%2F2swJIaNtUxwe%2B6rS6DV1Upprf7quOENIstGO9ilnRWZa6NDNHs%2BbHFaY61j8K3yxwacaq3iD3xSTJWzJNYvJEDSTmfXOSflTi7qfNSfW6rkdGQhW1Q%2F9diIi9W09NTJvQBzbhgbw9v3977I9sRRVMMwyNqljlkMhQVA%3D%3D","seek":0,"status":"play"} Oct 25 05:59:06 musicstream volumio[1041]: verbose: CURRENT POSITION 19 Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus stop Oct 25 05:59:06 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946395] ControllerPandora::fetchAndAddTracks Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946395] ControllerPandora::getStationTracks Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946396] [Pandora] PandoraHandler::getSongMaxDiff: 9 Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946396] ControllerPandora::fetchAndAddTracks::getSqInfo Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946396] ControllerPandora::getStationTracks Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946397] [Pandora] fetchAndAddTracks: diff1: 9 sQPos1: 18 Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946397] [Pandora] fetchAndAddTracks: Fetching tracks Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946397] ControllerPandora::PandoraHandler::fillStationData Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 70ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 60ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 58ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 57ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 55ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 54ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 53ms Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: Oct 25 05:59:06 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:06 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 26ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 20ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 19ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 14ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 12ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 10ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 8ms Oct 25 05:59:06 musicstream volumio[1041]: info: ------------------------------ 7ms Oct 25 05:59:06 musicstream volumio[1041]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 25 05:59:06 musicstream kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 25 05:59:06 musicstream volumio[1041]: info: camilladsp spawned new process with pid 13961, instance 3, run: true Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946834] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist Oct 25 05:59:06 musicstream volumio[1041]: info: [1729853946847] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:06 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:06 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:06 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:06 musicstream kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 25 05:59:06 musicstream volumio[1041]: info: camilladsp spawned new process with pid 13968, instance 1, run: true Oct 25 05:59:06 musicstream volumio[1041]: info: camilladsp spawned new process with pid 13975, instance 2, run: true Oct 25 05:59:07 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:07 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947438] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved ... Ready For It? Radio playlist Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947439] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947440] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::addQueueItems Oct 25 05:59:07 musicstream volumio[1041]: info: Preload queue cleared Oct 25 05:59:07 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=6485984188216224523 Oct 25 05:59:07 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=6485984188216224523 in service pandora Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947442] ControllerPandora::explodeUri Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=2633848045884435410 Oct 25 05:59:07 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=2633848045884435410 in service pandora Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947444] ControllerPandora::explodeUri Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=1359398021237066087 Oct 25 05:59:07 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=1359398021237066087 in service pandora Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947446] ControllerPandora::explodeUri Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=1658243676994933652 Oct 25 05:59:07 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=1658243676994933652 in service pandora Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947448] ControllerPandora::explodeUri Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::updateTrackBlock Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrackBlock Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947482] ControllerPandora::getStationTracks Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947483] [Pandora] PandoraHandler::getSongMaxDiff: 13 Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947484] ControllerPandora::fetchAndAddTracks::getSqInfo Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947484] ControllerPandora::getStationTracks Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947485] [Pandora] fetchAndAddTracks: diff2 > 0: 13 sQPos2: 18 Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947486] ControllerPandora::removeOldTrackBlock Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947486] ControllerPandora::removeStationTracks Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947486] ControllerPandora::getStationTracks Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947488] [Pandora] removeStationTracks: Removing 13 tracks from queue Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947490] ControllerPandora::pandoraListener Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 83 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 83 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 81 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 80 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 80 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 78 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 77 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 75 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 73 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: Oct 25 05:59:07 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 37 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 29 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 29 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 29 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 26 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 25 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 23 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 21 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 20 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 18 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 16 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947643] ControllerPandora::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Don't Stop The Music","artist":"Rihanna","album":"Good Girl Gone Bad","uri":"http://audio-dc6-t1-1-v4v6.pandora.com/access/8216522551309287438.mp3?version=5&lid=921182580&token=PUYkLwfU6mNjzhHwkcn%2FFI3z6Jm3ZuW%2BVZRF3GXO3VJrzbVGwAqKBapm0rzR6y6JTKOloTZTIWOvmriQNHI0AS%2FlZ5zrUrmzcDQluXhZkM%2B4XMyZubyKvbF69NheW6ppAJxbFrYHegCSXTFCkRx%2FIKvEiN9UlIKjDL%2FMtDNnuHjJH9Xc4o%2F2swJIaNtUxwe%2B6rS6DV1Upprf7quOENIstGO9ilnRWZa6NDNHs%2BbHFaY61j8K3yxwacaq3iD3xSTJWzJNYvJEDSTmfXOSflTi7qfNSfW6rkdGQhW1Q%2F9diIi9W09NTJvQBzbhgbw9v3977I9sRRVMMwyNqljlkMhQVA%3D%3D","trackType":"mp3"} Oct 25 05:59:07 musicstream volumio[1041]: verbose: CURRENT POSITION 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:07 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 185ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 184ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 182ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 180ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 178ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 176ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 174ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 172ms Oct 25 05:59:07 musicstream volumio[1041]: info: [1729853947686] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 63 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 56 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 55 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 54 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 52 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 51 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand status took 7 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:07 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 142ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 122ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 120ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 117ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 115ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 114ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 111ms Oct 25 05:59:07 musicstream volumio[1041]: info: ------------------------------ 109ms Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:07 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:07 musicstream volumio[1041]: info: CoreCommandRouter::volumioGetQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CoreStateMachine::getQueue Oct 25 05:59:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:07 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:07 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 92 milliseconds Oct 25 05:59:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:07 musicstream volumio[1041]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 25 05:59:09 musicstream volumio[1041]: info: [1729853949748] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:09 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:09 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:09 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:09 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:09 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:09 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:09 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:10 musicstream volumio[1041]: info: [1729853950141] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:10 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:10 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:10 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:10 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:10 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:10 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:10 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:10 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:10 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:11 musicstream volumio[1041]: info: [1729853951852] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:11 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:11 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:11 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:11 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:11 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:11 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:11 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:12 musicstream volumio[1041]: info: [1729853952793] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:12 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:12 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:12 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:12 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:12 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:12 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:12 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:13 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:13 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:14 musicstream volumio[1041]: info: [1729853954752] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:14 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:14 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:14 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:14 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:14 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:14 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:14 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:15 musicstream volumio[1041]: info: [1729853955145] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:15 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:15 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:15 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:15 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:15 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:15 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:15 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:16 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:16 musicstream volumio[1041]: info: [1729853956116] ControllerPandora::removeTrack Oct 25 05:59:16 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:16 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:16 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:16 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:16 musicstream volumio[1041]: info: [1729853956123] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=9073810838404396018 at queue index: 1 Oct 25 05:59:16 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:16 musicstream volumio[1041]: info: sendMpdCommand status took 56 milliseconds Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:16 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:16 musicstream volumio[1041]: info: [1729853956185] ControllerPandora::pushState Oct 25 05:59:16 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:16 musicstream volumio[1041]: info: CorePlayQueue::getTrack 18 Oct 25 05:59:16 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":28537,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Don't Stop The Music","artist":"Rihanna","album":"Good Girl Gone Bad","uri":"http://audio-dc6-t1-1-v4v6.pandora.com/access/8216522551309287438.mp3?version=5&lid=921182580&token=PUYkLwfU6mNjzhHwkcn%2FFI3z6Jm3ZuW%2BVZRF3GXO3VJrzbVGwAqKBapm0rzR6y6JTKOloTZTIWOvmriQNHI0AS%2FlZ5zrUrmzcDQluXhZkM%2B4XMyZubyKvbF69NheW6ppAJxbFrYHegCSXTFCkRx%2FIKvEiN9UlIKjDL%2FMtDNnuHjJH9Xc4o%2F2swJIaNtUxwe%2B6rS6DV1Upprf7quOENIstGO9ilnRWZa6NDNHs%2BbHFaY61j8K3yxwacaq3iD3xSTJWzJNYvJEDSTmfXOSflTi7qfNSfW6rkdGQhW1Q%2F9diIi9W09NTJvQBzbhgbw9v3977I9sRRVMMwyNqljlkMhQVA%3D%3D","trackType":"mp3"} Oct 25 05:59:16 musicstream volumio[1041]: verbose: CURRENT POSITION 18 Oct 25 05:59:16 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:16 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:16 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:16 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:16 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:16 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:16 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:16 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:16 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:16 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:16 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:16 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:16 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:16 musicstream volumio[1041]: info: [1729853956857] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:16 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:16 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:16 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:16 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:17 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:17 musicstream volumio[1041]: info: [1729853957489] ControllerPandora::removeTrack Oct 25 05:59:17 musicstream volumio[1041]: info: [1729853957489] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=9073810838404396018 at queue index: -1 Oct 25 05:59:17 musicstream volumio[1041]: info: [1729853957797] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:17 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:17 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:17 musicstream volumio[1041]: info: sendMpdCommand status took 6 milliseconds Oct 25 05:59:17 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:17 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:17 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:17 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:19 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:19 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:19 musicstream volumio[1041]: info: [1729853959757] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:19 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:19 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:19 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:19 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:19 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:19 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:19 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960149] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioNext Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::next Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960531] ControllerPandora::next Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960531] [Pandora] handleMediaButton: User chose "next" function Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960531] ControllerPandora::stop Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::stop Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand stop Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand stop took 7 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::clear Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand clear Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand clear took 2 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960542] ControllerPandora::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 18 Oct 25 05:59:20 musicstream volumio[1041]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Don't Stop The Music","name":"Don't Stop The Music","artist":"Rihanna","album":"Good Girl Gone Bad","albumart":"http://mediaserver-cont-sv5-2-v4v6.pandora.com/images/a8/5b/1f/38/8d354feba0b2e35348d6475b/1080W_1080H.jpg","realUri":"http://audio-dc6-t1-1-v4v6.pandora.com/access/8216522551309287438.mp3?version=5&lid=921182580&token=PUYkLwfU6mNjzhHwkcn%2FFI3z6Jm3ZuW%2BVZRF3GXO3VJrzbVGwAqKBapm0rzR6y6JTKOloTZTIWOvmriQNHI0AS%2FlZ5zrUrmzcDQluXhZkM%2B4XMyZubyKvbF69NheW6ppAJxbFrYHegCSXTFCkRx%2FIKvEiN9UlIKjDL%2FMtDNnuHjJH9Xc4o%2F2swJIaNtUxwe%2B6rS6DV1Upprf7quOENIstGO9ilnRWZa6NDNHs%2BbHFaY61j8K3yxwacaq3iD3xSTJWzJNYvJEDSTmfXOSflTi7qfNSfW6rkdGQhW1Q%2F9diIi9W09NTJvQBzbhgbw9v3977I9sRRVMMwyNqljlkMhQVA%3D%3D","isStreaming":true,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-dc6-t1-1-v4v6.pandora.com/access/8216522551309287438.mp3?version=5&lid=921182580&token=PUYkLwfU6mNjzhHwkcn%2FFI3z6Jm3ZuW%2BVZRF3GXO3VJrzbVGwAqKBapm0rzR6y6JTKOloTZTIWOvmriQNHI0AS%2FlZ5zrUrmzcDQluXhZkM%2B4XMyZubyKvbF69NheW6ppAJxbFrYHegCSXTFCkRx%2FIKvEiN9UlIKjDL%2FMtDNnuHjJH9Xc4o%2F2swJIaNtUxwe%2B6rS6DV1Upprf7quOENIstGO9ilnRWZa6NDNHs%2BbHFaY61j8K3yxwacaq3iD3xSTJWzJNYvJEDSTmfXOSflTi7qfNSfW6rkdGQhW1Q%2F9diIi9W09NTJvQBzbhgbw9v3977I9sRRVMMwyNqljlkMhQVA%3D%3D","seek":0,"status":"stop"} Oct 25 05:59:20 musicstream volumio[1041]: verbose: CURRENT POSITION 18 Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService stop Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::play index undefined Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::startPlaybackTimer Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960561] ControllerPandora::clearAddPlayTrack Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::clear Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand clear Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:20 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 47ms Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 47 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand clear took 26 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 15 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 15 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 13 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 13 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 12 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 11 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand status took 9 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:20 musicstream volumio[1041]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960596] ControllerPandora::checkForExpiredStations Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 112ms Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960652] ControllerPandora::removeTrack Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960653] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 156ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 156ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 157ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 160ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 160ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 160ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 161ms Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960745] ControllerPandora::appendTracksToMpd Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960746] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand addid Oct 25 05:59:20 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand play Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:20 musicstream volumio[1041]: error: updateQueue error: null Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 279ms Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand addid took 115 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: sendMpdCommand play took 113 milliseconds Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 112ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 108ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 106ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 102ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 97ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 92ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 89ms Oct 25 05:59:20 musicstream volumio[1041]: verbose: MPD COMMAND [object Object] Oct 25 05:59:20 musicstream volumio[1041]: verbose: MPD COMMAND [object Object] Oct 25 05:59:20 musicstream volumio[1041]: verbose: MPD COMMAND [object Object] Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960869] ControllerPandora::pushState Oct 25 05:59:20 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:20 musicstream volumio[1041]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Come & Get It","name":"Come & Get It","artist":"Selena Gomez","album":"For You","albumart":"http://cont-2.p-cdn.us/images/46/c9/b0/a5/d6a4454e9ef91b56ecf118ed/1080W_1080H.jpg","realUri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","isStreaming":true,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","seek":0,"status":"play"} Oct 25 05:59:20 musicstream volumio[1041]: verbose: CURRENT POSITION 19 Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus stop Oct 25 05:59:20 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960870] ControllerPandora::fetchAndAddTracks Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960870] ControllerPandora::getStationTracks Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960870] [Pandora] PandoraHandler::getSongMaxDiff: 12 Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960871] ControllerPandora::fetchAndAddTracks::getSqInfo Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960871] ControllerPandora::getStationTracks Oct 25 05:59:20 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960872] [Pandora] fetchAndAddTracks: diff1: 12 sQPos1: 18 Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960872] [Pandora] fetchAndAddTracks: Fetching tracks Oct 25 05:59:20 musicstream volumio[1041]: info: [1729853960872] ControllerPandora::PandoraHandler::fillStationData Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 75ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 58ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 57ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 55ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 54ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 52ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 51ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 50ms Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: Oct 25 05:59:20 musicstream volumio[1041]: ---------------------------- MPD announces system playlist update Oct 25 05:59:20 musicstream volumio[1041]: info: Ignoring MPD Status Update Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 26ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 17ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 16ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 15ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 13ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 12ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 8ms Oct 25 05:59:20 musicstream volumio[1041]: info: ------------------------------ 6ms Oct 25 05:59:20 musicstream volumio[1041]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 25 05:59:21 musicstream volumio[1041]: info: camilladsp spawned new process with pid 14028, instance 2, run: true Oct 25 05:59:21 musicstream kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 25 05:59:21 musicstream volumio[1041]: info: camilladsp spawned new process with pid 14035, instance 1, run: true Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961302] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist Oct 25 05:59:21 musicstream volumio[1041]: info: camilladsp spawned new process with pid 14042, instance 3, run: true Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961460] ControllerPandora::pandoraListener Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 36 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 35 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 33 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 33 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 35 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 35 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 34 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 33 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 31 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: Oct 25 05:59:21 musicstream volumio[1041]: ---------------------------- MPD announces state update: player Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 21 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 11 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 10 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 9 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 8 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 8 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 7 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 6 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961528] ControllerPandora::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:21 musicstream volumio[1041]: verbose: CURRENT POSITION 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:21 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 129ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 127ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 126ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 126ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 125ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 124ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 123ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 123ms Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 78 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 77 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 78 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 78 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 79 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 80 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 80 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 81 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::pushState Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrack 19 Oct 25 05:59:21 musicstream volumio[1041]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 123ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 111ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 110ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 109ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 108ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 107ms Oct 25 05:59:21 musicstream volumio[1041]: info: ------------------------------ 106ms Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::volumioGetQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:21 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:21 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:21 musicstream volumio[1041]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961870] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved ... Ready For It? Radio playlist Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961870] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961871] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::addQueueItems Oct 25 05:59:21 musicstream volumio[1041]: info: Preload queue cleared Oct 25 05:59:21 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=7313461908708963811 Oct 25 05:59:21 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=7313461908708963811 in service pandora Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961873] ControllerPandora::explodeUri Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=6146570782704839574 Oct 25 05:59:21 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=6146570782704839574 in service pandora Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961875] ControllerPandora::explodeUri Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=4326654190976736056 Oct 25 05:59:21 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=4326654190976736056 in service pandora Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961876] ControllerPandora::explodeUri Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: Adding Item to queue: /pandora/stationToken=3841158419610870132trackId=8997840753999341227 Oct 25 05:59:21 musicstream volumio[1041]: info: Exploding uri /pandora/stationToken=3841158419610870132trackId=8997840753999341227 in service pandora Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961877] ControllerPandora::explodeUri Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CoreStateMachine::updateTrackBlock Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getTrackBlock Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961916] ControllerPandora::getStationTracks Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961916] [Pandora] PandoraHandler::getSongMaxDiff: 16 Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961916] ControllerPandora::fetchAndAddTracks::getSqInfo Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961916] ControllerPandora::getStationTracks Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961917] [Pandora] fetchAndAddTracks: diff2 > 0: 16 sQPos2: 18 Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961917] ControllerPandora::removeOldTrackBlock Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961917] ControllerPandora::removeStationTracks Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961917] ControllerPandora::getStationTracks Oct 25 05:59:21 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961918] [Pandora] removeStationTracks: Removing 16 tracks from queue Oct 25 05:59:21 musicstream volumio[1041]: info: [1729853961919] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:21 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand status took 28 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:21 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 25 05:59:21 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:22 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:22 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:22 musicstream volumio[1041]: info: [1729853962807] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:22 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:22 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:22 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:22 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:22 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:22 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:22 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:24 musicstream volumio[1041]: info: [1729853964762] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:24 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:24 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:24 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:24 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:24 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:24 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:24 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:25 musicstream volumio[1041]: info: [1729853965153] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:25 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:25 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:25 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:25 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:25 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:25 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:25 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:25 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:25 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:26 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:26 musicstream volumio[1041]: info: [1729853966117] ControllerPandora::removeTrack Oct 25 05:59:26 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:26 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:26 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:26 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:26 musicstream volumio[1041]: info: [1729853966126] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=7076160236366364912 at queue index: 1 Oct 25 05:59:26 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:26 musicstream volumio[1041]: info: sendMpdCommand status took 49 milliseconds Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:26 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:26 musicstream volumio[1041]: info: [1729853966183] ControllerPandora::pushState Oct 25 05:59:26 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:26 musicstream volumio[1041]: info: CorePlayQueue::getTrack 18 Oct 25 05:59:26 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":16559,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:26 musicstream volumio[1041]: verbose: CURRENT POSITION 18 Oct 25 05:59:26 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:26 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:26 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:26 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:26 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:26 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:26 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:26 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:26 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:26 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:26 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:26 musicstream volumio[1041]: info: [1729853966956] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:26 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:26 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:26 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:26 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:27 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:27 musicstream volumio[1041]: info: [1729853967487] ControllerPandora::removeTrack Oct 25 05:59:27 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:27 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 4 Oct 25 05:59:27 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:27 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:27 musicstream volumio[1041]: info: [1729853967495] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=7076160236366364912 at queue index: 4 Oct 25 05:59:27 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:27 musicstream volumio[1041]: info: sendMpdCommand status took 34 milliseconds Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:27 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:27 musicstream volumio[1041]: info: [1729853967534] ControllerPandora::pushState Oct 25 05:59:27 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:27 musicstream volumio[1041]: info: CorePlayQueue::getTrack 17 Oct 25 05:59:27 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":20811,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:27 musicstream volumio[1041]: verbose: CURRENT POSITION 17 Oct 25 05:59:27 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:27 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:27 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:27 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:27 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:27 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:27 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:27 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:27 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:27 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:27 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:27 musicstream volumio[1041]: info: [1729853967811] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:27 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:27 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:27 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:27 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:28 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:28 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:29 musicstream volumio[1041]: info: [1729853969766] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:29 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:29 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:29 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:29 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:29 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:29 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 25 05:59:29 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:30 musicstream volumio[1041]: info: [1729853970157] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:30 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:30 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:30 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:30 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:30 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:30 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:30 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:31 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:31 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:31 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:31 musicstream volumio[1041]: info: [1729853971918] ControllerPandora::removeTrack Oct 25 05:59:31 musicstream volumio[1041]: info: [1729853971918] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=7076160236366364912 at queue index: -1 Oct 25 05:59:31 musicstream volumio[1041]: info: [1729853971962] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:31 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:31 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:31 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:31 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:31 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:31 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:31 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:32 musicstream volumio[1041]: info: [1729853972817] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:32 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:32 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:32 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:32 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:32 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:32 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:32 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:34 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:34 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:34 musicstream volumio[1041]: info: [1729853974770] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:34 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:34 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:34 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:34 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:34 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:34 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:34 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:35 musicstream volumio[1041]: info: [1729853975161] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:35 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:35 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:35 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:35 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:35 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:35 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 05:59:35 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:35 musicstream volumio[1041]: info: CoreCommandRouter::volumioGetState Oct 25 05:59:36 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:36 musicstream volumio[1041]: info: [1729853976116] ControllerPandora::removeTrack Oct 25 05:59:36 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:36 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:36 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:36 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:36 musicstream volumio[1041]: info: [1729853976126] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=359718205456840930 at queue index: 1 Oct 25 05:59:36 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:36 musicstream volumio[1041]: info: sendMpdCommand status took 45 milliseconds Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:36 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:36 musicstream volumio[1041]: info: [1729853976178] ControllerPandora::pushState Oct 25 05:59:36 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:36 musicstream volumio[1041]: info: CorePlayQueue::getTrack 16 Oct 25 05:59:36 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":46434,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:36 musicstream volumio[1041]: verbose: CURRENT POSITION 16 Oct 25 05:59:36 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:36 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:36 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:36 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:36 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:36 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:36 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:36 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:36 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:36 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:36 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:36 musicstream volumio[1041]: info: [1729853976966] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:36 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:36 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:36 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:36 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:37 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:37 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:37 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:37 musicstream volumio[1041]: info: [1729853977488] ControllerPandora::removeTrack Oct 25 05:59:37 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:37 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 3 Oct 25 05:59:37 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:37 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:37 musicstream volumio[1041]: info: [1729853977497] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=359718205456840930 at queue index: 3 Oct 25 05:59:37 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:37 musicstream volumio[1041]: info: sendMpdCommand status took 41 milliseconds Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:37 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:37 musicstream volumio[1041]: info: [1729853977545] ControllerPandora::pushState Oct 25 05:59:37 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:37 musicstream volumio[1041]: info: CorePlayQueue::getTrack 15 Oct 25 05:59:37 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":50685,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:37 musicstream volumio[1041]: verbose: CURRENT POSITION 15 Oct 25 05:59:37 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:37 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:37 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:37 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:37 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:37 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:37 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:37 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:37 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:37 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:37 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:37 musicstream volumio[1041]: info: [1729853977821] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:37 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:37 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:37 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:37 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:39 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 25 05:59:39 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 25 05:59:39 musicstream volumio[1041]: info: [1729853979776] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:39 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:39 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:39 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:39 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:39 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:39 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:39 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:40 musicstream volumio[1041]: info: [1729853980169] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:40 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:40 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:40 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:40 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:40 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:40 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 25 05:59:40 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:40 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:40 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:41 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:41 musicstream volumio[1041]: info: [1729853981918] ControllerPandora::removeTrack Oct 25 05:59:41 musicstream volumio[1041]: info: [1729853981918] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=359718205456840930 at queue index: -1 Oct 25 05:59:41 musicstream volumio[1041]: info: [1729853981973] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:41 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:41 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:41 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:41 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:41 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:41 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 25 05:59:41 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:42 musicstream volumio[1041]: info: [1729853982828] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:42 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:42 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:42 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:42 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:42 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:42 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:42 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:43 musicstream volumio[1041]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 05:59:43 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:43 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:44 musicstream volumio[1041]: info: [1729853984782] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:44 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:44 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:44 musicstream volumio[1041]: info: sendMpdCommand status took 6 milliseconds Oct 25 05:59:44 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:44 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:44 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:44 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:45 musicstream volumio[1041]: info: [1729853985173] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:45 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:45 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:45 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:45 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:45 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:45 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 25 05:59:45 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:46 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:46 musicstream volumio[1041]: info: [1729853986116] ControllerPandora::removeTrack Oct 25 05:59:46 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:46 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:46 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:46 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:46 musicstream volumio[1041]: info: [1729853986128] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=5130021343517166764 at queue index: 1 Oct 25 05:59:46 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:46 musicstream volumio[1041]: info: sendMpdCommand status took 48 milliseconds Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:46 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:46 musicstream volumio[1041]: info: [1729853986186] ControllerPandora::pushState Oct 25 05:59:46 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:46 musicstream volumio[1041]: info: CorePlayQueue::getTrack 14 Oct 25 05:59:46 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":76674,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:46 musicstream volumio[1041]: verbose: CURRENT POSITION 14 Oct 25 05:59:46 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:46 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:46 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:46 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:46 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:46 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:46 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:46 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:46 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:46 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:46 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:46 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:46 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:46 musicstream volumio[1041]: info: [1729853986977] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:46 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:46 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:46 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:46 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:47 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:47 musicstream volumio[1041]: info: [1729853987488] ControllerPandora::removeTrack Oct 25 05:59:47 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:47 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 2 Oct 25 05:59:47 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:47 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:47 musicstream volumio[1041]: info: [1729853987493] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=5130021343517166764 at queue index: 2 Oct 25 05:59:47 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:47 musicstream volumio[1041]: info: sendMpdCommand status took 32 milliseconds Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:47 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:47 musicstream volumio[1041]: info: [1729853987528] ControllerPandora::pushState Oct 25 05:59:47 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:47 musicstream volumio[1041]: info: CorePlayQueue::getTrack 13 Oct 25 05:59:47 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":80674,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:47 musicstream volumio[1041]: verbose: CURRENT POSITION 13 Oct 25 05:59:47 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:47 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:47 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:47 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:47 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:47 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:47 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:47 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:47 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:47 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:47 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:47 musicstream volumio[1041]: info: [1729853987832] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:47 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:47 musicstream volumio[1041]: info: sendMpdCommand status took 4 milliseconds Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:47 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:47 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:49 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:49 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:49 musicstream volumio[1041]: info: CALLMETHOD: audio_interface fusiondsp choosedsp [object Object] Oct 25 05:59:49 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , choosedsp Oct 25 05:59:49 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:49 musicstream volumio[1041]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 05:59:49 musicstream volumio[1041]: info: CoreCommandRouter::Close All Modals sent Oct 25 05:59:49 musicstream volumio[1041]: info: [1729853989951] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:49 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:49 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:50 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:50 musicstream volumio[1041]: info: sendMpdCommand status took 227 milliseconds Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:50 musicstream volumio[1041]: info: [1729853990182] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:50 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:50 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 25 05:59:50 musicstream volumio[1041]: info: sendMpdCommand status took 12 milliseconds Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:50 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 253 milliseconds Oct 25 05:59:50 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:50 musicstream volumio[1041]: info: CALLMETHOD: audio_interface fusiondsp choosedsp [object Object] Oct 25 05:59:50 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , choosedsp Oct 25 05:59:50 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:50 musicstream volumio[1041]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 05:59:50 musicstream volumio[1041]: info: CoreCommandRouter::Close All Modals sent Oct 25 05:59:51 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:51 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:51 musicstream volumio[1041]: info: [1729853991918] ControllerPandora::removeTrack Oct 25 05:59:51 musicstream volumio[1041]: info: [1729853991918] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=5130021343517166764 at queue index: -1 Oct 25 05:59:51 musicstream volumio[1041]: info: [1729853991980] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:51 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:51 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:51 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:51 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:51 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:51 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:51 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:52 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:52 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:52 musicstream volumio[1041]: info: [1729853992840] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:52 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:52 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:52 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:52 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:52 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:52 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:52 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:55 musicstream volumio[1041]: info: [1729853995198] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:55 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:55 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:55 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:55 musicstream volumio[1041]: info: [1729853995451] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:55 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:55 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:55 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 05:59:55 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:55 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:55 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:55 musicstream volumio[1041]: info: CALLMETHOD: audio_interface fusiondsp choosedsp [object Object] Oct 25 05:59:55 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , choosedsp Oct 25 05:59:55 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:55 musicstream volumio[1041]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 05:59:55 musicstream volumio[1041]: info: CoreCommandRouter::Close All Modals sent Oct 25 05:59:56 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 05:59:56 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:56 musicstream volumio[1041]: info: [1729853996183] ControllerPandora::removeTrack Oct 25 05:59:56 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:56 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:56 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:56 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:56 musicstream volumio[1041]: info: [1729853996193] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=6267845907823559955 at queue index: 1 Oct 25 05:59:56 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:56 musicstream volumio[1041]: info: sendMpdCommand status took 281 milliseconds Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:56 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:56 musicstream volumio[1041]: info: [1729853996483] ControllerPandora::pushState Oct 25 05:59:56 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:56 musicstream volumio[1041]: info: CorePlayQueue::getTrack 12 Oct 25 05:59:56 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":106674,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:56 musicstream volumio[1041]: verbose: CURRENT POSITION 12 Oct 25 05:59:56 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:56 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:56 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:56 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:56 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:56 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:56 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:56 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:56 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:56 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:56 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:56 musicstream volumio[1041]: info: [1729853996986] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:56 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:56 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:56 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 25 05:59:56 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:57 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 05:59:57 musicstream volumio[1041]: info: [1729853997488] ControllerPandora::removeTrack Oct 25 05:59:57 musicstream volumio[1041]: info: CoreStateMachine::removeQueueItem Oct 25 05:59:57 musicstream volumio[1041]: info: CorePlayQueue::removeQueueItem 1 Oct 25 05:59:57 musicstream volumio[1041]: info: CorePlayQueue::saveQueue Oct 25 05:59:57 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushQueue Oct 25 05:59:57 musicstream volumio[1041]: info: [1729853997493] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=3841158419610870132trackId=6267845907823559955 at queue index: 1 Oct 25 05:59:57 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:57 musicstream volumio[1041]: info: sendMpdCommand status took 34 milliseconds Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:57 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:57 musicstream volumio[1041]: info: [1729853997532] ControllerPandora::pushState Oct 25 05:59:57 musicstream volumio[1041]: info: CoreCommandRouter::servicePushState Oct 25 05:59:57 musicstream volumio[1041]: info: CorePlayQueue::getTrack 11 Oct 25 05:59:57 musicstream volumio[1041]: verbose: STATE SERVICE {"status":"play","position":0,"seek":110297,"duration":231,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Come & Get It","artist":"Selena Gomez","album":"For You","uri":"http://audio-sv5-t1-1-v4v6.pandora.com/access/5955203957167671160.mp3?version=5&lid=921182580&token=PUYkLwfU6mMCC9zolJjOJlQXeSochwjoBWk7qjx0CD2iKAbD%2Fm7Y5TsqkZk2OfL3sDCLIvjl2xjvj163dm2ewIWOKMKv7a6BhobsLQaZrAs%2BcMvmlC8IkJ%2Fl%2B2Qs4K7%2B2039G%2FIbgvX5faqabdeGr5orIygj0OxNCsgtQw3am5bTrlHcipjtltMLHo3rZXLjZRgo2ZKPGdaq02y6PHuo0WZo30RfbGvOOoJCCbn9cFUFry3SMXMvwqZTJyEJa6tH47kT7m%2FSX4dvX2gHCxQEjUVCwoUvmGxTfzoE75Q4PiHyc%2B4QOBm5bdVMTMvAvloGSt57FGLL28elVJ1CDJXJDw%3D%3D","trackType":"mp3"} Oct 25 05:59:57 musicstream volumio[1041]: verbose: CURRENT POSITION 11 Oct 25 05:59:57 musicstream volumio[1041]: info: CoreStateMachine::syncState stateService play Oct 25 05:59:57 musicstream volumio[1041]: info: CoreStateMachine::syncState currentStatus play Oct 25 05:59:57 musicstream volumio[1041]: info: Received an update from plugin. extracting info from payload Oct 25 05:59:57 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:57 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 05:59:57 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:57 musicstream volumio[1041]: info: CoreStateMachine::pushState Oct 25 05:59:57 musicstream volumio[1041]: info: CoreCommandRouter::volumioPushState Oct 25 05:59:57 musicstream volumio[1041]: info: CoreStateMachine::setConsumeUpdateService pandora Oct 25 05:59:57 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:57 musicstream volumio[1041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 25 05:59:57 musicstream volumio[1041]: info: [1729853997844] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 05:59:57 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 05:59:57 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 05:59:57 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 05:59:57 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 05:59:58 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 05:59:58 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 05:59:59 musicstream volumio[1041]: info: CALLMETHOD: audio_interface fusiondsp disableeffect Oct 25 05:59:59 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , disableeffect Oct 25 05:59:59 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 05:59:59 musicstream volumio[1041]: info: FusionDsp - Effects disabled Oct 25 05:59:59 musicstream volumio[1041]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 05:59:59 musicstream volumio[1041]: info: CoreCommandRouter::Close All Modals sent Oct 25 05:59:59 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 06:00:00 musicstream volumio[1041]: info: [1729854000284] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:00 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:00 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:00 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:00 musicstream volumio[1041]: info: [1729854000458] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:00 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:00 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:00 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:00 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:00 musicstream volumio[1041]: info: CALLMETHOD: audio_interface fusiondsp saveparameq [object Object] Oct 25 06:00:00 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , saveparameq Oct 25 06:00:01 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:01 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:01 musicstream volumio[1041]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 25 06:00:01 musicstream volumio[1041]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 25 06:00:01 musicstream volumio[1041]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 25 06:00:01 musicstream volumio[1041]: info: CoreCommandRouter::Close All Modals sent Oct 25 06:00:01 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 06:00:01 musicstream volumio[1041]: info: [1729854001921] ControllerPandora::removeTrack Oct 25 06:00:01 musicstream volumio[1041]: info: [1729854001921] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=6267845907823559955 at queue index: -1 Oct 25 06:00:02 musicstream volumio[1041]: info: [1729854002117] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:02 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:02 musicstream volumio[1041]: info: sendMpdCommand status took 234 milliseconds Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:02 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:02 musicstream volumio[1041]: info: [1729854002853] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:02 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:02 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:02 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:02 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:04 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:04 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:05 musicstream volumio[1041]: info: [1729854005293] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:05 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:05 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:05 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:05 musicstream volumio[1041]: info: [1729854005462] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:05 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:05 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:05 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:05 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:06 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 06:00:06 musicstream volumio[1041]: info: [1729854006118] ControllerPandora::removeTrack Oct 25 06:00:06 musicstream volumio[1041]: info: [1729854006119] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=7076160236366364912 at queue index: -1 Oct 25 06:00:07 musicstream volumio[1041]: info: [1729854007357] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:07 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:07 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 06:00:07 musicstream volumio[1041]: info: [1729854007487] ControllerPandora::removeTrack Oct 25 06:00:07 musicstream volumio[1041]: info: [1729854007487] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=7076160236366364912 at queue index: -1 Oct 25 06:00:07 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:07 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:07 musicstream volumio[1041]: info: [1729854007859] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:07 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:07 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:07 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:07 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:10 musicstream volumio[1041]: info: [1729854010297] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:10 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:10 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:10 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:10 musicstream volumio[1041]: info: [1729854010471] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:10 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:10 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:10 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 06:00:10 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:10 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:10 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:11 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 06:00:11 musicstream volumio[1041]: info: [1729854011919] ControllerPandora::removeTrack Oct 25 06:00:11 musicstream volumio[1041]: info: [1729854011920] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=7076160236366364912 at queue index: -1 Oct 25 06:00:12 musicstream volumio[1041]: info: [1729854012361] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:12 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:12 musicstream volumio[1041]: info: sendMpdCommand status took 2 milliseconds Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:12 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:12 musicstream volumio[1041]: info: [1729854012867] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:12 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:12 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:12 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 06:00:12 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:12 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 25 06:00:12 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 25 06:00:13 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:13 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:15 musicstream volumio[1041]: info: [1729854015302] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:15 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:15 musicstream volumio[1041]: info: sendMpdCommand status took 3 milliseconds Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:15 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:15 musicstream volumio[1041]: info: [1729854015478] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:15 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:15 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:15 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:15 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:16 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 06:00:16 musicstream volumio[1041]: info: [1729854016117] ControllerPandora::removeTrack Oct 25 06:00:16 musicstream volumio[1041]: info: [1729854016117] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=359718205456840930 at queue index: -1 Oct 25 06:00:16 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:16 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:17 musicstream volumio[1041]: info: [1729854017368] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:17 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:17 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:17 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:17 musicstream volumio[1041]: info: CorePlayQueue::getQueue Oct 25 06:00:17 musicstream volumio[1041]: info: [1729854017488] ControllerPandora::removeTrack Oct 25 06:00:17 musicstream volumio[1041]: info: [1729854017488] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=3841158419610870132trackId=359718205456840930 at queue index: -1 Oct 25 06:00:17 musicstream volumio[1041]: info: [1729854017874] ControllerPandora::StreamLifeChecker::heartMonitor Oct 25 06:00:17 musicstream volumio[1041]: info: ControllerMpd::getState Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand status Oct 25 06:00:17 musicstream volumio[1041]: info: sendMpdCommand status took 1 milliseconds Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::parseState Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 25 06:00:17 musicstream volumio[1041]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 25 06:00:17 musicstream volumio[1041]: verbose: ControllerMpd::parseTrackInfo Oct 25 06:00:18 musicstream volumio[1041]: info: Starting Uninstall of plugin audio_interface - fusiondsp Oct 25 06:00:18 musicstream volumio[1041]: info: Uninstalling plugin fusiondsp Oct 25 06:00:18 musicstream volumio[1041]: info: FusionDsp - Stopping FusionDsp service Oct 25 06:00:18 musicstream volumio[1041]: info: camilladsp stopping service pid 14042... Oct 25 06:00:18 musicstream kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 25 06:00:18 musicstream volumio[1041]: info: camilladsp service terminated, instance 3 Oct 25 06:00:18 musicstream volumio[1041]: info: Disabling plugin fusiondsp Oct 25 06:00:18 musicstream sudo[14238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Oct 25 06:00:18 musicstream sudo[14238]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:18 musicstream volumio[1041]: info: Preparing to generate the ALSA configuration file Oct 25 06:00:18 musicstream systemd[1]: Stopping FusionDsp Daemon... Oct 25 06:00:18 musicstream volumio[13330]: Backend configuration: Oct 25 06:00:18 musicstream volumio[13330]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Oct 25 06:00:18 musicstream volumio[13330]: active_config_txt: null Oct 25 06:00:18 musicstream volumio[13330]: camilla_host: 127.0.0.1 Oct 25 06:00:18 musicstream volumio[13330]: camilla_port: 9876 Oct 25 06:00:18 musicstream volumio[13330]: coeff_dir: /data/INTERNAL/FusionDsp/filters Oct 25 06:00:18 musicstream volumio[13330]: config_dir: /data/configuration/audio_interface/fusiondsp Oct 25 06:00:18 musicstream volumio[13330]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Oct 25 06:00:18 musicstream volumio[13330]: log_file: /tmp/camilladsp.log Oct 25 06:00:18 musicstream volumio[13330]: on_get_active_config: null Oct 25 06:00:18 musicstream volumio[13330]: on_set_active_config: null Oct 25 06:00:18 musicstream volumio[13330]: port: 5011 Oct 25 06:00:18 musicstream volumio[13330]: supported_capture_types: null Oct 25 06:00:18 musicstream volumio[13330]: supported_playback_types: null Oct 25 06:00:18 musicstream volumio[13330]: update_config_symlink: false Oct 25 06:00:18 musicstream volumio[13330]: update_config_txt: false Oct 25 06:00:18 musicstream volumio[13330]: ======== Running on http://0.0.0.0:5011 ======== Oct 25 06:00:18 musicstream volumio[13330]: (Press CTRL+C to quit) Oct 25 06:00:18 musicstream volumio[1041]: info: Asound.conf file written Oct 25 06:00:18 musicstream sudo[14241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 25 06:00:18 musicstream sudo[14241]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:18 musicstream sudo[14241]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:18 musicstream volumio[1041]: info: Output device has changed, restarting MPD Oct 25 06:00:18 musicstream systemd[1]: fusiondsp.service: Succeeded. Oct 25 06:00:18 musicstream systemd[1]: Stopped FusionDsp Daemon. Oct 25 06:00:18 musicstream sudo[14247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 06:00:18 musicstream sudo[14247]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:18 musicstream sudo[14247]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:18 musicstream sudo[14238]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:18 musicstream volumio[1041]: info: Output device has changed, restarting Shairport Sync Oct 25 06:00:18 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:18 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 06:00:18 musicstream sudo[14250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 06:00:18 musicstream sudo[14250]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:18 musicstream systemd[1]: Stopping Music Player Daemon... Oct 25 06:00:18 musicstream volumio[1041]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 06:00:18 musicstream volumio[1041]: info: Checking if uninstall.sh is present Oct 25 06:00:18 musicstream volumio[1041]: info: Executing uninstall.sh Oct 25 06:00:18 musicstream volumio[1041]: info: MPD Permissions set Oct 25 06:00:18 musicstream volumio[1041]: info: FusionDsp - Reporting Fusion DSP Disabled Oct 25 06:00:18 musicstream volumio[1041]: info: Removing fusiondspeq DSP Signal Path Element Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream systemd[1]: mpd.service: Succeeded. Oct 25 06:00:19 musicstream systemd[1]: Stopped Music Player Daemon. Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 06:00:19 musicstream volumio[1041]: info: Starting Shairport Sync Oct 25 06:00:19 musicstream sudo[14257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/uninstall.sh Oct 25 06:00:19 musicstream sudo[14257]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:19 musicstream systemd[1]: Starting Music Player Daemon... Oct 25 06:00:19 musicstream sudo[14267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 25 06:00:19 musicstream sudo[14267]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:19 musicstream systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 25 06:00:19 musicstream sudo[14270]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm /etc/systemd/system/multi-user.target.wants/fusiondsp.service Oct 25 06:00:19 musicstream sudo[14270]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:19 musicstream sudo[14267]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:19 musicstream sudo[14270]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:19 musicstream volumio[1041]: info: Shairport-Sync Started Oct 25 06:00:19 musicstream sudo[14257]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:19 musicstream sudo[14259]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 06:00:19 musicstream sudo[14259]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 06:00:19 musicstream volumio[1041]: info: Uninstall script completed Oct 25 06:00:19 musicstream volumio[1041]: info: Removing plugin fusiondsp from configuration Oct 25 06:00:19 musicstream sudo[14259]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:19 musicstream volumio[1041]: info: Successfully removed fusiondsp configuration files Oct 25 06:00:19 musicstream volumio[1041]: info: Plugin folders cleanup Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning into folder /volumio/app/plugins/ Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category audio_interface Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category miscellanea Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category music_service Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category plugins.json Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category system_controller Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category user_interface Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning into folder /data/plugins/ Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category audio_interface Oct 25 06:00:19 musicstream volumio[1041]: info: Cleaning folder for fusiondsp Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category music_service Oct 25 06:00:19 musicstream volumio[1041]: info: Scanning category user_interface Oct 25 06:00:19 musicstream volumio[1041]: info: Plugin folders cleanup completed Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 25 06:00:19 musicstream volumio[1041]: info: [{"prettyName":"80s80s Radio","name":"80s80s","category":"music_service","version":"1.0.4","icon":"fa-headphones","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Mixcloud","name":"mixcloud","category":"music_service","version":"1.0.1","icon":"fa-mixcloud","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"MotherEarthRadio","name":"motherearthradio","category":"music_service","version":"1.2.2","icon":"fa-lightbulb-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"pandora","name":"pandora","category":"music_service","version":"2.12.1","icon":"fa-lightbulb-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Podcast","name":"podcast","category":"music_service","version":"2.2.0","icon":"fa-podcast","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Radio Paradise","name":"radio_paradise","category":"music_service","version":"1.0.12","icon":"fa-headphones","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.1","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Music","name":"ytmusic","category":"music_service","version":"1.1.3","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Touch Display","name":"touch_display","category":"user_interface","version":"3.5.0","icon":"fa-hand-pointer-o","isManuallyInstalled":false,"enabled":true,"active":true}] Oct 25 06:00:19 musicstream volumio[1041]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 25 06:00:19 musicstream volumio[1041]: info: Initializing connection to go-librespot Websocket Oct 25 06:00:19 musicstream volumio[1041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 25 06:00:19 musicstream volumio[1041]: info: camilladsp spawned new process with pid undefined, instance 2, run: true Oct 25 06:00:19 musicstream volumio[1041]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 06:00:19 musicstream volumio[1041]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Oct 25 06:00:19 musicstream volumio[1041]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Oct 25 06:00:19 musicstream volumio[1041]: at onErrorNT (internal/child_process.js:465:16) Oct 25 06:00:19 musicstream volumio[1041]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 25 06:00:19 musicstream volumio[1041]: at runNextTicks (internal/process/task_queues.js:62:3) Oct 25 06:00:19 musicstream volumio[1041]: at listOnTimeout (internal/timers.js:523:9) Oct 25 06:00:19 musicstream volumio[1041]: at processTimers (internal/timers.js:497:7) { Oct 25 06:00:19 musicstream volumio[1041]: errno: -2, Oct 25 06:00:19 musicstream volumio[1041]: code: 'ENOENT', Oct 25 06:00:19 musicstream volumio[1041]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Oct 25 06:00:19 musicstream volumio[1041]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Oct 25 06:00:19 musicstream volumio[1041]: spawnargs: [ Oct 25 06:00:19 musicstream volumio[1041]: '-p', Oct 25 06:00:19 musicstream volumio[1041]: 9876, Oct 25 06:00:19 musicstream volumio[1041]: '-o', Oct 25 06:00:19 musicstream volumio[1041]: '/tmp/camilladsp.log', Oct 25 06:00:19 musicstream volumio[1041]: '-l', Oct 25 06:00:19 musicstream volumio[1041]: 'warn', Oct 25 06:00:19 musicstream volumio[1041]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Oct 25 06:00:19 musicstream volumio[1041]: ] Oct 25 06:00:19 musicstream volumio[1041]: } Oct 25 06:00:19 musicstream volumio[1041]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 06:00:20 musicstream mpd[14274]: Oct 25 06:00 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 06:00:20 musicstream systemd[1]: Started Music Player Daemon. Oct 25 06:00:20 musicstream sudo[14250]: pam_unix(sudo:session): session closed for user root Oct 25 06:00:21 musicstream sudo[14293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 05:59 Oct 25 06:00:21 musicstream sudo[14293]: 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"