Bug 5959 - Premature STMo events on unpause with full decode buffer
: Premature STMo events on unpause with full decode buffer
Status: CLOSED FIXED
Product: SB 2/3
Classification: Unclassified
Component: Slimproto
: 82
: All Fedora
: P2 major (vote)
: ---
Assigned To: Felix Mueller
http://forums.slimdevices.com/showpos...
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2007-10-29 01:12 UTC by Alan Young
Modified: 2009-09-08 09:23 UTC (History)
2 users (show)

See Also:
Category: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Alan Young 2007-10-29 01:12:22 UTC
There have been two reports now, one by me (firmware 82) and another on the forums at http://forums.slimdevices.com/showpost.php?p=237413&postcount=6, with a debug trace attached, where the player gets into a state where it generates STMo (output-buffer underrun) events immediately after an unpause (strm-u) command and when it has a (nearly) full decode buffer.

This has been in the context of sync startup but I do not think that it is specifically sync-related.
Comment 1 Alan Young 2007-10-29 01:15:58 UTC
In the trace referred to above you can see lots of events like this:

Slim::Networking::Slimproto::_stat_handler (739) 00:04:20:05:ad:a1 Squeezebox stream status:
	event_code:      STMo
	bytes_rec_H      0
	bytes_rec_L      6458496
	fullness:        3142235 (99%)
	bufferSize      3145728
	fullness         3142235
	bytes_received   6458496
	signal_strength: 44
	jiffies:         40374355
Slim::Networking::Slimproto::_stat_handler (751) 
	output size:     3528000
	output fullness: 0
	elapsed seconds: 137
Slim::Networking::Slimproto::_stat_handler (763) 
	elapsed milliseconds: 137985
	server timestamp:     0

They happen immediately after an strm-u, even though the decode buffer is virtually full.

Examining the trace in more detail, looking at the jiffies and elapsed milliseconds files for subsequent status packets, we see that elapsed milliseconds is advancing in multiples of 26ms (1, 2, or 3 times 26). These clearly equate to 1, 2 or 3 MP3 frames. But at the same time, the jiffies counter (should be real-time) is advancing more slowly; that seems very odd, although I suppose that this could be an artefact of the output state starvation.

My guess is that the decoder is not getting enough CPU to fill the output buffer quickly enough in the time immediately after the unpause command.

In any case it seems wrong to issue STMo events when there is plenty of data in the decode buffer.
Comment 2 Felix Mueller 2007-12-05 05:45:59 UTC
Fixed in SB fw 84 and TP fw 34
Comment 3 Blackketter Dean 2007-12-26 14:58:18 UTC
Felix: Will you close this when Chris approves this FW for the nightly release?
Comment 4 Felix Mueller 2007-12-27 01:34:19 UTC
I would, but I can't as the only option I get to choose from is: Leave as NEW. I guess, the bug needs to be assigned to somebody (me) first, but I can't do that either. 
Comment 5 Blackketter Dean 2007-12-28 08:06:07 UTC
Holy crap, Felix.  You didn't have any permissions!  I made you an uber-super-power-user.  

Please review your existing bugs and make any changes as needed.  Including this one. :)
Comment 6 James Richardson 2008-05-15 13:00:02 UTC
This bug has recently been fixed in the latest release of SqueezeCenter 7.0.1

Please try that version, if you still see the error, then reopen this bug.

To download this version, please navigate to: http://www.slimdevices.com/su_downloads.html