Bugzilla – Bug 1401
Stopping OGG playback makes sox process use 100% CPU
Last modified: 2009-09-08 09:30:49 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?
Hmm...I've confirmed that sox dies correctly on OS X and Windows. This may be platform-specific.
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.
Dan: does this happen for you on debian?
*** Bug 1665 has been marked as a duplicate of this bug. ***
Same here on my windows 2000 box.
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.
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.
ChrisB, any chance you could post a debug log with the --d_source flag specified when you play one of these playlists?
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
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?
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
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.
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.
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 ...
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.
Created attachment 679 [details] debian sox patches
Dan: should we build a new sox?
I've checked in a new binary with the Debian patches as subversion change 4195