[09-09-30 09:59:21.0286] Slim::Player::StreamingController::stop (1951) 00:04:20:05:ab:fa
[09-09-30 09:59:21.0292] Slim::Player::StreamingController::resetSongqueue (1633) Song queue is now 
[09-09-30 09:59:38.8257] Slim::Player::StreamingController::stop (1951) 00:04:20:05:ab:fa
[09-09-30 09:59:38.8261] Slim::Player::StreamingController::resetSongqueue (1633) Song queue is now 
[09-09-30 09:59:38.8285] Slim::Utils::Misc::msg (1160) Warning: [09:59:38.8283] Backtrace:

   frame 0: Slim::Player::StreamingController::play (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 980)
   frame 1: Slim::Control::Commands::playlistJumpCommand (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 2: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 3: Slim::Control::Request::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 877)
   frame 4: Slim::Control::Request::executeRequest (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Player/Client.pm line 642)
   frame 5: Slim::Player::Client::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 2889)
   frame 6: Slim::Control::Commands::_playlistXitem_load_done (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 1477)
   frame 7: Slim::Control::Commands::__ANON__ (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Utils/Scanner.pm line 70)
   frame 8: Slim::Utils::Scanner::scanPathOrURL (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 1486)
   frame 9: Slim::Control::Commands::playlistXitemCommand (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 10: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 11: Slim::Control::Request::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 877)
   frame 12: Slim::Control::Request::executeRequest (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Player/Client.pm line 642)
   frame 13: Slim::Player::Client::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Buttons/XMLBrowser.pm line 1196)
   frame 14: Slim::Buttons::XMLBrowser::playItem (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Buttons/XMLBrowser.pm line 787)
   frame 15: Slim::Buttons::XMLBrowser::__ANON__ (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Buttons/Input/Choice.pm line 310)
   frame 16: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Buttons/Input/Choice.pm line 310)
   frame 17: Slim::Buttons::Input::Choice::callCallback (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Buttons/Input/Choice.pm line 269)
   frame 18: Slim::Buttons::Input::Choice::__ANON__ (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 1102)
   frame 19: Slim::Hardware::IR::executeButton (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 250)
   frame 20: Slim::Control::Commands::buttonCommand (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 21: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 22: Slim::Control::Request::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 877)
   frame 23: Slim::Control::Request::executeRequest (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Player/Client.pm line 642)
   frame 24: Slim::Player::Client::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 1123)
   frame 25: Slim::Hardware::IR::processCode (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 793)
   frame 26: Slim::Hardware::IR::processIR (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 478)
   frame 27: Slim::Control::Commands::irCommand (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 28: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 29: Slim::Control::Request::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 877)
   frame 30: Slim::Control::Request::executeRequest (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Player/Client.pm line 642)
   frame 31: Slim::Player::Client::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 123)
   frame 32: Slim::Hardware::IR::idle (./slimserver.pl line 601)
   frame 33: main::idle (./slimserver.pl line 574)
   frame 34: main::main (./slimserver.pl line 1103)

[09-09-30 09:59:38.8290] Slim::Player::StreamingController::play (1955) 00:04:20:05:ab:fa
[09-09-30 09:59:38.8298] Slim::Player::StreamingController::_setPlayingState (2223) new playing state STOPPED
[09-09-30 09:59:38.8301] Slim::Player::StreamingController::_setStreamingState (2236) new streaming state IDLE
[09-09-30 09:59:38.8307] Slim::Player::Song::new (107) index 0 -> pandora://144893509167694149.mp3
[09-09-30 09:59:38.8324] Slim::Player::StreamingController::_setStreamingState (2236) new streaming state TRACKWAIT
[09-09-30 09:59:38.8328] Slim::Player::Song::getNextSong (228) pandora://144893509167694149.mp3
[09-09-30 09:59:38.8331] Slim::Player::Song::getNextSong (250) scanning URL pandora://144893509167694149.mp3
[09-09-30 09:59:38.8334] Slim::Player::Song::__ANON__ (296) Found a playlist
[09-09-30 09:59:38.8338] Slim::Player::Song::getNextSong (228) pandora://144893509167694149.mp3
[09-09-30 09:59:38.8343] Slim::Plugin::Pandora::ProtocolHandler::getNextTrack (165) Getting next track from SqueezeNetwork for stationid=144893509167694149
[09-09-30 09:59:38.8359] Slim::Player::StreamingController::_playersMessage (777) Fetching track details...: pandora://144893509167694149.mp3
[09-09-30 09:59:39.0799] Slim::Utils::Misc::msg (1160) Warning: [09:59:39.0796] Backtrace:

   frame 0: Slim::Player::StreamingController::play (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 980)
   frame 1: Slim::Control::Commands::playlistJumpCommand (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 2: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 3: Slim::Control::Request::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 877)
   frame 4: Slim::Control::Request::executeRequest (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Player/Client.pm line 642)
   frame 5: Slim::Player::Client::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Buttons/Playlist.pm line 235)
   frame 6: Slim::Buttons::Playlist::__ANON__ (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 1102)
   frame 7: Slim::Hardware::IR::executeButton (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Commands.pm line 250)
   frame 8: Slim::Control::Commands::buttonCommand (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 9: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 1914)
   frame 10: Slim::Control::Request::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Control/Request.pm line 877)
   frame 11: Slim::Control::Request::executeRequest (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Player/Client.pm line 642)
   frame 12: Slim::Player::Client::execute (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 1123)
   frame 13: Slim::Hardware::IR::processCode (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 941)
   frame 14: Slim::Hardware::IR::releaseCode (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Hardware/IR.pm line 621)
   frame 15: Slim::Hardware::IR::checkRelease (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Utils/Timers.pm line 255)
   frame 16: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Utils/Timers.pm line 255)
   frame 17: Slim::Utils::Timers::__ANON__ (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Networking/IO/Select.pm line 184)
   frame 18: (eval) (/Users/andy/dev/Slim/7.4/trunk/server/Slim/Networking/IO/Select.pm line 184)
   frame 19: Slim::Networking::IO::Select::loop (./slimserver.pl line 620)
   frame 20: main::idle (./slimserver.pl line 574)
   frame 21: main::main (./slimserver.pl line 1103)

[09-09-30 09:59:39.0805] Slim::Player::StreamingController::play (1955) 00:04:20:05:ab:fa
[09-09-30 09:59:39.0813] Slim::Player::StreamingController::_Stop (607) Song queue is now 0
[09-09-30 09:59:39.0817] Slim::Player::StreamingController::_setPlayingState (2223) new playing state STOPPED
[09-09-30 09:59:39.0820] Slim::Player::StreamingController::_setStreamingState (2236) new streaming state IDLE
[09-09-30 09:59:39.0827] Slim::Player::Song::new (107) index 0 -> pandora://144893509167694149.mp3
[09-09-30 09:59:39.0833] Slim::Player::StreamingController::_setStreamingState (2236) new streaming state TRACKWAIT
[09-09-30 09:59:39.0837] Slim::Player::Song::getNextSong (228) pandora://144893509167694149.mp3
[09-09-30 09:59:39.0840] Slim::Player::Song::getNextSong (250) scanning URL pandora://144893509167694149.mp3
[09-09-30 09:59:39.0844] Slim::Player::Song::__ANON__ (296) Found a playlist
[09-09-30 09:59:39.0848] Slim::Player::Song::getNextSong (228) pandora://144893509167694149.mp3
[09-09-30 09:59:39.0853] Slim::Plugin::Pandora::ProtocolHandler::getNextTrack (165) Getting next track from SqueezeNetwork for stationid=144893509167694149
[09-09-30 09:59:39.0876] Slim::Player::StreamingController::_playersMessage (777) Fetching track details...: pandora://144893509167694149.mp3
[09-09-30 09:59:39.3928] Slim::Plugin::Pandora::ProtocolHandler::gotNextTrack (190) Got Pandora track: {
  albumArtUrl             => "http://images-sjl-4.pandora.com/images/public/amz/8/2/3/0/767715000328_455W_455H.jpg",
  albumDetailUrl          => "http://www.pandora.com/music/album/various+artists/zen+connection+vol+3?ad=1:30:1:16066:ip,ip:0",
  albumName               => "Zen Connection, Vol. 3",
  allowFeedback           => bless(do{\(my $o = 1)}, "JSON::XS::Boolean"),
  amazonAlbumAsin         => "B000071KCF",
  amazonAlbumUrl          => "http://www.amazon.com/dp/B000BF0DC4/?",
  "amazonSongDigitalAsin" => "B000QVROQ6",
  artistDetailUrl         => "http://www.pandora.com/music/artist/kaya+project?ad=1:30:1:16066:ip,ip:0",
  artistName              => "Kaya Project",
  audioUrl                => "http://audio-sjl-1.pandora.com/access/4752623757233467813?version=4&lid=3359045&token=eOwiJxTKsIQuquxma0er1v7LuUdQiz2o9LGkA%2FllhnEAA3a0JLMF%2BSGN8C1uXuNMXAK%2Bh6uJrfOz7yHy8xDa0Pw1hBP3py9bmMOt4fb0ovnP5%2B0n0gNvvjgT0TCmACxUdeSRUA6cuBxfOaRlF%2BjidGoGqa7yJGQ8gXdUAIPz6gcxusGNFxEql0qm5071xtryaJxi%2B4cxoj4SEpdkNsW990z1kSq0TkLPlfFNNzNHsVo29FuXitwwycTPW38al4Hb2BEcjelQPZxBLUoBma%2FRXnFuiKm3ZOqB7vGgHnGEkaRzLzfJ6gnW9t%2BOSIyjsrBw",
  canSkip                 => 1,
  itunesSongUrl           => "http://click.linksynergy.com/fs-bin/stat?id=FLenzF8lvbI&offerid=78941&type=3&subid=0&tmpid=1826&RD_PARM1=http%253A%252F%252Fphobos.apple.com%252FWebObjects%252FMZStore.woa%252Fwa%252FviewAlbum%253Fi%253D14327768%2526id%253D14327828%2526partnerId%3D30",
  secs                    => 366,
  songDetailUrl           => "http://www.pandora.com/music/song/kaya+project/walking+through?ad=1:30:1:16066:ip,ip:0",
  songName                => "Walking Through",
  songRating              => 1,
  stationId               => "144893509167694149",
  trackGain               => "-4.67",
  trackToken              => "b5686b7009d7fc3888bd9f7edbfad8a9d42f99b98d5a87fdc3964f4affdb79b25535e63d36e2b3b5",
}
[09-09-30 09:59:39.3934] Slim::Player::StreamingController::_nextTrackReady (726) 00:04:20:05:ab:fa: discarding unexpected nextTrackCallbackId 3, expected 5
[09-09-30 09:59:39.5185] Slim::Plugin::Pandora::ProtocolHandler::gotNextTrack (190) Got Pandora track: {
  albumArtUrl              => "http://images-sjl-2.pandora.com/images/public/amz/2/2/5/0/625978110522_500W_500H.jpg",
  albumDetailUrl           => "http://www.pandora.com/music/album/ammoncontact/new+birth?ad=1:30:1:16066:ip,ip:0",
  albumName                => "New Birth",
  allowFeedback            => bless(do{\(my $o = 1)}, "JSON::XS::Boolean"),
  amazonAlbumAsin          => "B0009J2RW6",
  "amazonAlbumDigitalAsin" => "B001B1QWWW",
  amazonAlbumUrl           => "http://www.amazon.com/dp/B0009J2RW6/?",
  "amazonSongDigitalAsin"  => "B001B1VYSO",
  artistDetailUrl          => "http://www.pandora.com/music/artist/ammoncontact?ad=1:30:1:16066:ip,ip:0",
  artistName               => "Ammoncontact",
  audioUrl                 => "http://audio-sjl-4.pandora.com/access/3202000003709829451?version=4&lid=3359045&token=3WcOLjOCS%2FOR36lv4fBPRaNtAWLdP2cSIfAMTFo%2Bopi%2FbDhUblMZdcSe5%2FEirSBbH3JWYBRtgVfia%2FLNB3XEIxTgxrhviASvoccvYenUG5s2yKb1gz%2BAQd6FkK%2Bu7gPsrHPLdfENDQhF3MUsoOaFwMfXO8OFV5XWk6Vmjr2aXKQLjjB9nhnbKPPZiOiTbjjf0eCLxAuuOAIQ%2Bge8SRI7vDWJqGHzrJxYyUf6xsbgzzyosPMYvdVC1XxS%2BpuDzqzuPOTcGdwwMAgh8lU76thtJoiKHYijrsFxqNfd3DX6fJX9r%2BCo%2BREFCTP1GBjBv1nf",
  canSkip                  => 1,
  itunesSongUrl            => "http://click.linksynergy.com/fs-bin/stat?id=FLenzF8lvbI&offerid=78941&type=3&subid=0&tmpid=1826&RD_PARM1=http%253A%252F%252Fphobos.apple.com%252FWebObjects%252FMZStore.woa%252Fwa%252FviewAlbum%253Fi%253D104881221%2526id%253D104881718%2526partnerId%3D30",
  secs                     => 139,
  songDetailUrl            => "http://www.pandora.com/music/song/ammoncontact/naeem?ad=1:30:1:16066:ip,ip:0",
  songName                 => "Naeem",
  songRating               => 0,
  stationId                => "144893509167694149",
  trackGain                => "-2.01",
  trackToken               => "d33b0228c925c90788bd9f7edbfad8a9d42f99b98d5a87fdc3964f4affdb79b25535e63d36e2b3b5",
}
[09-09-30 09:59:39.5191] Slim::Player::StreamingController::_nextTrackReady (733) 00:04:20:05:ab:fa: nextTrack will be index 0
[09-09-30 09:59:39.5195] Slim::Player::StreamingController::_Stream (1160) Song queue is now 0
[09-09-30 09:59:39.5199] Slim::Player::StreamingController::_Stream (1163) 00:04:20:05:ab:fa: preparing to stream song index 0
[09-09-30 09:59:39.5203] Slim::Player::Song::open (357) pandora://144893509167694149.mp3
[09-09-30 09:59:39.5212] Slim::Player::TranscodingHelper::getConvertCommand2 (430) Error: Didn't find any command matches for type: mp3
[09-09-30 09:59:39.5216] Slim::Player::Song::open (377) seek=false time=0 canSeek=0SEEK_ERROR_TYPE_NOT_SUPPORTEDPandora
[09-09-30 09:59:39.5223] Slim::Player::TranscodingHelper::getConvertCommand2 (433) Matched: mp3->mp3 via: -
[09-09-30 09:59:39.5226] Slim::Player::Song::open (398) Transcoder: streamMode=I, streamformat=mp3
[09-09-30 09:59:39.5231] Slim::Player::Song::open (436) URL supports direct streaming [pandora://144893509167694149.mp3->http://audio-sjl-4.pandora.com/access/3202000003709829451?version=4&lid=3359045&token=3WcOLjOCS%2FOR36lv4fBPRaNtAWLdP2cSIfAMTFo%2Bopi%2FbDhUblMZdcSe5%2FEirSBbH3JWYBRtgVfia%2FLNB3XEIxTgxrhviASvoccvYenUG5s2yKb1gz%2BAQd6FkK%2Bu7gPsrHPLdfENDQhF3MUsoOaFwMfXO8OFV5XWk6Vmjr2aXKQLjjB9nhnbKPPZiOiTbjjf0eCLxAuuOAIQ%2Bge8SRI7vDWJqGHzrJxYyUf6xsbgzzyosPMYvdVC1XxS%2BpuDzqzuPOTcGdwwMAgh8lU76thtJoiKHYijrsFxqNfd3DX6fJX9r%2BCo%2BREFCTP1GBjBv1nf]
[09-09-30 09:59:39.5251] Slim::Player::StreamingController::_Stream (1214) 00:04:20:05:ab:fa: stream
[09-09-30 09:59:39.5256] Slim::Plugin::Pandora::ProtocolHandler::trackGain (362) Using replaygain value of -2.01 for Pandora track
[09-09-30 09:59:39.5612] Slim::Player::StreamingController::_Stream (1245) Song queue is now 0
[09-09-30 09:59:39.5618] Slim::Player::StreamingController::_setPlayingState (2223) new playing state BUFFERING
[09-09-30 09:59:39.5668] Slim::Player::StreamingController::_setStreamingState (2236) new streaming state STREAMING
[09-09-30 09:59:39.6519] Slim::Player::Player::_buffering (1135) Buffering... 0 / 20480
[09-09-30 09:59:39.7890] Slim::Player::TranscodingHelper::getConvertCommand2 (430) Error: Didn't find any command matches for type: mp3
[09-09-30 09:59:39.9537] Slim::Player::Player::_buffering (1135) Buffering... 0 / 20480
[09-09-30 09:59:40.2551] Slim::Player::Player::_buffering (1135) Buffering... 1200 / 20480
[09-09-30 09:59:40.5563] Slim::Player::Player::_buffering (1135) Buffering... 9959 / 20480
[09-09-30 09:59:40.6068] Slim::Player::StreamingController::playerTrackStarted (2035) 00:04:20:05:ab:fa
[09-09-30 09:59:40.6073] Slim::Player::StreamingController::_setPlayingState (2223) new playing state PLAYING
[09-09-30 09:59:40.6076] Slim::Player::StreamingController::_Playing (361) Song 0 has now started playing
[09-09-30 09:59:40.6083] Slim::Player::StreamingController::_Playing (391) Song queue is now 0
[09-09-30 09:59:49.8411] Slim::Player::TranscodingHelper::getConvertCommand2 (430) Error: Didn't find any command matches for type: mp3
[09-09-30 10:00:09.4827] Slim::Player::StreamingController::playerEndOfStream (2132) 00:04:20:05:ab:fa
[09-09-30 10:00:09.4835] Slim::Player::StreamingController::_setStreamingState (2236) new streaming state STREAMOUT