-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Thu 2025-05-15 01:48:45 EDT. -- May 15 01:47:00 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:00 pationew volumio[1093]: info: [1747288020142] ControllerPandora::handleBrowseUri May 15 01:47:00 pationew volumio[1093]: info: [1747288020142] ControllerPandora::checkForExpiredStations May 15 01:47:00 pationew volumio[1093]: info: [1747288020143] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:00 pationew volumio[1093]: info: [1747288020532] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:01 pationew volumio[1093]: info: [1747288021372] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Level 42 Radio playlist May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: [1747288021372] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:01 pationew volumio[1093]: info: [1747288021372] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:01 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:01 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=3043047871640468609 May 15 01:47:01 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=3043047871640468609 in service pandora May 15 01:47:01 pationew volumio[1093]: info: [1747288021372] ControllerPandora::explodeUri May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=5042223277398749137 May 15 01:47:01 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=5042223277398749137 in service pandora May 15 01:47:01 pationew volumio[1093]: info: [1747288021373] ControllerPandora::explodeUri May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=5579897142160312993 May 15 01:47:01 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=5579897142160312993 in service pandora May 15 01:47:01 pationew volumio[1093]: info: [1747288021373] ControllerPandora::explodeUri May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=1136401191204417160 May 15 01:47:01 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=1136401191204417160 in service pandora May 15 01:47:01 pationew volumio[1093]: info: [1747288021373] ControllerPandora::explodeUri May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::play index 9 May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::stop May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::serviceStop May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::serviceStop May 15 01:47:01 pationew volumio[1093]: info: [1747288021380] ControllerPandora::stop May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::stop May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand stop May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand stop took 3 milliseconds May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand clear took 1 milliseconds May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:01 pationew volumio[1093]: info: [1747288021384] ControllerPandora::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Lessons In Love","name":"Lessons In Love","artist":"Level 42","album":"Living It Up (Deluxe)","albumart":"http://cont-2.p-cdn.us/images/09/fd/93/6e/9e1c41d189ec813468829818/1080W_1080H.jpg","realUri":"http://t1-1.p-cdn.us/access/583240905402068953.mp3?version=5&lid=617752572&token=KOnCZMdjCP14G3CiBHmS8wIzNQoLxMvOufT3%2Bsn%2FCcs7b0P9Mbzcnr4QMPaJpK2FIzv6lgVuVCAfGwFSU4oAEJ9z3fdjHxqqvMmn5VFyzCClJVzaeGUFK%2Blj%2BjdI40fZYj41zfN0d9xCV%2Bhs5jrhafxJ9SkdAjFHRDQ3td0UKApe9Vj0Fup5N609JKULiBp2PfkmwI7fwJuM0g0g%2Fu0JStXRO4cz8M0xQRNEZckmljsF6WgLT%2BxWM3EqWZPhChHHaEae9F28wehy6Ep6wD16VsaFIZ%2BxciovpSYyVMJiAZPup4jmbbUbeuTasYjTBnZpXVyXD84qFqbCPEsnMZL1MQ%3D%3D","isStreaming":true,"duration":242,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://t1-1.p-cdn.us/access/583240905402068953.mp3?version=5&lid=617752572&token=KOnCZMdjCP14G3CiBHmS8wIzNQoLxMvOufT3%2Bsn%2FCcs7b0P9Mbzcnr4QMPaJpK2FIzv6lgVuVCAfGwFSU4oAEJ9z3fdjHxqqvMmn5VFyzCClJVzaeGUFK%2Blj%2BjdI40fZYj41zfN0d9xCV%2Bhs5jrhafxJ9SkdAjFHRDQ3td0UKApe9Vj0Fup5N609JKULiBp2PfkmwI7fwJuM0g0g%2Fu0JStXRO4cz8M0xQRNEZckmljsF6WgLT%2BxWM3EqWZPhChHHaEae9F28wehy6Ep6wD16VsaFIZ%2BxciovpSYyVMJiAZPup4jmbbUbeuTasYjTBnZpXVyXD84qFqbCPEsnMZL1MQ%3D%3D","seek":0,"status":"stop"} May 15 01:47:01 pationew volumio[1093]: verbose: CURRENT POSITION 9 May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::syncState stateService stop May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: No code May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::play index undefined May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::startPlaybackTimer May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: [1747288021390] ControllerPandora::clearAddPlayTrack May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 8ms May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 8 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand clear took 2 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 01:47:01 pationew volumio[1093]: info: [1747288021392] ControllerPandora::checkForExpiredStations May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current pandora Received mpd May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 13ms May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: [1747288021396] ControllerPandora::removeTrack May 15 01:47:01 pationew volumio[1093]: info: [1747288021396] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 5ms May 15 01:47:01 pationew volumio[1093]: info: [1747288021396] ControllerPandora::appendTracksToMpd May 15 01:47:01 pationew volumio[1093]: info: [1747288021396] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand addid May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand play May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 10ms May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand addid took 5 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand play took 6 milliseconds May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 6ms May 15 01:47:01 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:01 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:01 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:01 pationew volumio[1093]: info: [1747288021403] ControllerPandora::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Enjoy the Silence","name":"Enjoy the Silence","artist":"Depeche Mode","album":"Violator (Deluxe)","albumart":"http://cont-4.p-cdn.us/images/cb/d1/cf/0a/0ea040ef800731913f6fadf7/1080W_1080H.jpg","realUri":"http://t1-5.p-cdn.us/access/3043047871640468609.mp3?version=5&lid=617752572&token=3kyxxQrwIZ%2FeBbD1NoP4upaD0BhNCUoUplTsIx2tAhXuTkOtbPXrfPEZhQ8lzet6EX62Fzf88Bvhh7fQny%2FDr1wB5RX6%2FzMs0YRsWzSS0GBNbC9uz6kltlzaawd59AmvCQffNumBhvyl5bMZBzBF7QsM7YmbFJb2Y0HKmDqWkanjJwpIrHe8kZQPRsaoHtqwNhhx6tgt2Vr0O0JNReXKi3f9iWHoDK8HJSzP5ytOboOvbTX3cx5jdWCTZgM7HkGdgKEhmM0gnuWeO%2FI18p3pEfSYXJsqNqWpu85yiT3uXl5ymdtBdzclr6yxAg8IUVGnJuvcppykr9dbPndZ%2F5nZrw%3D%3D","isStreaming":true,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://t1-5.p-cdn.us/access/3043047871640468609.mp3?version=5&lid=617752572&token=3kyxxQrwIZ%2FeBbD1NoP4upaD0BhNCUoUplTsIx2tAhXuTkOtbPXrfPEZhQ8lzet6EX62Fzf88Bvhh7fQny%2FDr1wB5RX6%2FzMs0YRsWzSS0GBNbC9uz6kltlzaawd59AmvCQffNumBhvyl5bMZBzBF7QsM7YmbFJb2Y0HKmDqWkanjJwpIrHe8kZQPRsaoHtqwNhhx6tgt2Vr0O0JNReXKi3f9iWHoDK8HJSzP5ytOboOvbTX3cx5jdWCTZgM7HkGdgKEhmM0gnuWeO%2FI18p3pEfSYXJsqNqWpu85yiT3uXl5ymdtBdzclr6yxAg8IUVGnJuvcppykr9dbPndZ%2F5nZrw%3D%3D","seek":0,"status":"play"} May 15 01:47:01 pationew volumio[1093]: verbose: CURRENT POSITION 9 May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:01 pationew volumio[1093]: info: [1747288021405] ControllerPandora::fetchAndAddTracks May 15 01:47:01 pationew volumio[1093]: info: [1747288021405] ControllerPandora::getStationTracks May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: [1747288021405] [Pandora] PandoraHandler::getSongMaxDiff: -20 May 15 01:47:01 pationew volumio[1093]: info: [1747288021405] ControllerPandora::fetchAndAddTracks::getSqInfo May 15 01:47:01 pationew volumio[1093]: info: [1747288021406] ControllerPandora::getStationTracks May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: [1747288021406] [Pandora] fetchAndAddTracks: diff1: -20 sQPos1: 8 May 15 01:47:01 pationew volumio[1093]: info: [1747288021406] [Pandora] fetchAndAddTracks: Fetching tracks May 15 01:47:01 pationew volumio[1093]: info: [1747288021406] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 6ms May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 2ms May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:01 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:01 pationew volumio[1093]: info: [1747288021547] ControllerPandora::pandoraListener May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 37 milliseconds May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 36 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 36 milliseconds May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:01 pationew volumio[1093]: info: May 15 01:47:01 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 4 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 3 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: [1747288021589] ControllerPandora::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Enjoy the Silence","artist":"Depeche Mode","album":"Violator (Deluxe)","uri":"http://t1-5.p-cdn.us/access/3043047871640468609.mp3?version=5&lid=617752572&token=3kyxxQrwIZ%2FeBbD1NoP4upaD0BhNCUoUplTsIx2tAhXuTkOtbPXrfPEZhQ8lzet6EX62Fzf88Bvhh7fQny%2FDr1wB5RX6%2FzMs0YRsWzSS0GBNbC9uz6kltlzaawd59AmvCQffNumBhvyl5bMZBzBF7QsM7YmbFJb2Y0HKmDqWkanjJwpIrHe8kZQPRsaoHtqwNhhx6tgt2Vr0O0JNReXKi3f9iWHoDK8HJSzP5ytOboOvbTX3cx5jdWCTZgM7HkGdgKEhmM0gnuWeO%2FI18p3pEfSYXJsqNqWpu85yiT3uXl5ymdtBdzclr6yxAg8IUVGnJuvcppykr9dbPndZ%2F5nZrw%3D%3D","trackType":"mp3"} May 15 01:47:01 pationew volumio[1093]: verbose: CURRENT POSITION 9 May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus play May 15 01:47:01 pationew volumio[1093]: info: Received an update from plugin. extracting info from payload May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 46ms May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 45ms May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 6 milliseconds May 15 01:47:01 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:01 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:01 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getTrack 9 May 15 01:47:01 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 10ms May 15 01:47:01 pationew volumio[1093]: info: ------------------------------ 8ms May 15 01:47:01 pationew volumio[1093]: info: CoreCommandRouter::volumioGetQueue May 15 01:47:01 pationew volumio[1093]: info: CoreStateMachine::getQueue May 15 01:47:01 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:01 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:01 pationew volumio[1093]: info: [1747288021871] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:04 pationew volumio[1093]: info: [1747288024387] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Level 42 Radio playlist May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: [1747288024387] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:04 pationew volumio[1093]: info: [1747288024387] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:04 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:04 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=7901946934509627173 May 15 01:47:04 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=7901946934509627173 in service pandora May 15 01:47:04 pationew volumio[1093]: info: [1747288024387] ControllerPandora::explodeUri May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=7034478507384157905 May 15 01:47:04 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=7034478507384157905 in service pandora May 15 01:47:04 pationew volumio[1093]: info: [1747288024387] ControllerPandora::explodeUri May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=393798125776237437 May 15 01:47:04 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=393798125776237437 in service pandora May 15 01:47:04 pationew volumio[1093]: info: [1747288024388] ControllerPandora::explodeUri May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230889615698569212trackId=4919210338365307995 May 15 01:47:04 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230889615698569212trackId=4919210338365307995 in service pandora May 15 01:47:04 pationew volumio[1093]: info: [1747288024388] ControllerPandora::explodeUri May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:04 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:04 pationew volumio[1093]: info: [1747288024391] ControllerPandora::getStationTracks May 15 01:47:04 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:04 pationew volumio[1093]: info: [1747288024391] [Pandora] PandoraHandler::getSongMaxDiff: -16 May 15 01:47:07 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:07 pationew volumio[1093]: info: [1747288027803] ControllerPandora::handleBrowseUri May 15 01:47:07 pationew volumio[1093]: info: [1747288027803] ControllerPandora::checkForExpiredStations May 15 01:47:07 pationew volumio[1093]: info: [1747288027805] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:08 pationew volumio[1093]: info: [1747288028206] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:09 pationew volumio[1093]: info: [1747288029221] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Neil Young Radio playlist May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: [1747288029221] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:09 pationew volumio[1093]: info: [1747288029222] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:09 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:09 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=6418557756440120796 May 15 01:47:09 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=6418557756440120796 in service pandora May 15 01:47:09 pationew volumio[1093]: info: [1747288029224] ControllerPandora::explodeUri May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=4669544760392708797 May 15 01:47:09 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=4669544760392708797 in service pandora May 15 01:47:09 pationew volumio[1093]: info: [1747288029224] ControllerPandora::explodeUri May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=1911626688899540708 May 15 01:47:09 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=1911626688899540708 in service pandora May 15 01:47:09 pationew volumio[1093]: info: [1747288029224] ControllerPandora::explodeUri May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=9087897313094697538 May 15 01:47:09 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=9087897313094697538 in service pandora May 15 01:47:09 pationew volumio[1093]: info: [1747288029224] ControllerPandora::explodeUri May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::play index 17 May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::stop May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::serviceStop May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::serviceStop May 15 01:47:09 pationew volumio[1093]: info: [1747288029236] ControllerPandora::stop May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::stop May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand stop May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand stop took 5 milliseconds May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand clear took 1 milliseconds May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:09 pationew volumio[1093]: info: [1747288029244] ControllerPandora::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Enjoy the Silence","name":"Enjoy the Silence","artist":"Depeche Mode","album":"Violator (Deluxe)","albumart":"http://cont-4.p-cdn.us/images/cb/d1/cf/0a/0ea040ef800731913f6fadf7/1080W_1080H.jpg","realUri":"http://t1-5.p-cdn.us/access/3043047871640468609.mp3?version=5&lid=617752572&token=3kyxxQrwIZ%2FeBbD1NoP4upaD0BhNCUoUplTsIx2tAhXuTkOtbPXrfPEZhQ8lzet6EX62Fzf88Bvhh7fQny%2FDr1wB5RX6%2FzMs0YRsWzSS0GBNbC9uz6kltlzaawd59AmvCQffNumBhvyl5bMZBzBF7QsM7YmbFJb2Y0HKmDqWkanjJwpIrHe8kZQPRsaoHtqwNhhx6tgt2Vr0O0JNReXKi3f9iWHoDK8HJSzP5ytOboOvbTX3cx5jdWCTZgM7HkGdgKEhmM0gnuWeO%2FI18p3pEfSYXJsqNqWpu85yiT3uXl5ymdtBdzclr6yxAg8IUVGnJuvcppykr9dbPndZ%2F5nZrw%3D%3D","isStreaming":true,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://t1-5.p-cdn.us/access/3043047871640468609.mp3?version=5&lid=617752572&token=3kyxxQrwIZ%2FeBbD1NoP4upaD0BhNCUoUplTsIx2tAhXuTkOtbPXrfPEZhQ8lzet6EX62Fzf88Bvhh7fQny%2FDr1wB5RX6%2FzMs0YRsWzSS0GBNbC9uz6kltlzaawd59AmvCQffNumBhvyl5bMZBzBF7QsM7YmbFJb2Y0HKmDqWkanjJwpIrHe8kZQPRsaoHtqwNhhx6tgt2Vr0O0JNReXKi3f9iWHoDK8HJSzP5ytOboOvbTX3cx5jdWCTZgM7HkGdgKEhmM0gnuWeO%2FI18p3pEfSYXJsqNqWpu85yiT3uXl5ymdtBdzclr6yxAg8IUVGnJuvcppykr9dbPndZ%2F5nZrw%3D%3D","seek":0,"status":"stop"} May 15 01:47:09 pationew volumio[1093]: verbose: CURRENT POSITION 17 May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::syncState stateService stop May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: No code May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::play index undefined May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::startPlaybackTimer May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: [1747288029251] ControllerPandora::clearAddPlayTrack May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 9ms May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 9 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand clear took 2 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 01:47:09 pationew volumio[1093]: info: [1747288029254] ControllerPandora::checkForExpiredStations May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current pandora Received mpd May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 13ms May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: [1747288029255] ControllerPandora::removeTrack May 15 01:47:09 pationew volumio[1093]: info: [1747288029255] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 4ms May 15 01:47:09 pationew volumio[1093]: info: [1747288029256] ControllerPandora::appendTracksToMpd May 15 01:47:09 pationew volumio[1093]: info: [1747288029256] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand addid May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand play May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 11ms May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand addid took 8 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand play took 8 milliseconds May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 8ms May 15 01:47:09 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] ControllerPandora::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Simple Man","name":"Simple Man","artist":"Lynyrd Skynyrd","album":"Pronounced 'Leh-'Nérd 'Skin-'Nérd (Expanded Edition)","albumart":"http://mediaserver-cont-usc-mp1-1-v4v6.pandora.com/images/0e/70/18/eb/4e024283abe3aed2d14775c1/1080W_1080H.jpg","realUri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/6418557756440120796.mp3?version=5&lid=617752572&token=59Bp4IpU7v8BdZUeLBx4zCWyq7D5qQZle1QdqzT1D1jxW%2BMoZlTpvUDveUmrv2PLOHtfjLQSqC2ShbpZ%2Bgq4TiFVnwX6rcUxPEXj4aAsHorZtqRRnZhxxkG72NJV8h29RNalFHaQoKKoJJTYVlRp4lfO4%2BU4PU%2FeKeSHelwmpkcn22fW03SlTlV8Df9ZP73dNCGJb12B8h7oCOqE8Xcx9e0YNX%2FDFc9xaI6p0XYAR8ZOs9C5FUeHMoZYn0c97cS%2FsZzjL%2Fp5Cy7jlNroE0R1qcCeosFv32EWyGbI34EIIQN3ODL41CWIlhLAZ29HUbHYMtIUKaHyYgdJoOIg56IR2Q%3D%3D","isStreaming":true,"duration":358,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/6418557756440120796.mp3?version=5&lid=617752572&token=59Bp4IpU7v8BdZUeLBx4zCWyq7D5qQZle1QdqzT1D1jxW%2BMoZlTpvUDveUmrv2PLOHtfjLQSqC2ShbpZ%2Bgq4TiFVnwX6rcUxPEXj4aAsHorZtqRRnZhxxkG72NJV8h29RNalFHaQoKKoJJTYVlRp4lfO4%2BU4PU%2FeKeSHelwmpkcn22fW03SlTlV8Df9ZP73dNCGJb12B8h7oCOqE8Xcx9e0YNX%2FDFc9xaI6p0XYAR8ZOs9C5FUeHMoZYn0c97cS%2FsZzjL%2Fp5Cy7jlNroE0R1qcCeosFv32EWyGbI34EIIQN3ODL41CWIlhLAZ29HUbHYMtIUKaHyYgdJoOIg56IR2Q%3D%3D","seek":0,"status":"play"} May 15 01:47:09 pationew volumio[1093]: verbose: CURRENT POSITION 17 May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] ControllerPandora::fetchAndAddTracks May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] ControllerPandora::getStationTracks May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] [Pandora] PandoraHandler::getSongMaxDiff: -28 May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] ControllerPandora::fetchAndAddTracks::getSqInfo May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] ControllerPandora::getStationTracks May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] [Pandora] fetchAndAddTracks: diff1: -28 sQPos1: 0 May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] [Pandora] fetchAndAddTracks: Fetching tracks May 15 01:47:09 pationew volumio[1093]: info: [1747288029265] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 3ms May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:09 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:09 pationew volumio[1093]: info: [1747288029586] ControllerPandora::pandoraListener May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 32 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 31 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 31 milliseconds May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:09 pationew volumio[1093]: info: May 15 01:47:09 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: [1747288029620] ControllerPandora::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":358,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Simple Man","artist":"Lynyrd Skynyrd","album":"Pronounced 'Leh-'Nérd 'Skin-'Nérd (Expanded Edition)","uri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/6418557756440120796.mp3?version=5&lid=617752572&token=59Bp4IpU7v8BdZUeLBx4zCWyq7D5qQZle1QdqzT1D1jxW%2BMoZlTpvUDveUmrv2PLOHtfjLQSqC2ShbpZ%2Bgq4TiFVnwX6rcUxPEXj4aAsHorZtqRRnZhxxkG72NJV8h29RNalFHaQoKKoJJTYVlRp4lfO4%2BU4PU%2FeKeSHelwmpkcn22fW03SlTlV8Df9ZP73dNCGJb12B8h7oCOqE8Xcx9e0YNX%2FDFc9xaI6p0XYAR8ZOs9C5FUeHMoZYn0c97cS%2FsZzjL%2Fp5Cy7jlNroE0R1qcCeosFv32EWyGbI34EIIQN3ODL41CWIlhLAZ29HUbHYMtIUKaHyYgdJoOIg56IR2Q%3D%3D","trackType":"mp3"} May 15 01:47:09 pationew volumio[1093]: verbose: CURRENT POSITION 17 May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus play May 15 01:47:09 pationew volumio[1093]: info: Received an update from plugin. extracting info from payload May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 38ms May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 37ms May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:09 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:09 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:09 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getTrack 17 May 15 01:47:09 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 8ms May 15 01:47:09 pationew volumio[1093]: info: ------------------------------ 7ms May 15 01:47:09 pationew volumio[1093]: info: CoreCommandRouter::volumioGetQueue May 15 01:47:09 pationew volumio[1093]: info: CoreStateMachine::getQueue May 15 01:47:09 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:09 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:09 pationew volumio[1093]: info: [1747288029672] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:10 pationew volumio[1093]: info: [1747288030446] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Neil Young Radio playlist May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: [1747288030446] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:10 pationew volumio[1093]: info: [1747288030446] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:10 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:10 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=2410394753330291427 May 15 01:47:10 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=2410394753330291427 in service pandora May 15 01:47:10 pationew volumio[1093]: info: [1747288030447] ControllerPandora::explodeUri May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=8029332329542777675 May 15 01:47:10 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=8029332329542777675 in service pandora May 15 01:47:10 pationew volumio[1093]: info: [1747288030447] ControllerPandora::explodeUri May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=4855615467998585482 May 15 01:47:10 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=4855615467998585482 in service pandora May 15 01:47:10 pationew volumio[1093]: info: [1747288030447] ControllerPandora::explodeUri May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=3066871533479798780trackId=9104052022692723718 May 15 01:47:10 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=3066871533479798780trackId=9104052022692723718 in service pandora May 15 01:47:10 pationew volumio[1093]: info: [1747288030447] ControllerPandora::explodeUri May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:10 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:10 pationew volumio[1093]: info: [1747288030451] ControllerPandora::getStationTracks May 15 01:47:10 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:10 pationew volumio[1093]: info: [1747288030451] [Pandora] PandoraHandler::getSongMaxDiff: -24 May 15 01:47:18 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:18 pationew volumio[1093]: info: [1747288038951] ControllerPandora::handleBrowseUri May 15 01:47:18 pationew volumio[1093]: info: [1747288038951] ControllerPandora::checkForExpiredStations May 15 01:47:18 pationew volumio[1093]: info: [1747288038951] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:19 pationew volumio[1093]: info: [1747288039359] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:20 pationew volumio[1093]: info: [1747288040584] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved 70s Rock Radio playlist May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: [1747288040585] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:20 pationew volumio[1093]: info: [1747288040585] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:20 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:20 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=2841625507886419851 May 15 01:47:20 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=2841625507886419851 in service pandora May 15 01:47:20 pationew volumio[1093]: info: [1747288040585] ControllerPandora::explodeUri May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=4068999206271755657 May 15 01:47:20 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=4068999206271755657 in service pandora May 15 01:47:20 pationew volumio[1093]: info: [1747288040586] ControllerPandora::explodeUri May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=1970386771993877540 May 15 01:47:20 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=1970386771993877540 in service pandora May 15 01:47:20 pationew volumio[1093]: info: [1747288040586] ControllerPandora::explodeUri May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=1586978131407805210 May 15 01:47:20 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=1586978131407805210 in service pandora May 15 01:47:20 pationew volumio[1093]: info: [1747288040586] ControllerPandora::explodeUri May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::play index 25 May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::stop May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::serviceStop May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::serviceStop May 15 01:47:20 pationew volumio[1093]: info: [1747288040591] ControllerPandora::stop May 15 01:47:20 pationew volumio[1093]: info: ControllerMpd::stop May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand stop May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand stop took 6 milliseconds May 15 01:47:20 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:20 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand clear took 1 milliseconds May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:20 pationew volumio[1093]: info: [1747288040599] ControllerPandora::pushState May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Simple Man","name":"Simple Man","artist":"Lynyrd Skynyrd","album":"Pronounced 'Leh-'Nérd 'Skin-'Nérd (Expanded Edition)","albumart":"http://mediaserver-cont-usc-mp1-1-v4v6.pandora.com/images/0e/70/18/eb/4e024283abe3aed2d14775c1/1080W_1080H.jpg","realUri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/6418557756440120796.mp3?version=5&lid=617752572&token=59Bp4IpU7v8BdZUeLBx4zCWyq7D5qQZle1QdqzT1D1jxW%2BMoZlTpvUDveUmrv2PLOHtfjLQSqC2ShbpZ%2Bgq4TiFVnwX6rcUxPEXj4aAsHorZtqRRnZhxxkG72NJV8h29RNalFHaQoKKoJJTYVlRp4lfO4%2BU4PU%2FeKeSHelwmpkcn22fW03SlTlV8Df9ZP73dNCGJb12B8h7oCOqE8Xcx9e0YNX%2FDFc9xaI6p0XYAR8ZOs9C5FUeHMoZYn0c97cS%2FsZzjL%2Fp5Cy7jlNroE0R1qcCeosFv32EWyGbI34EIIQN3ODL41CWIlhLAZ29HUbHYMtIUKaHyYgdJoOIg56IR2Q%3D%3D","isStreaming":true,"duration":358,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/6418557756440120796.mp3?version=5&lid=617752572&token=59Bp4IpU7v8BdZUeLBx4zCWyq7D5qQZle1QdqzT1D1jxW%2BMoZlTpvUDveUmrv2PLOHtfjLQSqC2ShbpZ%2Bgq4TiFVnwX6rcUxPEXj4aAsHorZtqRRnZhxxkG72NJV8h29RNalFHaQoKKoJJTYVlRp4lfO4%2BU4PU%2FeKeSHelwmpkcn22fW03SlTlV8Df9ZP73dNCGJb12B8h7oCOqE8Xcx9e0YNX%2FDFc9xaI6p0XYAR8ZOs9C5FUeHMoZYn0c97cS%2FsZzjL%2Fp5Cy7jlNroE0R1qcCeosFv32EWyGbI34EIIQN3ODL41CWIlhLAZ29HUbHYMtIUKaHyYgdJoOIg56IR2Q%3D%3D","seek":0,"status":"stop"} May 15 01:47:20 pationew volumio[1093]: verbose: CURRENT POSITION 25 May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::syncState stateService stop May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:20 pationew volumio[1093]: info: No code May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::play index undefined May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::startPlaybackTimer May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: [1747288040608] ControllerPandora::clearAddPlayTrack May 15 01:47:20 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:20 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:20 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 12ms May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 12 milliseconds May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand clear took 3 milliseconds May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand status took 2 milliseconds May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:20 pationew volumio[1093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 01:47:20 pationew volumio[1093]: info: [1747288040611] ControllerPandora::checkForExpiredStations May 15 01:47:20 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current pandora Received mpd May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 15ms May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: [1747288040613] ControllerPandora::removeTrack May 15 01:47:20 pationew volumio[1093]: info: [1747288040613] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 4ms May 15 01:47:20 pationew volumio[1093]: info: [1747288040613] ControllerPandora::appendTracksToMpd May 15 01:47:20 pationew volumio[1093]: info: [1747288040613] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand addid May 15 01:47:20 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand play May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 9ms May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand addid took 5 milliseconds May 15 01:47:20 pationew volumio[1093]: info: sendMpdCommand play took 5 milliseconds May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 5ms May 15 01:47:20 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:20 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] ControllerPandora::pushState May 15 01:47:20 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:20 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"I'm Not In Love","name":"I'm Not In Love","artist":"10cc","album":"The Singles","albumart":"http://mediaserver-cont-dc6-1-v4v6.pandora.com/images/e7/9e/dc/5c/c79545548313632459d4cf8f/1080W_1080H.jpg","realUri":"http://t1-2.p-cdn.us/access/2841625507886419851.mp3?version=5&lid=617752572&token=MhoDMCbVXZJ3OQ3JnbPs97FUULbpBYPm%2FZV%2BwNm%2F%2Bj9gCw32cJxCAngKJT4plq9jTCOsmKjX7nJPXpZH3PObeErv6NABjlbuQ%2FREOp4fJuFD28J8mEruVqknGpPDDypfplEYDB8WtoqOG0bkdhvWQSMZz%2FIt%2BJQSVanGco3W%2FdfwVW72gaeG6BE3fzUPI8TT71O3GWnAwThEjl9GGekh8UXa9iNFH1NigDYzn2V5txQ5atjwZSbZO9%2FfrsF4S59zn8YiRGNuwTPIa%2BheWr6Lio0m1gMJeCr2vlN4QHsjkXiasEe60C%2FMCQU%2B%2Bc7mSrgEC6ppG3T6HK0XzS0hmOgUhw%3D%3D","isStreaming":true,"duration":362,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://t1-2.p-cdn.us/access/2841625507886419851.mp3?version=5&lid=617752572&token=MhoDMCbVXZJ3OQ3JnbPs97FUULbpBYPm%2FZV%2BwNm%2F%2Bj9gCw32cJxCAngKJT4plq9jTCOsmKjX7nJPXpZH3PObeErv6NABjlbuQ%2FREOp4fJuFD28J8mEruVqknGpPDDypfplEYDB8WtoqOG0bkdhvWQSMZz%2FIt%2BJQSVanGco3W%2FdfwVW72gaeG6BE3fzUPI8TT71O3GWnAwThEjl9GGekh8UXa9iNFH1NigDYzn2V5txQ5atjwZSbZO9%2FfrsF4S59zn8YiRGNuwTPIa%2BheWr6Lio0m1gMJeCr2vlN4QHsjkXiasEe60C%2FMCQU%2B%2Bc7mSrgEC6ppG3T6HK0XzS0hmOgUhw%3D%3D","seek":0,"status":"play"} May 15 01:47:20 pationew volumio[1093]: verbose: CURRENT POSITION 25 May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:20 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] ControllerPandora::fetchAndAddTracks May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] ControllerPandora::getStationTracks May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] [Pandora] PandoraHandler::getSongMaxDiff: -28 May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] ControllerPandora::fetchAndAddTracks::getSqInfo May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] ControllerPandora::getStationTracks May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] [Pandora] fetchAndAddTracks: diff1: -28 sQPos1: 0 May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] [Pandora] fetchAndAddTracks: Fetching tracks May 15 01:47:20 pationew volumio[1093]: info: [1747288040620] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 5ms May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 3ms May 15 01:47:20 pationew volumio[1093]: info: May 15 01:47:20 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:20 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:20 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:21 pationew volumio[1093]: info: [1747288041015] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:21 pationew volumio[1093]: info: [1747288041667] ControllerPandora::pandoraListener May 15 01:47:21 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:21 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:21 pationew volumio[1093]: info: May 15 01:47:21 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:21 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:21 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:21 pationew volumio[1093]: info: May 15 01:47:21 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:21 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:21 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:21 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:21 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:21 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:21 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:21 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:21 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:22 pationew nmbd[3041]: [2025/05/15 01:47:22.478222, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 15 01:47:22 pationew nmbd[3041]: Packet send failed to 192.168.1.1(1377) ERRNO=Network is unreachable May 15 01:47:22 pationew nmbd[3041]: [2025/05/15 01:47:22.478313, 0] ../source3/nmbd/nmbd_packets.c:1027(reply_netbios_packet) May 15 01:47:22 pationew nmbd[3041]: reply_netbios_packet: send_packet to IP 192.168.1.1 port 1377 failed May 15 01:47:22 pationew nmbd[3041]: [2025/05/15 01:47:22.478430, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 15 01:47:22 pationew nmbd[3041]: Packet send failed to 192.168.1.1(1377) ERRNO=Network is unreachable May 15 01:47:22 pationew nmbd[3041]: [2025/05/15 01:47:22.478458, 0] ../source3/nmbd/nmbd_packets.c:1027(reply_netbios_packet) May 15 01:47:22 pationew nmbd[3041]: reply_netbios_packet: send_packet to IP 192.168.1.1 port 1377 failed May 15 01:47:22 pationew volumio[1093]: info: May 15 01:47:22 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand status took 863 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand status took 863 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand status took 863 milliseconds May 15 01:47:22 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:22 pationew volumio[1093]: info: May 15 01:47:22 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:22 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:22 pationew volumio[1093]: info: [1747288042534] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved 70s Rock Radio playlist May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: [1747288042534] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:22 pationew volumio[1093]: info: [1747288042534] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:22 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:22 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=1588559150141754531 May 15 01:47:22 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=1588559150141754531 in service pandora May 15 01:47:22 pationew volumio[1093]: info: [1747288042535] ControllerPandora::explodeUri May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=5752464773770414154 May 15 01:47:22 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=5752464773770414154 in service pandora May 15 01:47:22 pationew volumio[1093]: info: [1747288042536] ControllerPandora::explodeUri May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=9027502130761649410 May 15 01:47:22 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=9027502130761649410 in service pandora May 15 01:47:22 pationew volumio[1093]: info: [1747288042536] ControllerPandora::explodeUri May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2277920250619111420trackId=5276745540514358949 May 15 01:47:22 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2277920250619111420trackId=5276745540514358949 in service pandora May 15 01:47:22 pationew volumio[1093]: info: [1747288042537] ControllerPandora::explodeUri May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:22 pationew volumio[1093]: info: [1747288042544] ControllerPandora::getStationTracks May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: [1747288042544] [Pandora] PandoraHandler::getSongMaxDiff: -24 May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand status took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand status took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:22 pationew volumio[1093]: info: [1747288042546] ControllerPandora::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:22 pationew volumio[1093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":362,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"I'm Not In Love","artist":"10cc","album":"The Singles","uri":"http://t1-2.p-cdn.us/access/2841625507886419851.mp3?version=5&lid=617752572&token=MhoDMCbVXZJ3OQ3JnbPs97FUULbpBYPm%2FZV%2BwNm%2F%2Bj9gCw32cJxCAngKJT4plq9jTCOsmKjX7nJPXpZH3PObeErv6NABjlbuQ%2FREOp4fJuFD28J8mEruVqknGpPDDypfplEYDB8WtoqOG0bkdhvWQSMZz%2FIt%2BJQSVanGco3W%2FdfwVW72gaeG6BE3fzUPI8TT71O3GWnAwThEjl9GGekh8UXa9iNFH1NigDYzn2V5txQ5atjwZSbZO9%2FfrsF4S59zn8YiRGNuwTPIa%2BheWr6Lio0m1gMJeCr2vlN4QHsjkXiasEe60C%2FMCQU%2B%2Bc7mSrgEC6ppG3T6HK0XzS0hmOgUhw%3D%3D","trackType":"mp3"} May 15 01:47:22 pationew volumio[1093]: verbose: CURRENT POSITION 25 May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus play May 15 01:47:22 pationew volumio[1093]: info: Received an update from plugin. extracting info from payload May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:22 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:22 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:22 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:22 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:22 pationew volumio[1093]: info: ------------------------------ 883ms May 15 01:47:22 pationew volumio[1093]: info: ------------------------------ 883ms May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::volumioGetQueue May 15 01:47:22 pationew volumio[1093]: info: CoreStateMachine::getQueue May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 14 milliseconds May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:22 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:22 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:22 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:22 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:22 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:22 pationew volumio[1093]: info: CorePlayQueue::getTrack 25 May 15 01:47:22 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:22 pationew volumio[1093]: info: ------------------------------ 31ms May 15 01:47:22 pationew volumio[1093]: info: ------------------------------ 30ms May 15 01:47:22 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:22 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:24 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:24 pationew volumio[1093]: info: [1747288044326] ControllerPandora::handleBrowseUri May 15 01:47:24 pationew volumio[1093]: info: [1747288044326] ControllerPandora::checkForExpiredStations May 15 01:47:24 pationew volumio[1093]: info: [1747288044327] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:24 pationew volumio[1093]: info: [1747288044745] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:25 pationew volumio[1093]: info: [1747288045809] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Audioslave Radio playlist May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: [1747288045810] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:25 pationew volumio[1093]: info: [1747288045810] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:25 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:25 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=1551165983902596569 May 15 01:47:25 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=1551165983902596569 in service pandora May 15 01:47:25 pationew volumio[1093]: info: [1747288045810] ControllerPandora::explodeUri May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=3489589677579960518 May 15 01:47:25 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=3489589677579960518 in service pandora May 15 01:47:25 pationew volumio[1093]: info: [1747288045810] ControllerPandora::explodeUri May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=685828112072784872 May 15 01:47:25 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=685828112072784872 in service pandora May 15 01:47:25 pationew volumio[1093]: info: [1747288045810] ControllerPandora::explodeUri May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=3192956340140589796 May 15 01:47:25 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=3192956340140589796 in service pandora May 15 01:47:25 pationew volumio[1093]: info: [1747288045810] ControllerPandora::explodeUri May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::play index 33 May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::stop May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::serviceStop May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::serviceStop May 15 01:47:25 pationew volumio[1093]: info: [1747288045819] ControllerPandora::stop May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::stop May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand stop May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand stop took 7 milliseconds May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand clear took 1 milliseconds May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:25 pationew volumio[1093]: info: [1747288045827] ControllerPandora::pushState May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"I'm Not In Love","name":"I'm Not In Love","artist":"10cc","album":"The Singles","albumart":"http://mediaserver-cont-dc6-1-v4v6.pandora.com/images/e7/9e/dc/5c/c79545548313632459d4cf8f/1080W_1080H.jpg","realUri":"http://t1-2.p-cdn.us/access/2841625507886419851.mp3?version=5&lid=617752572&token=MhoDMCbVXZJ3OQ3JnbPs97FUULbpBYPm%2FZV%2BwNm%2F%2Bj9gCw32cJxCAngKJT4plq9jTCOsmKjX7nJPXpZH3PObeErv6NABjlbuQ%2FREOp4fJuFD28J8mEruVqknGpPDDypfplEYDB8WtoqOG0bkdhvWQSMZz%2FIt%2BJQSVanGco3W%2FdfwVW72gaeG6BE3fzUPI8TT71O3GWnAwThEjl9GGekh8UXa9iNFH1NigDYzn2V5txQ5atjwZSbZO9%2FfrsF4S59zn8YiRGNuwTPIa%2BheWr6Lio0m1gMJeCr2vlN4QHsjkXiasEe60C%2FMCQU%2B%2Bc7mSrgEC6ppG3T6HK0XzS0hmOgUhw%3D%3D","isStreaming":true,"duration":362,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://t1-2.p-cdn.us/access/2841625507886419851.mp3?version=5&lid=617752572&token=MhoDMCbVXZJ3OQ3JnbPs97FUULbpBYPm%2FZV%2BwNm%2F%2Bj9gCw32cJxCAngKJT4plq9jTCOsmKjX7nJPXpZH3PObeErv6NABjlbuQ%2FREOp4fJuFD28J8mEruVqknGpPDDypfplEYDB8WtoqOG0bkdhvWQSMZz%2FIt%2BJQSVanGco3W%2FdfwVW72gaeG6BE3fzUPI8TT71O3GWnAwThEjl9GGekh8UXa9iNFH1NigDYzn2V5txQ5atjwZSbZO9%2FfrsF4S59zn8YiRGNuwTPIa%2BheWr6Lio0m1gMJeCr2vlN4QHsjkXiasEe60C%2FMCQU%2B%2Bc7mSrgEC6ppG3T6HK0XzS0hmOgUhw%3D%3D","seek":0,"status":"stop"} May 15 01:47:25 pationew volumio[1093]: verbose: CURRENT POSITION 33 May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::syncState stateService stop May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:25 pationew volumio[1093]: info: No code May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::play index undefined May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current pandora Received mpd May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::startPlaybackTimer May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: info: [1747288045834] ControllerPandora::clearAddPlayTrack May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 8ms May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 9ms May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 9 milliseconds May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand clear took 2 milliseconds May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:25 pationew volumio[1093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 01:47:25 pationew volumio[1093]: info: [1747288045836] ControllerPandora::checkForExpiredStations May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 10ms May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: [1747288045836] ControllerPandora::removeTrack May 15 01:47:25 pationew volumio[1093]: info: [1747288045836] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 May 15 01:47:25 pationew volumio[1093]: info: [1747288045836] ControllerPandora::appendTracksToMpd May 15 01:47:25 pationew volumio[1093]: info: [1747288045836] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand addid May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand play May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 6ms May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand addid took 6 milliseconds May 15 01:47:25 pationew volumio[1093]: info: sendMpdCommand play took 5 milliseconds May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 6ms May 15 01:47:25 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:25 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] ControllerPandora::pushState May 15 01:47:25 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:25 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"I Am the Highway","name":"I Am the Highway","artist":"Audioslave","album":"Audioslave","albumart":"http://cont-3.p-cdn.us/images/85/c3/b8/86/226e47fcba58cc4bdfec2bf0/1080W_1080H.jpg","realUri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/1551165983902596569.mp3?version=5&lid=617752572&token=Dlo1Jx08HDrjuiHCx8Weh7YRJqeCcSk1EvskPAZBmUn7cXVJmKmcPxX9ahYya7tqyvR087PxV2r6I9572j9yPIfXE51Vw8GALTDQmlmFUA0HYHMMMyH4cbK%2FcWYsmqtMKr1vcpc8zzHpNwJcKimN5FztOUSeQdGDYjp%2FRgOp9ivzxPwB4ug8UKiIP2d71VS7GGOu%2FJS%2BjRg0UPVHGhSXezReW%2B8lcL2oXSTmKAaBdUEAuaiQOBU5UpeeZSH8nwd2wjOLl6wvGxsbcQsYwiykHXre0xKIfOD9ax%2B8YyC5ACGfVCczyiOtZpoIK8WdgEn2EtyGMkLgOpwSVIyBOfOWrQ%3D%3D","isStreaming":true,"duration":335,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/1551165983902596569.mp3?version=5&lid=617752572&token=Dlo1Jx08HDrjuiHCx8Weh7YRJqeCcSk1EvskPAZBmUn7cXVJmKmcPxX9ahYya7tqyvR087PxV2r6I9572j9yPIfXE51Vw8GALTDQmlmFUA0HYHMMMyH4cbK%2FcWYsmqtMKr1vcpc8zzHpNwJcKimN5FztOUSeQdGDYjp%2FRgOp9ivzxPwB4ug8UKiIP2d71VS7GGOu%2FJS%2BjRg0UPVHGhSXezReW%2B8lcL2oXSTmKAaBdUEAuaiQOBU5UpeeZSH8nwd2wjOLl6wvGxsbcQsYwiykHXre0xKIfOD9ax%2B8YyC5ACGfVCczyiOtZpoIK8WdgEn2EtyGMkLgOpwSVIyBOfOWrQ%3D%3D","seek":0,"status":"play"} May 15 01:47:25 pationew volumio[1093]: verbose: CURRENT POSITION 33 May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:25 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] ControllerPandora::fetchAndAddTracks May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] ControllerPandora::getStationTracks May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] [Pandora] PandoraHandler::getSongMaxDiff: -28 May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] ControllerPandora::fetchAndAddTracks::getSqInfo May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] ControllerPandora::getStationTracks May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] [Pandora] fetchAndAddTracks: diff1: -28 sQPos1: 0 May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] [Pandora] fetchAndAddTracks: Fetching tracks May 15 01:47:25 pationew volumio[1093]: info: [1747288045843] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 3ms May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:25 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:25 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:25 pationew volumio[1093]: info: [1747288045977] ControllerPandora::pandoraListener May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:25 pationew volumio[1093]: info: May 15 01:47:25 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:25 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:25 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:25 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:25 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:25 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:26 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:26 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:26 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:26 pationew volumio[1093]: info: May 15 01:47:26 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand status took 511 milliseconds May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand status took 511 milliseconds May 15 01:47:26 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand status took 510 milliseconds May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:26 pationew volumio[1093]: info: May 15 01:47:26 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:26 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:26 pationew volumio[1093]: info: [1747288046490] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand status took 4 milliseconds May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand status took 4 milliseconds May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:26 pationew volumio[1093]: info: [1747288046493] ControllerPandora::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:26 pationew volumio[1093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":335,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"I Am the Highway","artist":"Audioslave","album":"Audioslave","uri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/1551165983902596569.mp3?version=5&lid=617752572&token=Dlo1Jx08HDrjuiHCx8Weh7YRJqeCcSk1EvskPAZBmUn7cXVJmKmcPxX9ahYya7tqyvR087PxV2r6I9572j9yPIfXE51Vw8GALTDQmlmFUA0HYHMMMyH4cbK%2FcWYsmqtMKr1vcpc8zzHpNwJcKimN5FztOUSeQdGDYjp%2FRgOp9ivzxPwB4ug8UKiIP2d71VS7GGOu%2FJS%2BjRg0UPVHGhSXezReW%2B8lcL2oXSTmKAaBdUEAuaiQOBU5UpeeZSH8nwd2wjOLl6wvGxsbcQsYwiykHXre0xKIfOD9ax%2B8YyC5ACGfVCczyiOtZpoIK8WdgEn2EtyGMkLgOpwSVIyBOfOWrQ%3D%3D","trackType":"mp3"} May 15 01:47:26 pationew volumio[1093]: verbose: CURRENT POSITION 33 May 15 01:47:26 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:26 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus play May 15 01:47:26 pationew volumio[1093]: info: Received an update from plugin. extracting info from payload May 15 01:47:26 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:26 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:26 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:26 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:26 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:26 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:26 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:26 pationew volumio[1093]: info: ------------------------------ 520ms May 15 01:47:26 pationew volumio[1093]: info: ------------------------------ 520ms May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:26 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:26 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:26 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:26 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:26 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:26 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:26 pationew volumio[1093]: info: ------------------------------ 12ms May 15 01:47:26 pationew volumio[1093]: info: ------------------------------ 10ms May 15 01:47:26 pationew volumio[1093]: info: CoreCommandRouter::volumioGetQueue May 15 01:47:26 pationew volumio[1093]: info: CoreStateMachine::getQueue May 15 01:47:26 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:26 pationew volumio[1093]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 15 01:47:27 pationew volumio[1093]: info: [1747288047292] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Audioslave Radio playlist May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:27 pationew volumio[1093]: info: [1747288047292] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:27 pationew volumio[1093]: info: [1747288047292] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:27 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:27 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=1098110691996390212 May 15 01:47:27 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=1098110691996390212 in service pandora May 15 01:47:27 pationew volumio[1093]: info: [1747288047292] ControllerPandora::explodeUri May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:27 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=6783519088014354326 May 15 01:47:27 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=6783519088014354326 in service pandora May 15 01:47:27 pationew volumio[1093]: info: [1747288047292] ControllerPandora::explodeUri May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:27 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=2466991792000146321 May 15 01:47:27 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=2466991792000146321 in service pandora May 15 01:47:27 pationew volumio[1093]: info: [1747288047293] ControllerPandora::explodeUri May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:27 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2575713848196737020trackId=4309328329757897192 May 15 01:47:27 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2575713848196737020trackId=4309328329757897192 in service pandora May 15 01:47:27 pationew volumio[1093]: info: [1747288047293] ControllerPandora::explodeUri May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:27 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:27 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:27 pationew volumio[1093]: info: [1747288047299] ControllerPandora::getStationTracks May 15 01:47:27 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:27 pationew volumio[1093]: info: [1747288047299] [Pandora] PandoraHandler::getSongMaxDiff: -24 May 15 01:47:32 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:32 pationew volumio[1093]: info: CorePlayQueue::getTrack 33 May 15 01:47:32 pationew volumio[1093]: info: [1747288052616] ControllerPandora::ExpireOldTracks::reaper May 15 01:47:32 pationew volumio[1093]: info: [1747288052616] [Pandora] ExpireOldTracks::reaper: No victims found: Expiring zero tracks. Don't worry -- Jason will return. May 15 01:47:40 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:40 pationew volumio[1093]: info: [1747288060087] ControllerPandora::handleBrowseUri May 15 01:47:40 pationew volumio[1093]: info: [1747288060087] ControllerPandora::checkForExpiredStations May 15 01:47:40 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:42 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:42 pationew volumio[1093]: info: [1747288062903] ControllerPandora::handleBrowseUri May 15 01:47:42 pationew volumio[1093]: info: [1747288062903] ControllerPandora::checkForExpiredStations May 15 01:47:42 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:52 pationew nmbd[3041]: [2025/05/15 01:47:52.463640, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 15 01:47:52 pationew nmbd[3041]: Packet send failed to 192.168.1.1(1377) ERRNO=Network is unreachable May 15 01:47:52 pationew nmbd[3041]: [2025/05/15 01:47:52.463734, 0] ../source3/nmbd/nmbd_packets.c:1027(reply_netbios_packet) May 15 01:47:52 pationew nmbd[3041]: reply_netbios_packet: send_packet to IP 192.168.1.1 port 1377 failed May 15 01:47:52 pationew nmbd[3041]: [2025/05/15 01:47:52.528638, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 15 01:47:52 pationew nmbd[3041]: Packet send failed to 192.168.1.1(1377) ERRNO=Network is unreachable May 15 01:47:52 pationew nmbd[3041]: [2025/05/15 01:47:52.528705, 0] ../source3/nmbd/nmbd_packets.c:1027(reply_netbios_packet) May 15 01:47:52 pationew nmbd[3041]: reply_netbios_packet: send_packet to IP 192.168.1.1 port 1377 failed May 15 01:47:53 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri May 15 01:47:53 pationew volumio[1093]: info: [1747288073715] ControllerPandora::handleBrowseUri May 15 01:47:53 pationew volumio[1093]: info: [1747288073715] ControllerPandora::checkForExpiredStations May 15 01:47:53 pationew volumio[1093]: info: [1747288073715] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:54 pationew volumio[1093]: info: [1747288074144] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:55 pationew volumio[1093]: info: [1747288075252] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Erasure Radio playlist May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: [1747288075252] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:55 pationew volumio[1093]: info: [1747288075252] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:55 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:55 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=6253376505598328688 May 15 01:47:55 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=6253376505598328688 in service pandora May 15 01:47:55 pationew volumio[1093]: info: [1747288075253] ControllerPandora::explodeUri May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=8127812320206168384 May 15 01:47:55 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=8127812320206168384 in service pandora May 15 01:47:55 pationew volumio[1093]: info: [1747288075253] ControllerPandora::explodeUri May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=2258350376183748145 May 15 01:47:55 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=2258350376183748145 in service pandora May 15 01:47:55 pationew volumio[1093]: info: [1747288075253] ControllerPandora::explodeUri May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=3960849923689154145 May 15 01:47:55 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=3960849923689154145 in service pandora May 15 01:47:55 pationew volumio[1093]: info: [1747288075253] ControllerPandora::explodeUri May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::play index 41 May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::stop May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::serviceStop May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::serviceStop May 15 01:47:55 pationew volumio[1093]: info: [1747288075260] ControllerPandora::stop May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::stop May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand stop May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand stop took 7 milliseconds May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand clear took 1 milliseconds May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand status took 1 milliseconds May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:55 pationew volumio[1093]: info: [1747288075268] ControllerPandora::pushState May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"I Am the Highway","name":"I Am the Highway","artist":"Audioslave","album":"Audioslave","albumart":"http://cont-3.p-cdn.us/images/85/c3/b8/86/226e47fcba58cc4bdfec2bf0/1080W_1080H.jpg","realUri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/1551165983902596569.mp3?version=5&lid=617752572&token=Dlo1Jx08HDrjuiHCx8Weh7YRJqeCcSk1EvskPAZBmUn7cXVJmKmcPxX9ahYya7tqyvR087PxV2r6I9572j9yPIfXE51Vw8GALTDQmlmFUA0HYHMMMyH4cbK%2FcWYsmqtMKr1vcpc8zzHpNwJcKimN5FztOUSeQdGDYjp%2FRgOp9ivzxPwB4ug8UKiIP2d71VS7GGOu%2FJS%2BjRg0UPVHGhSXezReW%2B8lcL2oXSTmKAaBdUEAuaiQOBU5UpeeZSH8nwd2wjOLl6wvGxsbcQsYwiykHXre0xKIfOD9ax%2B8YyC5ACGfVCczyiOtZpoIK8WdgEn2EtyGMkLgOpwSVIyBOfOWrQ%3D%3D","isStreaming":true,"duration":335,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-usc-mp1-t1-1-v4v6.pandora.com/access/1551165983902596569.mp3?version=5&lid=617752572&token=Dlo1Jx08HDrjuiHCx8Weh7YRJqeCcSk1EvskPAZBmUn7cXVJmKmcPxX9ahYya7tqyvR087PxV2r6I9572j9yPIfXE51Vw8GALTDQmlmFUA0HYHMMMyH4cbK%2FcWYsmqtMKr1vcpc8zzHpNwJcKimN5FztOUSeQdGDYjp%2FRgOp9ivzxPwB4ug8UKiIP2d71VS7GGOu%2FJS%2BjRg0UPVHGhSXezReW%2B8lcL2oXSTmKAaBdUEAuaiQOBU5UpeeZSH8nwd2wjOLl6wvGxsbcQsYwiykHXre0xKIfOD9ax%2B8YyC5ACGfVCczyiOtZpoIK8WdgEn2EtyGMkLgOpwSVIyBOfOWrQ%3D%3D","seek":0,"status":"stop"} May 15 01:47:55 pationew volumio[1093]: verbose: CURRENT POSITION 41 May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::syncState stateService stop May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:55 pationew volumio[1093]: info: No code May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::play index undefined May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current pandora Received mpd May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::startPlaybackTimer May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: info: [1747288075276] ControllerPandora::clearAddPlayTrack May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::clear May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 9ms May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 9ms May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 9 milliseconds May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand clear took 1 milliseconds May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 0ms May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:55 pationew volumio[1093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 01:47:55 pationew volumio[1093]: info: [1747288075278] ControllerPandora::checkForExpiredStations May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 11ms May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: [1747288075278] ControllerPandora::removeTrack May 15 01:47:55 pationew volumio[1093]: info: [1747288075278] [Pandora] removeTrack: Not removing track with uri: null at queue index: -1 May 15 01:47:55 pationew volumio[1093]: info: [1747288075278] ControllerPandora::appendTracksToMpd May 15 01:47:55 pationew volumio[1093]: info: [1747288075278] [Pandora] appendTracksToMpd: Added 1 track(s) to mpd May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand addid May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand play May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: error: updateQueue error: null May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 8ms May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand addid took 7 milliseconds May 15 01:47:55 pationew volumio[1093]: info: sendMpdCommand play took 7 milliseconds May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 7ms May 15 01:47:55 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:55 pationew volumio[1093]: verbose: MPD COMMAND [object Object] May 15 01:47:55 pationew volumio[1093]: info: [1747288075286] ControllerPandora::pushState May 15 01:47:55 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:55 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Chains of Love (2009 Remaster)","name":"Chains of Love (2009 Remaster)","artist":"Erasure","album":"Pop Deluxe Box","albumart":"http://mediaserver-cont-dc6-1-v4v6.pandora.com/images/6c/37/01/ef/6f6c43c289db3abcffd58117/1080W_1080H.jpg","realUri":"http://audio-sv5-t1-2-v4v6.pandora.com/access/6253376505598328688.mp3?version=5&lid=617752572&token=8kxOPF%2FnvYpsrjbOhZ3ikU3iGVmtgoyopG8twWqhO1cNH6wcuuxUSW3pBUdLLjmzoW6P83uYMmJQT%2FZyFHjJcUc4w9Es%2FbkZlGW33PaKVDCaILIuJHAGMjpbMk4pwXDbAbb2vG6gkEcRJIKUdC8Jd%2BAEUeyqhcQN6MfJh1WCjisQVaIE%2FWX%2Bey1Zhw%2FPay%2Fw912pAtdFrjtp7C8p0A1y1raM96lZdco4TTRBZCVTdDCpww2rud0g8BbpySX1iWz76yPRg7kizubVYJW2nxzWfAmsefHqAfKR7hQ7pyf5%2FT8GXQWW3b3jDvyO0j4wsxY8ygW%2FgsFqKmj9YLtQlxKv6g%3D%3D","isStreaming":true,"duration":224,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-sv5-t1-2-v4v6.pandora.com/access/6253376505598328688.mp3?version=5&lid=617752572&token=8kxOPF%2FnvYpsrjbOhZ3ikU3iGVmtgoyopG8twWqhO1cNH6wcuuxUSW3pBUdLLjmzoW6P83uYMmJQT%2FZyFHjJcUc4w9Es%2FbkZlGW33PaKVDCaILIuJHAGMjpbMk4pwXDbAbb2vG6gkEcRJIKUdC8Jd%2BAEUeyqhcQN6MfJh1WCjisQVaIE%2FWX%2Bey1Zhw%2FPay%2Fw912pAtdFrjtp7C8p0A1y1raM96lZdco4TTRBZCVTdDCpww2rud0g8BbpySX1iWz76yPRg7kizubVYJW2nxzWfAmsefHqAfKR7hQ7pyf5%2FT8GXQWW3b3jDvyO0j4wsxY8ygW%2FgsFqKmj9YLtQlxKv6g%3D%3D","seek":0,"status":"play"} May 15 01:47:55 pationew volumio[1093]: verbose: CURRENT POSITION 41 May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus stop May 15 01:47:55 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:55 pationew volumio[1093]: info: [1747288075286] ControllerPandora::fetchAndAddTracks May 15 01:47:55 pationew volumio[1093]: info: [1747288075286] ControllerPandora::getStationTracks May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: [1747288075287] [Pandora] PandoraHandler::getSongMaxDiff: -28 May 15 01:47:55 pationew volumio[1093]: info: [1747288075287] ControllerPandora::fetchAndAddTracks::getSqInfo May 15 01:47:55 pationew volumio[1093]: info: [1747288075287] ControllerPandora::getStationTracks May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:55 pationew volumio[1093]: info: [1747288075287] [Pandora] fetchAndAddTracks: diff1: -28 sQPos1: 0 May 15 01:47:55 pationew volumio[1093]: info: [1747288075287] [Pandora] fetchAndAddTracks: Fetching tracks May 15 01:47:55 pationew volumio[1093]: info: [1747288075287] ControllerPandora::PandoraHandler::fillStationData May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 4ms May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 1ms May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces system playlist update May 15 01:47:55 pationew volumio[1093]: info: Ignoring MPD Status Update May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 2ms May 15 01:47:55 pationew volumio[1093]: info: ------------------------------ 2ms May 15 01:47:55 pationew volumio[1093]: info: [1747288075657] ControllerPandora::pandoraListener May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:55 pationew volumio[1093]: info: May 15 01:47:55 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:55 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:55 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:55 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:55 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:55 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:55 pationew volumio[1093]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 15 01:47:55 pationew volumio[1093]: info: FusionDsp - ---- read samplerate from file: 44100 May 15 01:47:55 pationew volumio[1093]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 15 01:47:57 pationew volumio[1093]: info: May 15 01:47:57 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand status took 2039 milliseconds May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand status took 2038 milliseconds May 15 01:47:57 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:57 pationew volumio[1093]: info: May 15 01:47:57 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:47:57 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:47:57 pationew volumio[1093]: info: [1747288077698] ControllerPandora::PandoraHandler::fetchTracks::fetchStationPlaylist May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand status took 5 milliseconds May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand status took 5 milliseconds May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:57 pationew volumio[1093]: info: [1747288077703] ControllerPandora::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:57 pationew volumio[1093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":224,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Chains of Love (2009 Remaster)","artist":"Erasure","album":"Pop Deluxe Box","uri":"http://audio-sv5-t1-2-v4v6.pandora.com/access/6253376505598328688.mp3?version=5&lid=617752572&token=8kxOPF%2FnvYpsrjbOhZ3ikU3iGVmtgoyopG8twWqhO1cNH6wcuuxUSW3pBUdLLjmzoW6P83uYMmJQT%2FZyFHjJcUc4w9Es%2FbkZlGW33PaKVDCaILIuJHAGMjpbMk4pwXDbAbb2vG6gkEcRJIKUdC8Jd%2BAEUeyqhcQN6MfJh1WCjisQVaIE%2FWX%2Bey1Zhw%2FPay%2Fw912pAtdFrjtp7C8p0A1y1raM96lZdco4TTRBZCVTdDCpww2rud0g8BbpySX1iWz76yPRg7kizubVYJW2nxzWfAmsefHqAfKR7hQ7pyf5%2FT8GXQWW3b3jDvyO0j4wsxY8ygW%2FgsFqKmj9YLtQlxKv6g%3D%3D","trackType":"mp3"} May 15 01:47:57 pationew volumio[1093]: verbose: CURRENT POSITION 41 May 15 01:47:57 pationew volumio[1093]: info: CoreStateMachine::syncState stateService play May 15 01:47:57 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus play May 15 01:47:57 pationew volumio[1093]: info: Received an update from plugin. extracting info from payload May 15 01:47:57 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:57 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:47:57 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:47:57 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:57 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:57 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:57 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:57 pationew volumio[1093]: info: ------------------------------ 2049ms May 15 01:47:57 pationew volumio[1093]: info: ------------------------------ 2048ms May 15 01:47:57 pationew volumio[1093]: error: FusionDsp - WebSocket error: [object Object] May 15 01:47:57 pationew volumio[1093]: error: FusionDsp - WebSocket error: [object Object] May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 17 milliseconds May 15 01:47:57 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 18 milliseconds May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:57 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:47:57 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:57 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:57 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:47:57 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:47:57 pationew volumio[1093]: info: ------------------------------ 24ms May 15 01:47:57 pationew volumio[1093]: info: ------------------------------ 23ms May 15 01:47:57 pationew volumio[1093]: info: CoreCommandRouter::volumioGetQueue May 15 01:47:57 pationew volumio[1093]: info: CoreStateMachine::getQueue May 15 01:47:57 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: [1747288078460] [Pandora] PandoraHandler::fetchTracks::fetchStationPlaylist: Retrieved Erasure Radio playlist May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: [1747288078460] ControllerPandora::PandoraHandler::fetchTracks::fillNewTracks May 15 01:47:58 pationew volumio[1093]: info: [1747288078460] [Pandora] PandoraHandler::fetchTracks::fillNewTracks: Fetched 4 track(s) May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::addQueueItems May 15 01:47:58 pationew volumio[1093]: info: Preload queue cleared May 15 01:47:58 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=6895314375371227275 May 15 01:47:58 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=6895314375371227275 in service pandora May 15 01:47:58 pationew volumio[1093]: info: [1747288078461] ControllerPandora::explodeUri May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=1398447931405561977 May 15 01:47:58 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=1398447931405561977 in service pandora May 15 01:47:58 pationew volumio[1093]: info: [1747288078461] ControllerPandora::explodeUri May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=6139259081918808880 May 15 01:47:58 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=6139259081918808880 in service pandora May 15 01:47:58 pationew volumio[1093]: info: [1747288078461] ControllerPandora::explodeUri May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: Adding Item to queue: /pandora/stationToken=2230887914891519996trackId=3632079876470334260 May 15 01:47:58 pationew volumio[1093]: info: Exploding uri /pandora/stationToken=2230887914891519996trackId=3632079876470334260 in service pandora May 15 01:47:58 pationew volumio[1093]: info: [1747288078461] ControllerPandora::explodeUri May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: CoreCommandRouter::volumioPushQueue May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::saveQueue May 15 01:47:58 pationew volumio[1093]: info: CoreStateMachine::updateTrackBlock May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getTrackBlock May 15 01:47:58 pationew volumio[1093]: info: [1747288078469] ControllerPandora::getStationTracks May 15 01:47:58 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:47:58 pationew volumio[1093]: info: [1747288078469] [Pandora] PandoraHandler::getSongMaxDiff: -24 May 15 01:48:01 pationew volumio[1093]: info: CoreCommandRouter::volumioGetState May 15 01:48:08 pationew volumio[1093]: info: CorePlayQueue::getQueue May 15 01:48:08 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:48:08 pationew volumio[1093]: info: [1747288088901] ControllerPandora::ExpireOldTracks::reaper May 15 01:48:08 pationew volumio[1093]: info: [1747288088901] [Pandora] ExpireOldTracks::reaper: No victims found: Expiring zero tracks. Don't worry -- Jason will return. May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::volumioPause May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::pause May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::servicePause May 15 01:48:17 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::servicePause May 15 01:48:17 pationew volumio[1093]: info: [1747288097369] ControllerPandora::pause May 15 01:48:17 pationew volumio[1093]: info: ControllerMpd::pause May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand pause May 15 01:48:17 pationew volumio[1093]: info: May 15 01:48:17 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:48:17 pationew volumio[1093]: info: sendMpdCommand pause took 0 milliseconds May 15 01:48:17 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:48:17 pationew volumio[1093]: info: [1747288097371] ControllerPandora::pushState May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:48:17 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:48:17 pationew volumio[1093]: verbose: STATE SERVICE {"service":"pandora","type":"song","trackType":"mp3","title":"Chains of Love (2009 Remaster)","name":"Chains of Love (2009 Remaster)","artist":"Erasure","album":"Pop Deluxe Box","albumart":"http://mediaserver-cont-dc6-1-v4v6.pandora.com/images/6c/37/01/ef/6f6c43c289db3abcffd58117/1080W_1080H.jpg","realUri":"http://audio-sv5-t1-2-v4v6.pandora.com/access/6253376505598328688.mp3?version=5&lid=617752572&token=8kxOPF%2FnvYpsrjbOhZ3ikU3iGVmtgoyopG8twWqhO1cNH6wcuuxUSW3pBUdLLjmzoW6P83uYMmJQT%2FZyFHjJcUc4w9Es%2FbkZlGW33PaKVDCaILIuJHAGMjpbMk4pwXDbAbb2vG6gkEcRJIKUdC8Jd%2BAEUeyqhcQN6MfJh1WCjisQVaIE%2FWX%2Bey1Zhw%2FPay%2Fw912pAtdFrjtp7C8p0A1y1raM96lZdco4TTRBZCVTdDCpww2rud0g8BbpySX1iWz76yPRg7kizubVYJW2nxzWfAmsefHqAfKR7hQ7pyf5%2FT8GXQWW3b3jDvyO0j4wsxY8ygW%2FgsFqKmj9YLtQlxKv6g%3D%3D","isStreaming":true,"duration":224,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"uri":"http://audio-sv5-t1-2-v4v6.pandora.com/access/6253376505598328688.mp3?version=5&lid=617752572&token=8kxOPF%2FnvYpsrjbOhZ3ikU3iGVmtgoyopG8twWqhO1cNH6wcuuxUSW3pBUdLLjmzoW6P83uYMmJQT%2FZyFHjJcUc4w9Es%2FbkZlGW33PaKVDCaILIuJHAGMjpbMk4pwXDbAbb2vG6gkEcRJIKUdC8Jd%2BAEUeyqhcQN6MfJh1WCjisQVaIE%2FWX%2Bey1Zhw%2FPay%2Fw912pAtdFrjtp7C8p0A1y1raM96lZdco4TTRBZCVTdDCpww2rud0g8BbpySX1iWz76yPRg7kizubVYJW2nxzWfAmsefHqAfKR7hQ7pyf5%2FT8GXQWW3b3jDvyO0j4wsxY8ygW%2FgsFqKmj9YLtQlxKv6g%3D%3D","seek":22019,"status":"pause"} May 15 01:48:17 pationew volumio[1093]: verbose: CURRENT POSITION 41 May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::syncState stateService pause May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::syncState currentStatus pause May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::pushState May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::volumioPushState May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::stPlaybackTimer May 15 01:48:17 pationew volumio[1093]: info: CoreStateMachine::setConsumeUpdateService pandora May 15 01:48:17 pationew volumio[1093]: info: sendMpdCommand status took 3 milliseconds May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:48:17 pationew volumio[1093]: info: May 15 01:48:17 pationew volumio[1093]: ---------------------------- MPD announces state update: player May 15 01:48:17 pationew volumio[1093]: info: ControllerMpd::getState May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand status May 15 01:48:17 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 01:48:17 pationew volumio[1093]: info: sendMpdCommand status took 2 milliseconds May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::parseState May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 01:48:17 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:48:17 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:48:17 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:48:17 pationew volumio[1093]: info: ------------------------------ 9ms May 15 01:48:17 pationew volumio[1093]: info: sendMpdCommand playlistinfo took 0 milliseconds May 15 01:48:17 pationew volumio[1093]: verbose: ControllerMpd::parseTrackInfo May 15 01:48:17 pationew volumio[1093]: info: ControllerMpd::pushState May 15 01:48:17 pationew volumio[1093]: info: CoreCommandRouter::servicePushState May 15 01:48:17 pationew volumio[1093]: info: CorePlayQueue::getTrack 41 May 15 01:48:17 pationew volumio[1093]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current pandora Received mpd May 15 01:48:17 pationew volumio[1093]: info: ------------------------------ 6ms May 15 01:48:22 pationew nmbd[3041]: [2025/05/15 01:48:22.463803, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 15 01:48:22 pationew nmbd[3041]: Packet send failed to 192.168.1.1(1377) ERRNO=Network is unreachable May 15 01:48:22 pationew nmbd[3041]: [2025/05/15 01:48:22.463910, 0] ../source3/nmbd/nmbd_packets.c:1027(reply_netbios_packet) May 15 01:48:22 pationew nmbd[3041]: reply_netbios_packet: send_packet to IP 192.168.1.1 port 1377 failed May 15 01:48:22 pationew nmbd[3041]: [2025/05/15 01:48:22.839806, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 15 01:48:22 pationew nmbd[3041]: Packet send failed to 192.168.1.1(1377) ERRNO=Network is unreachable May 15 01:48:22 pationew nmbd[3041]: [2025/05/15 01:48:22.839876, 0] ../source3/nmbd/nmbd_packets.c:1027(reply_netbios_packet) May 15 01:48:22 pationew nmbd[3041]: reply_netbios_packet: send_packet to IP 192.168.1.1 port 1377 failed May 15 01:48:25 pationew volumio[1093]: info: CoreCommandRouter::volumioGetState May 15 01:48:36 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 15 01:48:36 pationew volumio[1093]: info: Preload queue cleared May 15 01:48:38 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 15 01:48:39 pationew volumio[1093]: info: Preload queue cleared May 15 01:48:39 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 15 01:48:40 pationew volumio[1093]: info: Preload queue cleared May 15 01:48:45 pationew volumio[1093]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 15 01:48:45 pationew volumio[1093]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 01:48:45 pationew volumio[1093]: TypeError: Cannot read property 'length' of undefined May 15 01:48:45 pationew volumio[1093]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 15 01:48:45 pationew volumio[1093]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 15 01:48:45 pationew volumio[1093]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 15 01:48:45 pationew volumio[1093]: at Parser.emit (events.js:315:20) May 15 01:48:45 pationew volumio[1093]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 15 01:48:45 pationew volumio[1093]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 15 01:48:45 pationew volumio[1093]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 15 01:48:45 pationew volumio[1093]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 15 01:48:45 pationew volumio[1093]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 15 01:48:45 pationew volumio[1093]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 15 01:48:45 pationew volumio[1093]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 15 01:48:45 pationew volumio[1093]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 15 01:48:45 pationew volumio[1093]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 15 01:48:45 pationew volumio[1093]: at IncomingMessage.emit (events.js:327:22) May 15 01:48:45 pationew volumio[1093]: at endReadableNT (internal/streams/readable.js:1327:12) May 15 01:48:45 pationew volumio[1093]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 15 01:48:45 pationew volumio[1093]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 01:48:45 pationew sudo[24197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-15 01:47 May 15 01:48:45 pationew sudo[24197]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:47:57 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fddd10196af80fdc784c726185a6abe4"