Bug 9482 - sleep at end of song + transcoded stream => 100% CPU for slimserver.pl
: sleep at end of song + transcoded stream => 100% CPU for slimserver.pl
Status: RESOLVED DUPLICATE of bug 9473
Product: Logitech Media Server
Classification: Unclassified
Component: Transcoding
: 7.3.0
: PC Linux (other)
: -- normal (vote)
: ---
Assigned To: Unassigned bug - please assign me!
http://forums.slimdevices.com/showthr...
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2008-09-14 00:05 UTC by Markus Schiegl
Modified: 2011-03-16 04:39 UTC (History)
1 user (show)

See Also:
Category: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Markus Schiegl 2008-09-14 00:05:25 UTC
summary of the forum thread:

Problem: after the player has been turned off by sleep mode, e.g. sleep at end of song, a few seconds later slimserver.pl consumes all available cpu, up to 100%.

System:
- with transcoding disabled it works fine
- tested with two players, a transporter and a boom

Description:
1. music plays
2. press "sleep" button to stop player at the end of the song
3. 10 seconds before the end of the current track, the next one is loaded (i.e flac/lame is started again)
4. the track ends, the player stops (screensaver off enabled)
5. a few seconds later slimserver.pl peaks at 100% CPU

the server.log with player.source=info doesn't show anything unusual for me, at least nothing when 5. happens.

log covers 3. to 4. (nothing is logged at 5.)
[08-09-13 23:13:41.7564] Slim::Player::StreamingController::_nextTrackReady (618) 00:04:20:10:01:57: nextTrack will be index 21
[08-09-13 23:13:41.7568] Slim::Player::StreamingController::_Stream (857) 00:04:20:10:01:57: preparing to stream song index 21
[08-09-13 23:13:41.7571] Slim::Player::StreamingController::_Stream (862) Song queue is now 21,20
[08-09-13 23:13:41.7576] Slim::Player::Song::open (291) file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3
[08-09-13 23:13:41.7582] Slim::Player::Song::open (307) URL is (no direct streaming) [file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3]
[08-09-13 23:13:41.7585] Slim::Player::ProtocolHandlers::openStream (81) Trying to open protocol stream for file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3
[08-09-13 23:13:41.7588] Slim::Player::ProtocolHandlers::openStream (85) Found handler for file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3 - using Slim::Player::Protocols::File
[08-09-13 23:13:41.7595] Slim::Player::Protocols::File::open (79) duration: [402.756] size: [9790189] endian [] offset: [5010] for file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3
[08-09-13 23:13:41.7598] Slim::Player::Protocols::File::open (96) Opening file /data/common/All Music/Dido/No Angel/12 - Take My Hand.mp3
[08-09-13 23:13:41.7604] Slim::Player::Protocols::File::open (161) Seeking in 5010 into /data/common/All Music/Dido/No Angel/12 - Take My Hand.mp3
[08-09-13 23:13:41.7608] Slim::Player::Song::open (323) URL is a song (audio): file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3, type=mp3
[08-09-13 23:13:41.7632] Slim::Player::TranscodingHelper::getConvertCommand (316) Matched Format: mp3 Type: mp3 Command: [lame] --silent -q $QUALITY$ -v -B $BITRATE$ --mp3input $FILE$ -
[08-09-13 23:13:41.7635] Slim::Player::Song::open (342) URL command [lame] --silent -q $QUALITY$ -v -B $BITRATE$ --mp3input $FILE$ - type mp3 format mp3
[08-09-13 23:13:41.7638] Slim::Player::Song::open (343) URL stream format : mp3
[08-09-13 23:13:41.7644] Slim::Player::Song::open (360) Tokenized command "/usr/bin/lame" --silent -q 3 -v -B 128 --mp3input "-" -
[08-09-13 23:13:41.8041] Slim::Player::StreamingController::_Stream (899) 00:04:20:10:01:57: stream
[08-09-13 23:13:41.8117] Slim::Player::Transporter::play (133) Setting DigitalInput to 0 for [file:///data/common/All%20Music/Dido/No%20Angel/12%20-%20Take%20My%20Hand.mp3]
[08-09-13 23:13:41.8121] Slim::Player::Transporter::setDigitalInput (213) Switching to digital input 0
[08-09-13 23:13:41.8148] Slim::Player::StreamingController::_Stream (921) Song queue is now 21,20
[08-09-13 23:13:41.8153] Slim::Player::StreamingController::_setStreamingState (1686) new streaming state STREAMING
[08-09-13 23:13:44.5362] Slim::Player::StreamingController::playerTrackStarted (1517) 00:04:20:10:01:57
[08-09-13 23:13:44.5366] Slim::Player::StreamingController::_setPlayingState (1677) new playing state PLAYING
[08-09-13 23:13:44.5369] Slim::Player::StreamingController::_Playing (334) Song 20 is not longer in the queue
[08-09-13 23:13:44.5373] Slim::Player::StreamingController::_Playing (340) Song 21 has now started playing
[08-09-13 23:13:44.5389] Slim::Player::StreamingController::_Playing (367) Song queue is now 21
[08-09-13 23:13:54.5140] Slim::Player::StreamingController::_Stop (518) Song queue is now 21
[08-09-13 23:13:54.5146] Slim::Player::StreamingController::_setPlayingState (1677) new playing state STOPPED
[08-09-13 23:13:54.5149] Slim::Player::StreamingController::_setStreamingState (1686) new streaming state IDLE
[08-09-13 23:13:54.5160] Slim::Player::Source::playmode (173) 00:04:20:10:01:57: Current playmode: stop

stracing slimserver.pl shows this pattern is repeated hundreds of times per second:

gettimeofday({1221340490, 913722}, NULL) = 0
gettimeofday({1221340490, 913829}, NULL) = 0
gettimeofday({1221340490, 913936}, NULL) = 0
select(32, [6 8 9 10 12 14 15 17 18 20 21 22 26], [11 14], [11 14 15 17 18 20 21 22 24], {0, 25215}) = -1 EBADF (Bad file descriptor)
gettimeofday({1221340490, 914173}, NULL) = 0
gettimeofday({1221340490, 914279}, NULL) = 0
gettimeofday({1221340490, 914386}, NULL) = 0
select(32, [6 8 9 10 12 14 15 17 18 20 21 22 26], [11 14], [11 14 15 17 18 20 21 22 24], {0, 24765}) = -1 EBADF (Bad file descriptor)
gettimeofday({1221340490, 914628}, NULL) = 0
gettimeofday({1221340490, 914729}, NULL) = 0
gettimeofday({1221340490, 914838}, NULL) = 0
select(32, [6 8 9 10 12 14 15 17 18 20 21 22 26], [11 14], [11 14 15 17 18 20 21 22 24], {0, 24312}) = -1 EBADF (Bad file descriptor)

kind regards,
Markus
Comment 1 Markus Schiegl 2008-09-16 21:45:01 UTC
The problem is most easy to reproduce using "sleep at end of song". Since reporting this bug this happened twice while peforming normal operations like play, stop, next, add, ... although i don't know which specific action was responsible.
Comment 2 Alan Young 2008-09-18 08:29:53 UTC
This is a duplicate of the problem being handled in bug 9473

*** This bug has been marked as a duplicate of bug 9473 ***
Comment 3 Markus Schiegl 2008-09-19 14:35:42 UTC
confirmed. problem is fixed. thanks!