Bug 1401 - Stopping OGG playback makes sox process use 100% CPU
: Stopping OGG playback makes sox process use 100% CPU
Status: RESOLVED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Transcoding
: 6.0.1
: PC Debian Linux
: P2 major (vote)
: ---
Assigned To: Dan Sully
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2005-04-20 15:54 UTC by Michel Marti
Modified: 2009-09-08 09:30 UTC (History)
3 users (show)

See Also:
Category: ---


Attachments
debian sox patches (9.74 KB, application/x-gzip)
2005-07-29 01:00 UTC, Michel Marti
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Michel Marti 2005-04-20 15:54:44 UTC
When stopping ogg-playback, the sox process does not dissapear for a rather long
time and consumes 100% CPU. 

Steps to reproduce:

1. Play a really big ogg file (like an archived radio show)
2. Stop playback
3. Invoke 'top' on the server and watch the "sox" process


Output from top:

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
                                                                 
16844 slimp3    25   0  2460 1432 1140 R 99.0  0.3   5:05.73
/opt/SlimServer_v6.0.1/Bin/i386-linux/sox -t ogg ...

Seems like sox keeps transcoding "full-throttle" if slimserver closes the pipe
to the process... Maybe killing sox would be the right thing to do?
Comment 1 Vidur Apparao 2005-04-21 16:35:08 UTC
Hmm...I've confirmed that sox dies correctly on OS X and Windows. This may be
platform-specific.
Comment 2 Michel Marti 2005-05-23 15:42:14 UTC
Vidur: Maybe you could ask Dan Sully to test this since he is running Debian
SID?!? BTW: The problem still appears using the latest SVN (trunk) version.
Comment 3 Blackketter Dean 2005-06-07 15:49:13 UTC
Dan: does this happen for you on debian?
Comment 4 Blackketter Dean 2005-06-13 22:28:41 UTC
*** Bug 1665 has been marked as a duplicate of this bug. ***
Comment 5 Chris Buzek 2005-06-24 03:58:09 UTC
Same here on my windows 2000 box.
Comment 6 Vidur Apparao 2005-06-30 14:57:09 UTC
ChrisB, you're saying that you're able to recreate this on Windows 2000? Could
you describe the exact steps...I wasn't able to do this on Windows XP.
Comment 7 Chris Buzek 2005-07-02 17:34:52 UTC
Vidur: I just start playing any playlist with ogg files and then press "next" or 
"previous", or "stop", or "play" (obviously, every command is affected that 
sends a "stop" to the current playing song). Then the server hangs, after a 
couple of secs SB says that it has lost connection to the server, and when it 
recovers again, the command is executed. In case of "next", "previous" and 
"play", the song timer is counting, but no music is heared. Then I press "stop", 
and after waiting again for the server to recover, I press "play", and the music 
finally plays. 

But I made an interesting observation: the timespan the slimserver uses 100% cpu 
is about proportional to the length of the current playlist. Pressing "stop" in 
a playlist with 12 songs, the server hangs 15 secs. Doing the same with a 180 
songs playlist, the server hangs for about 160 seconds.

Besides: Slimserver runs on a VIA Epia C3 system with 600 MHz and 256 MB ram. My 
database contains about 6000 songs.
Comment 8 Vidur Apparao 2005-07-19 13:19:01 UTC
ChrisB, any chance you could post a debug log with the --d_source flag specified
when you play one of these playlists? 
Comment 9 Chris Buzek 2005-07-21 11:48:51 UTC
Vidur: Sure. Here's what I did:

20:39:15 selected a playlist with 8 songs and pressed "play" => ok
20:39:46 pressed "next" => server hangs
20:40:14 server recovered, SB displays playing, but no sound
20:40:36 pressed "stop" => sever hangs
20:41:01 server recovered, stopped
20:41:21 pressed "play" => ok

And here's the log:

2005-07-21 20:39:15.8248 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 979)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/BrowseID3.pm 
line 342)
   frame 2: Slim::Buttons::BrowseID3::__ANON__ (/PerlApp/Slim/Hardware/IR.pm 
line 616)
   frame 3: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 4: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 5: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 6: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 7: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 8: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 9: main::idle (slimserver.pl line 40)
   frame 10: PerlSvc::Startup (perlsvc line 1204)
   frame 11: PerlSvc::_startup (slimserver.pl line 0)
   frame 12: (eval) (slimserver.pl line 0)

2005-07-21 20:39:15.8438 00:04:20:05:76:88: Switching to mode stop from stop
2005-07-21 20:39:15.8475  Already in playmode stop : ignoring mode change
2005-07-21 20:39:15.8501 Adding song index 0 to song queue
2005-07-21 20:39:15.8523 Clearing out song queue first
2005-07-21 20:39:15.8546 Song queue is now 0
2005-07-21 20:39:15.8621 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
742)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
985)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/BrowseID3.pm 
line 342)
   frame 3: Slim::Buttons::BrowseID3::__ANON__ (/PerlApp/Slim/Hardware/IR.pm 
line 616)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 6: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 7: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 8: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 9: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:39:15.8655 00:04:20:05:76:88: Switching to mode stop from stop
2005-07-21 20:39:15.8679  Already in playmode stop : ignoring mode change
2005-07-21 20:39:15.8702 jumping to 0
2005-07-21 20:39:15.8725 Adding song index 0 to song queue
2005-07-21 20:39:15.8747 Clearing out song queue first
2005-07-21 20:39:15.8770 Song queue is now 0
2005-07-21 20:39:15.8804 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
772)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
985)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/BrowseID3.pm 
line 342)
   frame 3: Slim::Buttons::BrowseID3::__ANON__ (/PerlApp/Slim/Hardware/IR.pm 
line 616)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 6: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 7: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 8: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 9: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:39:15.8855 00:04:20:05:76:88: Switching to mode play from stop
2005-07-21 20:39:15.9356 openSong on: file:///D:/Audio/Alben/Dream%20Theater/
1989_When%20Dream%20And%20Day%20Unite/01_A%20Fortune%20In%20Lies.ogg
2005-07-21 20:39:15.9536 openSong: getting duration  312, size 4862161, endian  
and offset 477 for file:///D:/Audio/Alben/Dream%20Theater/1989_When%20Dream%
20And%20Day%20Unite/01_A%20Fortune%20In%20Lies.ogg
2005-07-21 20:39:15.9583 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:39:15.9636 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:39:16.0229 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:39:16.0259 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:39:16.0284 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-21 20:39:16.0312 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0336 Checking to see if ogg-aif-squeezebox-00:04:20:05:76:88 
is enabled
2005-07-21 20:39:16.0362 There are 10 disabled formats...
2005-07-21 20:39:16.0387 Testing wma-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0411 Testing wma-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0436 Testing ogg-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0460 Testing mpc-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0485 Testing mpc-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0510 Testing mpc-aif-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0535 Testing mov-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0560 Testing mov-aif-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0585 Testing ape-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0610 Testing ape-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0635 Testing aif-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:39:16.0659    enabled
2005-07-21 20:39:16.0686 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0711 Checking to see if ogg-aif-*-00:04:20:05:76:88 is 
enabled
2005-07-21 20:39:16.0737 There are 10 disabled formats...
2005-07-21 20:39:16.0763 Testing wma-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0789 Testing wma-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0814 Testing ogg-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0840 Testing mpc-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0866 Testing mpc-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0892 Testing mpc-aif-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0917 Testing mov-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0943 Testing mov-aif-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0968 Testing ape-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.0994 Testing ape-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.1020 Testing aif-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:39:16.1045    enabled
2005-07-21 20:39:16.1071 checking formats for: ogg-aif-squeezebox-*
2005-07-21 20:39:16.1096 Checking to see if ogg-aif-squeezebox-* is enabled
2005-07-21 20:39:16.1123 There are 10 disabled formats...
2005-07-21 20:39:16.1149 Testing wma-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1181 Testing wma-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1208 Testing ogg-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1233 Testing mpc-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1260 Testing mpc-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1286 Testing mpc-aif-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1312 Testing mov-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1338 Testing mov-aif-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1365 Testing ape-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1391 Testing ape-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1417 Testing aif-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:39:16.1443    enabled
2005-07-21 20:39:16.1469 checking formats for: ogg-aif-*-*
2005-07-21 20:39:16.1496 Checking to see if ogg-aif-*-* is enabled
2005-07-21 20:39:16.1523 There are 10 disabled formats...
2005-07-21 20:39:16.1550 Testing wma-wav-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1576 Testing wma-flc-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1603 Testing ogg-flc-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1629 Testing mpc-wav-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1656 Testing mpc-flc-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1684 Testing mpc-aif-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1710 Testing mov-flc-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1736 Testing mov-aif-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1763 Testing ape-wav-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1790 Testing ape-flc-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1816 Testing aif-flc-*-* vs ogg-aif-*-*
2005-07-21 20:39:16.1843    enabled
2005-07-21 20:39:16.1869   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-21 20:39:16.1919 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:39:16.1951 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:39:16.1979 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-21 20:39:16.2007 openSong: this is an ogg file: file:///D:/Audio/Alben/
Dream%20Theater/1989_When%20Dream%20And%20Day%20Unite/01_A%20Fortune%20In%
20Lies.ogg
2005-07-21 20:39:16.2033   file type: ogg format: aif inrate: 128.003 maxRate: 0
2005-07-21 20:39:16.2060   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-21 20:39:16.2108 Using command for conversion: "C:
\Programme\SlimServer602\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\Alben\Dream Theater\1989_When Dream And Day Unite\01_A Fortune In Lies.
ogg" -t raw -r 44100 -c 2 -w -s -x - |
2005-07-21 20:39:16.2289 Streaming with format: aif
2005-07-21 20:39:16.4757 00:04:20:05:76:88 New play mode: play
2005-07-21 20:39:16.4855 00:04:20:05:76:88: Current playmode: play
2005-07-21 20:39:46.3786 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
742)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1208)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/Common.pm 
line 177)
   frame 3: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
616)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 6: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 7: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 8: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 9: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:39:46.3879 00:04:20:05:76:88: Switching to mode stop from play
2005-07-21 20:39:46.3922 00:04:20:05:76:88 New play mode: stop
2005-07-21 20:39:46.3952 Stopping and clearing out old chunks for client 00:04:
20:05:76:88
2005-07-21 20:40:13.8282 Resetting song queue
2005-07-21 20:40:13.8282 Song queue is now 0
2005-07-21 20:40:13.8313 00:04:20:05:76:88: Current playmode: stop
2005-07-21 20:40:13.8343 jumping by +1
2005-07-21 20:40:13.8371 Adding song index 1 to song queue
2005-07-21 20:40:13.8398 Clearing out song queue first
2005-07-21 20:40:13.8427 Song queue is now 1
2005-07-21 20:40:13.8466 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
772)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1208)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/Common.pm 
line 177)
   frame 3: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
616)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 6: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 7: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 8: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 9: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:40:13.8524 00:04:20:05:76:88: Switching to mode play from stop
2005-07-21 20:40:13.8865 openSong on: file:///D:/Audio/Alben/Dream%20Theater/
1989_When%20Dream%20And%20Day%20Unite/02_Status%20Seeker.ogg
2005-07-21 20:40:13.9044 openSong: getting duration  256, size 3864088, endian  
and offset 473 for file:///D:/Audio/Alben/Dream%20Theater/1989_When%20Dream%
20And%20Day%20Unite/02_Status%20Seeker.ogg
2005-07-21 20:40:13.9078 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:40:13.9109 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:40:13.9698 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:40:13.9728 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:40:13.9754 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-21 20:40:13.9783 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:13.9808 Checking to see if ogg-aif-squeezebox-00:04:20:05:76:88 
is enabled
2005-07-21 20:40:13.9836 There are 10 disabled formats...
2005-07-21 20:40:13.9861 Testing wma-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:13.9887 Testing wma-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:13.9913 Testing ogg-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:13.9939 Testing mpc-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:13.9965 Testing mpc-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:13.9991 Testing mpc-aif-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:14.0018 Testing mov-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:14.0044 Testing mov-aif-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:14.0070 Testing ape-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:14.0096 Testing ape-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:14.0122 Testing aif-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:40:14.0147    enabled
2005-07-21 20:40:14.0174 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0217 Checking to see if ogg-aif-*-00:04:20:05:76:88 is 
enabled
2005-07-21 20:40:14.0247 There are 10 disabled formats...
2005-07-21 20:40:14.0276 Testing wma-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0305 Testing wma-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0335 Testing ogg-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0364 Testing mpc-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0393 Testing mpc-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0422 Testing mpc-aif-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0451 Testing mov-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0480 Testing mov-aif-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0510 Testing ape-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0540 Testing ape-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0569 Testing aif-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:40:14.0598    enabled
2005-07-21 20:40:14.0629 checking formats for: ogg-aif-squeezebox-*
2005-07-21 20:40:14.0658 Checking to see if ogg-aif-squeezebox-* is enabled
2005-07-21 20:40:14.0689 There are 10 disabled formats...
2005-07-21 20:40:14.0725 Testing wma-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0755 Testing wma-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0784 Testing ogg-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0813 Testing mpc-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0843 Testing mpc-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0873 Testing mpc-aif-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0902 Testing mov-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0960 Testing mov-aif-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.0986 Testing ape-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.1013 Testing ape-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.1040 Testing aif-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:40:14.1067    enabled
2005-07-21 20:40:14.1094 checking formats for: ogg-aif-*-*
2005-07-21 20:40:14.1120 Checking to see if ogg-aif-*-* is enabled
2005-07-21 20:40:14.1148 There are 10 disabled formats...
2005-07-21 20:40:14.1175 Testing wma-wav-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1202 Testing wma-flc-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1229 Testing ogg-flc-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1255 Testing mpc-wav-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1282 Testing mpc-flc-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1309 Testing mpc-aif-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1336 Testing mov-flc-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1363 Testing mov-aif-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1389 Testing ape-wav-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1417 Testing ape-flc-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1443 Testing aif-flc-*-* vs ogg-aif-*-*
2005-07-21 20:40:14.1470    enabled
2005-07-21 20:40:14.1496   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-21 20:40:14.1547 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:40:14.1579 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:40:14.1606 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-21 20:40:14.1634 openSong: this is an ogg file: file:///D:/Audio/Alben/
Dream%20Theater/1989_When%20Dream%20And%20Day%20Unite/02_Status%20Seeker.ogg
2005-07-21 20:40:14.1661   file type: ogg format: aif inrate: 128.003 maxRate: 0
2005-07-21 20:40:14.1688   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-21 20:40:14.1737 Using command for conversion: "C:
\Programme\SlimServer602\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\Alben\Dream Theater\1989_When Dream And Day Unite\02_Status Seeker.ogg" -
t raw -r 44100 -c 2 -w -s -x - |
2005-07-21 20:40:14.1799 Streaming with format: aif
2005-07-21 20:40:14.3896 00:04:20:05:76:88 New play mode: play
2005-07-21 20:40:14.4048 00:04:20:05:76:88: Current playmode: play
2005-07-21 20:40:14.4105 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 597)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/Common.pm 
line 194)
   frame 2: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
616)
   frame 3: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 4: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 5: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 6: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 7: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 8: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 9: main::idle (slimserver.pl line 40)
   frame 10: PerlSvc::Startup (perlsvc line 1204)
   frame 11: PerlSvc::_startup (slimserver.pl line 0)
   frame 12: (eval) (slimserver.pl line 0)

2005-07-21 20:40:14.4150 00:04:20:05:76:88: Switching to mode play from play
2005-07-21 20:40:14.4197  Already in playmode play : ignoring mode change
2005-07-21 20:40:36.9453 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 634)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/Common.pm 
line 250)
   frame 2: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
616)
   frame 3: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 4: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 5: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
514)
   frame 6: Slim::Hardware::IR::holdCode (/PerlApp/Slim/Hardware/IR.pm line 437)
   frame 7: Slim::Hardware::IR::processIR (/PerlApp/Slim/Control/Command.pm line 
587)
   frame 8: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
87)
   frame 9: Slim::Hardware::IR::idle (slimserver.pl line 596)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:40:36.9499 00:04:20:05:76:88: Switching to mode stop from play
2005-07-21 20:40:36.9532 00:04:20:05:76:88 New play mode: stop
2005-07-21 20:40:36.9565 Stopping and clearing out old chunks for client 00:04:
20:05:76:88
2005-07-21 20:41:01.8472 Resetting song queue
2005-07-21 20:41:01.8472 Song queue is now 1
2005-07-21 20:41:01.8521 00:04:20:05:76:88: Current playmode: stop
2005-07-21 20:41:21.0650 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
742)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1208)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/Playlist.pm 
line 157)
   frame 3: Slim::Buttons::Playlist::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
616)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 6: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 7: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 8: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 9: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:41:21.0698 00:04:20:05:76:88: Switching to mode stop from stop
2005-07-21 20:41:21.0729  Already in playmode stop : ignoring mode change
2005-07-21 20:41:21.0761 jumping to 1
2005-07-21 20:41:21.0793 Adding song index 1 to song queue
2005-07-21 20:41:21.0825 Clearing out song queue first
2005-07-21 20:41:21.0857 Song queue is now 1
2005-07-21 20:41:21.0900 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
772)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1208)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Buttons/Playlist.pm 
line 157)
   frame 3: Slim::Buttons::Playlist::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
616)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 587)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Hardware/IR.pm line 
640)
   frame 6: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
499)
   frame 7: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
394)
   frame 8: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
62)
   frame 9: Slim::Utils::Timers::checkTimers (slimserver.pl line 624)
   frame 10: main::idle (slimserver.pl line 40)
   frame 11: PerlSvc::Startup (perlsvc line 1204)
   frame 12: PerlSvc::_startup (slimserver.pl line 0)
   frame 13: (eval) (slimserver.pl line 0)

2005-07-21 20:41:21.0948 00:04:20:05:76:88: Switching to mode play from stop
2005-07-21 20:41:21.1005 openSong on: file:///D:/Audio/Alben/Dream%20Theater/
1989_When%20Dream%20And%20Day%20Unite/02_Status%20Seeker.ogg
2005-07-21 20:41:21.1107 openSong: getting duration  256, size 3864088, endian  
and offset 473 for file:///D:/Audio/Alben/Dream%20Theater/1989_When%20Dream%
20And%20Day%20Unite/02_Status%20Seeker.ogg
2005-07-21 20:41:21.1149 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:41:21.1186 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:41:21.1741 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:41:21.1779 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:41:21.1812 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-21 20:41:21.1847 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.1879 Checking to see if ogg-aif-squeezebox-00:04:20:05:76:88 
is enabled
2005-07-21 20:41:21.1912 There are 10 disabled formats...
2005-07-21 20:41:21.1945 Testing wma-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.1977 Testing wma-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2010 Testing ogg-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2042 Testing mpc-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2074 Testing mpc-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2106 Testing mpc-aif-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2139 Testing mov-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2171 Testing mov-aif-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2203 Testing ape-wav-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2236 Testing ape-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2268 Testing aif-flc-*-* vs ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-21 20:41:21.2301    enabled
2005-07-21 20:41:21.2333 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2365 Checking to see if ogg-aif-*-00:04:20:05:76:88 is 
enabled
2005-07-21 20:41:21.2399 There are 10 disabled formats...
2005-07-21 20:41:21.2431 Testing wma-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2463 Testing wma-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2496 Testing ogg-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2530 Testing mpc-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2562 Testing mpc-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2594 Testing mpc-aif-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2632 Testing mov-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2665 Testing mov-aif-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2698 Testing ape-wav-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2757 Testing ape-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2790 Testing aif-flc-*-* vs ogg-aif-*-00:04:20:05:76:88
2005-07-21 20:41:21.2823    enabled
2005-07-21 20:41:21.2855 checking formats for: ogg-aif-squeezebox-*
2005-07-21 20:41:21.2888 Checking to see if ogg-aif-squeezebox-* is enabled
2005-07-21 20:41:21.2922 There are 10 disabled formats...
2005-07-21 20:41:21.2952 Testing wma-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.2985 Testing wma-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3019 Testing ogg-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3052 Testing mpc-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3084 Testing mpc-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3117 Testing mpc-aif-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3150 Testing mov-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3183 Testing mov-aif-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3216 Testing ape-wav-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3248 Testing ape-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3281 Testing aif-flc-*-* vs ogg-aif-squeezebox-*
2005-07-21 20:41:21.3314    enabled
2005-07-21 20:41:21.3347 checking formats for: ogg-aif-*-*
2005-07-21 20:41:21.3379 Checking to see if ogg-aif-*-* is enabled
2005-07-21 20:41:21.3414 There are 10 disabled formats...
2005-07-21 20:41:21.3446 Testing wma-wav-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3479 Testing wma-flc-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3514 Testing ogg-flc-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3547 Testing mpc-wav-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3579 Testing mpc-flc-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3613 Testing mpc-aif-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3645 Testing mov-flc-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3679 Testing mov-aif-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3710 Testing ape-wav-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3741 Testing ape-flc-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3772 Testing aif-flc-*-* vs ogg-aif-*-*
2005-07-21 20:41:21.3827    enabled
2005-07-21 20:41:21.3866   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-21 20:41:21.3923 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:41:21.3962 Setting maxBitRate for Squeezebox to: 0
2005-07-21 20:41:21.3997 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-21 20:41:21.4030 openSong: this is an ogg file: file:///D:/Audio/Alben/
Dream%20Theater/1989_When%20Dream%20And%20Day%20Unite/02_Status%20Seeker.ogg
2005-07-21 20:41:21.4060   file type: ogg format: aif inrate: 128.003 maxRate: 0
2005-07-21 20:41:21.4091   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-21 20:41:21.4144 Using command for conversion: "C:
\Programme\SlimServer602\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\Alben\Dream Theater\1989_When Dream And Day Unite\02_Status Seeker.ogg" -
t raw -r 44100 -c 2 -w -s -x - |
2005-07-21 20:41:21.4210 Streaming with format: aif
2005-07-21 20:41:21.5842 00:04:20:05:76:88 New play mode: play
2005-07-21 20:41:21.5957 00:04:20:05:76:88: Current playmode: play
Comment 10 KDF 2005-07-21 12:19:20 UTC
This doesn't look like 6.1 debug output. There shouldn't be so much "Testing..."
output with the latest.  Is this still from 6.0.1?
Comment 11 Chris Buzek 2005-07-22 12:03:31 UTC
Ooops, you're right. It's version 6.0.2 - 3085.

Now I've installed 6.1.1 and did the following:

20:25.47 pressed "start" in album with 10 songs, music plays.
20:26.25 pressed "next" => server hangs for 13 secs, SB connection survives.
20:26.38 server recovered, plays song, audible
20:27:00 pressed "next" => server hangs for 63 secs, SB lost connection.
20:28.03 server recovered, plays song, not audible!
20:28:24 pressed "stop" => server hangs for 40 secs, SB lost connection.
20:29:04 recovered, music is stopped
20:29:16 pressed "play" => plays song, ok.

The hanging time correlates with the remaining time of the currently playing 
song:
first song 2:34 (3,8 MB)
second song 9:20 (17 MB)
thrid song 5:17 (9,3 MB)
and when I press "next" in any song when there is about 25 secs left, the server 
hangs for only 5 secs.

And it seems that the sound output after recovering is ok if SB doesn't lose 
connection: the first song is short enough to keep the "hang time" below the 
"connection lost" timeout.

2005-07-22 20:25:47.7645 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 929)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 2: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/BrowseTree.pm 
line 84)
   frame 3: Slim::Buttons::BrowseTree::__ANON__ (/PerlApp/Slim/Hardware/IR.pm 
line 662)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Buttons/Input/List.
pm line 70)
   frame 5: Slim::Buttons::Input::List::__ANON__ (/PerlApp/Slim/Hardware/IR.pm 
line 662)
   frame 6: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 7: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 8: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 9: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 10: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 11: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 12: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 13: main::idle (slimserver.pl line 40)
   frame 14: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 15: PerlSvc::_startup (slimserver.pl line 0)
   frame 16: (eval) (slimserver.pl line 0)

2005-07-22 20:25:47.7650 00:04:20:05:76:88: Switching to mode stop from stop
2005-07-22 20:25:47.7652  Already in playmode stop : ignoring mode change
2005-07-22 20:25:47.7666 Adding song index 0 to song queue
2005-07-22 20:25:47.7668 Clearing out song queue first
2005-07-22 20:25:47.7671 Song queue is now 0
2005-07-22 20:25:48.1813 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
758)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1745)
   frame 2: Slim::Control::Command::load_done (/PerlApp/Slim/Utils/Scan.pm line 
454)
   frame 3: Slim::Utils::Scan::addToList_done (/PerlApp/Slim/Utils/Scan.pm line 
366)
   frame 4: Slim::Utils::Scan::addToList_run (/PerlApp/Slim/Utils/Scheduler.pm 
line 95)
   frame 5: Slim::Utils::Scheduler::run_tasks (slimserver.pl line 620)
   frame 6: main::idle (slimserver.pl line 40)
   frame 7: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 8: PerlSvc::_startup (slimserver.pl line 0)
   frame 9: (eval) (slimserver.pl line 0)

2005-07-22 20:25:48.1818 00:04:20:05:76:88: Switching to mode stop from stop
2005-07-22 20:25:48.1820  Already in playmode stop : ignoring mode change
2005-07-22 20:25:48.1822 jumping to 0
2005-07-22 20:25:48.1825 Adding song index 0 to song queue
2005-07-22 20:25:48.1833 Clearing out song queue first
2005-07-22 20:25:48.1836 Song queue is now 0
2005-07-22 20:25:48.1852 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
789)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1745)
   frame 2: Slim::Control::Command::load_done (/PerlApp/Slim/Utils/Scan.pm line 
454)
   frame 3: Slim::Utils::Scan::addToList_done (/PerlApp/Slim/Utils/Scan.pm line 
366)
   frame 4: Slim::Utils::Scan::addToList_run (/PerlApp/Slim/Utils/Scheduler.pm 
line 95)
   frame 5: Slim::Utils::Scheduler::run_tasks (slimserver.pl line 620)
   frame 6: main::idle (slimserver.pl line 40)
   frame 7: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 8: PerlSvc::_startup (slimserver.pl line 0)
   frame 9: (eval) (slimserver.pl line 0)

2005-07-22 20:25:48.1856 00:04:20:05:76:88: Switching to mode play from stop
2005-07-22 20:25:48.1930 openSong on: file:///D:/Audio/_Neu/Bathory/
2002_Nordland_I/01_Prelude.ogg
2005-07-22 20:25:48.2056 openSong: getting duration  154, size 3988219, endian  
and offset 394 for file:///D:/Audio/_Neu/Bathory/2002_Nordland_I/01_Prelude.ogg
2005-07-22 20:25:48.2070 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:25:48.2080 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:25:48.2593 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:25:48.2603 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:25:48.2606 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-22 20:25:48.2611 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-22 20:25:48.2613 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-22 20:25:48.2615 checking formats for: ogg-aif-squeezebox-*
2005-07-22 20:25:48.2616 checking formats for: ogg-aif-*-*
2005-07-22 20:25:48.2618 Checking to see if ogg-aif-*-* is enabled
2005-07-22 20:25:48.2621    enabled
2005-07-22 20:25:48.2622   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-22 20:25:48.2631 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:25:48.2641 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:25:48.2644 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-22 20:25:48.2647 openSong: this is an ogg file: file:///D:/Audio/_Neu/
Bathory/2002_Nordland_I/01_Prelude.ogg
2005-07-22 20:25:48.2649   file type: ogg format: aif inrate: 256.006 maxRate: 0
2005-07-22 20:25:48.2651   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-22 20:25:48.2674 Using command for conversion: "C:
\Programme\SlimServer611\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\_Neu\Bathory\2002_Nordland_I\01_Prelude.ogg" -t raw -r 44100 -c 2 -w -s -
x - |
2005-07-22 20:25:48.2711 Streaming with format: aif
2005-07-22 20:25:48.4192 00:04:20:05:76:88 New play mode: play
2005-07-22 20:25:48.4270 00:04:20:05:76:88: Current playmode: play
2005-07-22 20:26:25.6753 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
758)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1245)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 3: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
182)
   frame 4: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 5: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 6: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 7: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 8: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 9: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 10: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 11: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 12: main::idle (slimserver.pl line 40)
   frame 13: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 14: PerlSvc::_startup (slimserver.pl line 0)
   frame 15: (eval) (slimserver.pl line 0)

2005-07-22 20:26:25.6759 00:04:20:05:76:88: Switching to mode stop from play
2005-07-22 20:26:25.6762 00:04:20:05:76:88 New play mode: stop
2005-07-22 20:26:25.6766 Stopping and clearing out old chunks for client 00:04:
20:05:76:88
2005-07-22 20:26:38.4815 Resetting song queue
2005-07-22 20:26:38.4821 Song queue is now 0
2005-07-22 20:26:38.4832 00:04:20:05:76:88: Current playmode: stop
2005-07-22 20:26:38.4836 jumping by +1
2005-07-22 20:26:38.4839 Adding song index 1 to song queue
2005-07-22 20:26:38.4841 Clearing out song queue first
2005-07-22 20:26:38.4844 Song queue is now 1
2005-07-22 20:26:38.4865 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
789)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1245)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 3: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
182)
   frame 4: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 5: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 6: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 7: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 8: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 9: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 10: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 11: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 12: main::idle (slimserver.pl line 40)
   frame 13: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 14: PerlSvc::_startup (slimserver.pl line 0)
   frame 15: (eval) (slimserver.pl line 0)

2005-07-22 20:26:38.5063 00:04:20:05:76:88: Switching to mode play from stop
2005-07-22 20:26:38.5085 openSong on: file:///D:/Audio/_Neu/Bathory/
2002_Nordland_I/02_Nordland.ogg
2005-07-22 20:26:38.5248 openSong: getting duration  560, size 17679842, endian  
and offset 396 for file:///D:/Audio/_Neu/Bathory/2002_Nordland_I/02_Nordland.ogg
2005-07-22 20:26:38.5264 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:26:38.5274 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:26:38.5847 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:26:38.5857 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:26:38.5861 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-22 20:26:38.5865 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-22 20:26:38.5868 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-22 20:26:38.5870 checking formats for: ogg-aif-squeezebox-*
2005-07-22 20:26:38.5872 checking formats for: ogg-aif-*-*
2005-07-22 20:26:38.5874 Checking to see if ogg-aif-*-* is enabled
2005-07-22 20:26:38.5877    enabled
2005-07-22 20:26:38.5878   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-22 20:26:38.5887 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:26:38.5896 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:26:38.5900 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-22 20:26:38.5911 openSong: this is an ogg file: file:///D:/Audio/_Neu/
Bathory/2002_Nordland_I/02_Nordland.ogg
2005-07-22 20:26:38.5914   file type: ogg format: aif inrate: 256.006 maxRate: 0
2005-07-22 20:26:38.5916   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-22 20:26:38.5953 Using command for conversion: "C:
\Programme\SlimServer611\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\_Neu\Bathory\2002_Nordland_I\02_Nordland.ogg" -t raw -r 44100 -c 2 -w -s 
-x - |
2005-07-22 20:26:38.5993 Streaming with format: aif
2005-07-22 20:26:38.7484 00:04:20:05:76:88 New play mode: play
2005-07-22 20:26:38.7574 00:04:20:05:76:88: Current playmode: play
2005-07-22 20:26:38.7617 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 613)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 2: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
199)
   frame 3: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 6: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 7: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 8: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 9: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
100)
   frame 10: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 11: main::idle (slimserver.pl line 40)
   frame 12: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 13: PerlSvc::_startup (slimserver.pl line 0)
   frame 14: (eval) (slimserver.pl line 0)

2005-07-22 20:26:38.7626 00:04:20:05:76:88: Switching to mode play from play
2005-07-22 20:26:38.7628  Already in playmode play : ignoring mode change
2005-07-22 20:27:00.7732 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
758)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1245)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 3: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
182)
   frame 4: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 5: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 6: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 7: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 8: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 9: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 10: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 11: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 12: main::idle (slimserver.pl line 40)
   frame 13: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 14: PerlSvc::_startup (slimserver.pl line 0)
   frame 15: (eval) (slimserver.pl line 0)

2005-07-22 20:27:00.7739 00:04:20:05:76:88: Switching to mode stop from play
2005-07-22 20:27:00.7743 00:04:20:05:76:88 New play mode: stop
2005-07-22 20:27:00.7747 Stopping and clearing out old chunks for client 00:04:
20:05:76:88
2005-07-22 20:28:03.4938 Resetting song queue
2005-07-22 20:28:03.4938 Song queue is now 1
2005-07-22 20:28:03.4949 00:04:20:05:76:88: Current playmode: stop
2005-07-22 20:28:03.4955 jumping by +1
2005-07-22 20:28:03.4958 Adding song index 2 to song queue
2005-07-22 20:28:03.4961 Clearing out song queue first
2005-07-22 20:28:03.4963 Song queue is now 2
2005-07-22 20:28:03.4986 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
789)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1245)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 3: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
182)
   frame 4: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 5: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 6: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 7: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 8: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 9: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 10: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 11: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 12: main::idle (slimserver.pl line 40)
   frame 13: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 14: PerlSvc::_startup (slimserver.pl line 0)
   frame 15: (eval) (slimserver.pl line 0)

2005-07-22 20:28:03.4993 00:04:20:05:76:88: Switching to mode play from stop
2005-07-22 20:28:03.5014 openSong on: file:///D:/Audio/_Neu/Bathory/
2002_Nordland_I/03_Vinterblot.ogg
2005-07-22 20:28:03.5179 openSong: getting duration  313, size 9538540, endian  
and offset 397 for file:///D:/Audio/_Neu/Bathory/2002_Nordland_I/03_Vinterblot.
ogg
2005-07-22 20:28:03.5196 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:28:03.5206 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:28:03.5743 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:28:03.5754 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:28:03.5758 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-22 20:28:03.5766 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-22 20:28:03.5769 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-22 20:28:03.5771 checking formats for: ogg-aif-squeezebox-*
2005-07-22 20:28:03.5778 checking formats for: ogg-aif-*-*
2005-07-22 20:28:03.5781 Checking to see if ogg-aif-*-* is enabled
2005-07-22 20:28:03.5783    enabled
2005-07-22 20:28:03.5786   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-22 20:28:03.5796 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:28:03.5806 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:28:03.5810 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-22 20:28:03.5821 openSong: this is an ogg file: file:///D:/Audio/_Neu/
Bathory/2002_Nordland_I/03_Vinterblot.ogg
2005-07-22 20:28:03.5825   file type: ogg format: aif inrate: 256.006 maxRate: 0
2005-07-22 20:28:03.5828   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-22 20:28:03.5867 Using command for conversion: "C:
\Programme\SlimServer611\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\_Neu\Bathory\2002_Nordland_I\03_Vinterblot.ogg" -t raw -r 44100 -c 2 -w -
s -x - |
2005-07-22 20:28:03.5911 Streaming with format: aif
2005-07-22 20:28:03.7120 00:04:20:05:76:88 New play mode: play
2005-07-22 20:28:03.7312 00:04:20:05:76:88: Current playmode: play
2005-07-22 20:28:03.7357 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 613)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 2: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
199)
   frame 3: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 6: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 7: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 8: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 9: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm line 
100)
   frame 10: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 11: main::idle (slimserver.pl line 40)
   frame 12: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 13: PerlSvc::_startup (slimserver.pl line 0)
   frame 14: (eval) (slimserver.pl line 0)

2005-07-22 20:28:03.7367 00:04:20:05:76:88: Switching to mode play from play
2005-07-22 20:28:03.7371  Already in playmode play : ignoring mode change
2005-07-22 20:28:24.5581 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Command.pm 
line 650)
   frame 1: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 2: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Common.pm line 
255)
   frame 3: Slim::Buttons::Common::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 4: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 5: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 6: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 7: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
554)
   frame 8: Slim::Hardware::IR::holdCode (/PerlApp/Slim/Hardware/IR.pm line 475)
   frame 9: Slim::Hardware::IR::processIR (/PerlApp/Slim/Control/Command.pm line 
603)
   frame 10: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm 
line 1001)
   frame 11: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
88)
   frame 12: Slim::Hardware::IR::idle (slimserver.pl line 613)
   frame 13: main::idle (slimserver.pl line 40)
   frame 14: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 15: PerlSvc::_startup (slimserver.pl line 0)
   frame 16: (eval) (slimserver.pl line 0)

2005-07-22 20:28:24.5594 00:04:20:05:76:88: Switching to mode stop from play
2005-07-22 20:28:24.5599 00:04:20:05:76:88 New play mode: stop
2005-07-22 20:28:24.5606 Stopping and clearing out old chunks for client 00:04:
20:05:76:88
2005-07-22 20:29:00.6059 Resetting song queue
2005-07-22 20:29:00.6059 Song queue is now 2
2005-07-22 20:29:00.6071 00:04:20:05:76:88: Current playmode: stop
2005-07-22 20:29:16.3924 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
758)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1245)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 3: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Playlist.pm 
line 161)
   frame 4: Slim::Buttons::Playlist::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 5: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 6: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 7: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 8: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 9: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 10: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 11: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 12: main::idle (slimserver.pl line 40)
   frame 13: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 14: PerlSvc::_startup (slimserver.pl line 0)
   frame 15: (eval) (slimserver.pl line 0)

2005-07-22 20:29:16.3934 00:04:20:05:76:88: Switching to mode stop from stop
2005-07-22 20:29:16.3942  Already in playmode stop : ignoring mode change
2005-07-22 20:29:16.3946 jumping to 2
2005-07-22 20:29:16.3951 Adding song index 2 to song queue
2005-07-22 20:29:16.3954 Clearing out song queue first
2005-07-22 20:29:16.3958 Song queue is now 2
2005-07-22 20:29:16.3982 Backtrace:

   frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 
789)
   frame 1: Slim::Player::Source::jumpto (/PerlApp/Slim/Control/Command.pm line 
1245)
   frame 2: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 3: Slim::Player::Client::execute (/PerlApp/Slim/Buttons/Playlist.pm 
line 161)
   frame 4: Slim::Buttons::Playlist::__ANON__ (/PerlApp/Slim/Hardware/IR.pm line 
662)
   frame 5: Slim::Hardware::IR::executeButton (/PerlApp/Slim/Control/Command.pm 
line 603)
   frame 6: Slim::Control::Command::execute (/PerlApp/Slim/Player/Client.pm line 
1001)
   frame 7: Slim::Player::Client::execute (/PerlApp/Slim/Hardware/IR.pm line 
675)
   frame 8: Slim::Hardware::IR::processCode (/PerlApp/Slim/Hardware/IR.pm line 
538)
   frame 9: Slim::Hardware::IR::releaseCode (/PerlApp/Slim/Hardware/IR.pm line 
431)
   frame 10: Slim::Hardware::IR::checkRelease (/PerlApp/Slim/Utils/Timers.pm 
line 100)
   frame 11: Slim::Utils::Timers::checkTimers (slimserver.pl line 641)
   frame 12: main::idle (slimserver.pl line 40)
   frame 13: PerlSvc::Startup (perlsvc.pl line 1481)
   frame 14: PerlSvc::_startup (slimserver.pl line 0)
   frame 15: (eval) (slimserver.pl line 0)

2005-07-22 20:29:16.3993 00:04:20:05:76:88: Switching to mode play from stop
2005-07-22 20:29:16.4016 openSong on: file:///D:/Audio/_Neu/Bathory/
2002_Nordland_I/03_Vinterblot.ogg
2005-07-22 20:29:16.4107 openSong: getting duration  313, size 9538540, endian  
and offset 397 for file:///D:/Audio/_Neu/Bathory/2002_Nordland_I/03_Vinterblot.
ogg
2005-07-22 20:29:16.4127 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:29:16.4140 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:29:16.4698 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:29:16.4712 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:29:16.4718 undermax = 1, type = ogg, squeezebox = 00:04:20:05:76:
88, lame = 
2005-07-22 20:29:16.4725 checking formats for: ogg-aif-squeezebox-00:04:20:05:
76:88
2005-07-22 20:29:16.4729 checking formats for: ogg-aif-*-00:04:20:05:76:88
2005-07-22 20:29:16.4733 checking formats for: ogg-aif-squeezebox-*
2005-07-22 20:29:16.4736 checking formats for: ogg-aif-*-*
2005-07-22 20:29:16.4740 Checking to see if ogg-aif-*-* is enabled
2005-07-22 20:29:16.4743    enabled
2005-07-22 20:29:16.4746   Found command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 
2 -w -s $-x$ -
2005-07-22 20:29:16.4758 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:29:16.4770 Setting maxBitRate for 192.168.1.11 to: 0
2005-07-22 20:29:16.4776 Matched Format: aif Type: ogg Command: [sox] -t ogg 
$FILE$ -t raw -r 44100 -c 2 -w -s $-x$ - 
2005-07-22 20:29:16.4790 openSong: this is an ogg file: file:///D:/Audio/_Neu/
Bathory/2002_Nordland_I/03_Vinterblot.ogg
2005-07-22 20:29:16.4796   file type: ogg format: aif inrate: 256.006 maxRate: 0
2005-07-22 20:29:16.4799   command: [sox] -t ogg $FILE$ -t raw -r 44100 -c 2 -w 
-s $-x$ -
2005-07-22 20:29:16.4839 Using command for conversion: "C:
\Programme\SlimServer611\server\Bin\MSWin32-x86-multi-thread\sox.exe" -t ogg "D:
\Audio\_Neu\Bathory\2002_Nordland_I\03_Vinterblot.ogg" -t raw -r 44100 -c 2 -w -
s -x - |
2005-07-22 20:29:16.4880 Streaming with format: aif
2005-07-22 20:29:16.5947 00:04:20:05:76:88 New play mode: play
2005-07-22 20:29:16.6043 00:04:20:05:76:88: Current playmode: play
Comment 12 Michel Marti 2005-07-28 13:15:59 UTC
Vidur, 

I really think that the problem is caused by slimserver closing the pipe to sox,
assuming that sox will terminate. However, sox keeps transcoding the file "as
fast as it possible". Just reproduced this with SVN revision 3811 on debian
unstable. If you can point me to the relevant --d_ options I could produce a log
file. I tried with --d_source but the log doesn't show anything obvious.
Comment 13 Vidur Apparao 2005-07-28 13:35:13 UTC
Hmm...I don't think there's any other debugging flag that would reveal more
information. The key is what's happening on the sox side. We never explicitly
kill the process and expect the process to exit when we close our pipe to it.
This definitely does work on Windows, OS X, and in a test I did a while ago on a
Fedora machine.

It's hard to get a list of all of the sox command line parameters...I'm
wondering if there's a verbose or debugging mode that will tell us what's going
on there. Other than that, I'm cc:ing Dan in the hope that he has a debianic
system somewhere around that we can run tests on.
Comment 14 Michel Marti 2005-07-29 00:05:39 UTC
Here's part of an strace on the sox process:

09:02:07 read(3, "\212\v\307\254\233\231\325\372z\367\"\35\4\310\244\276"...,
131072) = 131072
09:02:07 write(1, "\21\373\n\274\24\360\r\4\24\n\ff\20Y\n\20\rP\t0\n\204\10"...,
4096) = 4096
09:02:07 write(1, "\0\313\377\264\0H\377`\0O\377\236\0\212\0\3\0\177\0\21"...,
4096) = 4096
09:02:07 write(1, "\374\177\ts\374U\tg\374*\tQ\373\346\t\3\373\232\10\213"...,
4096) = 4096
...
09:02:12 write(1,
"\353^\370\251\341\322\355\342\333q\347M\341\247\361\"\352"..., 4096) = -1 EPIPE
(Broken pipe)
09:02:12 --- SIGPIPE (Broken pipe) @ 0 (0) ---
09:02:13 read(3, "|X\356\354\362\340\311\274\\\256\267\376\261\265\266\327"...,
131072) = 131072
09:02:15 read(3, ">\261\253+\334\337]\241\27\2606\343\37n\216\377\360\373"...,
131072) = 131072
09:02:16 read(3, "\320\201\220I\201b8}\351\22D;O\203(\250\323\323\350`}\t"...,
131072) = 131072
...
Comment 15 Michel Marti 2005-07-29 00:58:12 UTC
Vidur: I replaced the sox binary shipped with the slimserver with a link to
debian's version of sox and this fixes the problem. Looking at the patches that
debian applies to sox, I see this:

--- sox-12.17.7.orig/debian/patches/06_eof.patch
+++ sox-12.17.7/debian/patches/06_eof.patch
@@ -0,0 +1,16 @@
+diff -ruN sox-12.17.7-old/src/sox.c sox-12.17.7/src/sox.c
+--- sox-12.17.7-old/src/sox.c  2005-07-15 17:39:54.000000000 +0200
++++ sox-12.17.7/src/sox.c      2005-07-15 17:51:46.000000000 +0200
+@@ -940,6 +940,12 @@
+                                               
(st_ssize_t)efftab[neffects-1].olen);
+           efftab[neffects-1].odone = efftab[neffects-1].olen;
+ 
++          if (file_desc[file_count-1]->file.eof) {
++                fprintf(stderr,"no space left on device\n");
++                exit(-1);
++          };
++
++
+           if (file_desc[file_count-1]->st_errno)
+           {
+               st_warn("Error writing: %s", file_desc[file_count-1]->st_errstr);


The are a couple of other debian patches to sox which you might be interested
in... I'm attaching the debian sox patchset to this bug.
Comment 16 Michel Marti 2005-07-29 01:00:34 UTC
Created attachment 679 [details]
debian sox patches
Comment 17 Blackketter Dean 2005-08-21 17:48:55 UTC
Dan: should we build a new sox?
Comment 18 Dan Sully 2005-09-07 14:19:18 UTC
I've checked in a new binary with the Debian patches as subversion change 4195