First Last Prev Next    This bug is not in your last search results.
Bug 7918 - strm-a (skip-ahead) can provoke STMo (output buffer underrun)
: strm-a (skip-ahead) can provoke STMo (output buffer underrun)
Status: CLOSED FIXED
Product: SB 2/3
Classification: Unclassified
Component: Audio
: 86
: PC Other
: P1 normal (vote)
: 7.3.2
Assigned To: Andy Grundman
:
Depends on:
Blocks:
  Show dependency tree / graph
 
Reported: 2008-04-21 08:52 UTC by Alan Young
Modified: 2009-01-22 13:53 UTC (History)
2 users (show)

See Also:
Category: ---

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Alan Young 2008-04-21 08:52:34 UTC 
It seems like the implementation of skip-ahead can cause an unnecessary output-buffer underrun events. This is particular problematic if an underrun occurs at the start of synchronized track play (which can happen relatively easily). The following (edited) log snippet illustrates the consequences:

[08-04-21 17:31:10.8937] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: play
[08-04-21 17:31:11.1199] Slim::Player::Sync::checkSync (515) 00:04:20:07:59:e1 is ready to sync
[08-04-21 17:31:12.8687] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 830 / output: 0)
[08-04-21 17:31:12.8690] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:12.8700] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:12.8774] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:20.0702] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:20.0712] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume
[08-04-21 17:31:20.0722] Slim::Player::Source::playmode (430) 00:04:20:07:59:e1: Resume, resetting mode: play
[08-04-21 17:31:20.0872] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: resume
[08-04-21 17:31:20.1151] Slim::Player::Sync::checkSync (678) 00:04:20:07:59:e1 resync: skipAhead 2796ms
[08-04-21 17:31:20.1479] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 2089306 / output: 0)
[08-04-21 17:31:20.1482] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:20.1491] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:20.1568] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:21.1757] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:21.1766] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume
[08-04-21 17:31:21.1776] Slim::Player::Source::playmode (430) 00:04:20:07:59:e1: Resume, resetting mode: play
[08-04-21 17:31:21.1923] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: resume
[08-04-21 17:31:21.2155] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 3142842 / output: 0)
[08-04-21 17:31:21.2159] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:21.2167] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:21.2244] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:22.2449] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:22.2460] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume
[08-04-21 17:31:22.2473] Slim::Player::Source::playmode (430) 00:04:20:07:59:e1: Resume, resetting mode: play
[08-04-21 17:31:22.2665] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: resume
[08-04-21 17:31:22.2966] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 3144582 / output: 0)
[08-04-21 17:31:22.2972] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:22.2983] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:22.3084] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:23.3298] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:23.3307] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume
[08-04-21 17:31:23.3316] Slim::Player::Source::playmode (430) 00:04:20:07:59:e1: Resume, resetting mode: play
[08-04-21 17:31:23.3464] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: resume
[08-04-21 17:31:23.3694] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 3145727 / output: 0)
[08-04-21 17:31:23.3697] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:23.3706] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:23.3783] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:24.3985] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:24.3996] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume
[08-04-21 17:31:24.4008] Slim::Player::Source::playmode (430) 00:04:20:07:59:e1: Resume, resetting mode: play
[08-04-21 17:31:24.4206] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: resume
[08-04-21 17:31:24.4524] Slim::Player::Sync::checkSync (678) 00:04:20:07:59:e1 resync: skipAhead 1177ms
[08-04-21 17:31:24.4989] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 3145046 / output: 0)
[08-04-21 17:31:24.4994] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:24.5005] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:24.5102] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:25.5306] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:25.5315] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume
[08-04-21 17:31:25.5325] Slim::Player::Source::playmode (430) 00:04:20:07:59:e1: Resume, resetting mode: play
[08-04-21 17:31:25.5464] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: resume
[08-04-21 17:31:25.5691] Slim::Player::Source::outputUnderrun (782) 00:04:20:07:59:e1: Output buffer underrun (decoder: 3143231 / output: 0)
[08-04-21 17:31:25.5694] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode pause from play
[08-04-21 17:31:25.5702] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: pause
[08-04-21 17:31:25.5776] Slim::Player::Source::playmode (573) 00:04:20:07:59:e1: Current playmode: pause
[08-04-21 17:31:26.5970] Slim::Player::Source::playmode (309) 00:04:20:07:59:e1: Switching to mode play from pause
[08-04-21 17:31:26.5979] Slim::Player::Source::playmode (412) 00:04:20:07:59:e1 New play mode: resume

The skip-ahead happens because the player which had the underrun is being told to catch up with the players which did not underrun. Somehow we need handle this case, either by ignoring the skip-ahead unless we have enough data to handle it or by taking into account the fact that we have just done a skip-ahead and, as we have plenty of data in the decode buffer, an STMo is inappropriate.

Something similar has already been done for start-at (see bug 5959), where we simply ignore a past-due start-at-time. In this case I feel that the ignore option is the less preferable one as it will make synchronized start under difficult circumstances less smooth than it could be.

Bug 7695 is impacted by this.
Comment 1 Alan Young 2008-04-24 00:13:20 UTC 
I'm not sure that this has to be related to skip-ahead. Please see the logs attached to bug 7935 which show STMo happening even without synced players (and hence no skip-ahead).
Comment 2 Chris Owens 2008-11-10 09:58:06 UTC 
A user would see the player rebuffers at track start or at other points in the track.  The right fix is not to allow a skipahead if there's not enough data to support it.
Comment 3 Andy Grundman 2008-12-17 08:17:59 UTC 
Fixed in r5267.
Comment 4 James Richardson 2008-12-18 15:17:16 UTC 
This appears to be addressed in

SqueezeCenter 7.3.1 r24367
Controller 7.3 r3476
SqueezePlay 7.3 r3550M
Receiver r56
SB2/3 r121
Transporter r71
Boom r41

Tested Sync'd and Unsync'd players.  Tested Random Mix Local Content (mix CODEC), Sirius, Rhapsody, Internet-RADIO - tested 2 hours with no re-buffering events detected.
Comment 5 Andy Grundman 2008-12-18 15:32:23 UTC 
No, this is not in the firmware you tested.  It will be in 7.3.2.
Comment 6 Andy Grundman 2008-12-18 15:32:59 UTC 
James: see previous comment.
Comment 7 James Richardson 2009-01-22 09:58:04 UTC 
Fixed - Closed Message (SC)

This bug has been fixed in the 7.3.3 release version of SqueezeCenter!

Please download the new version from http://www.slimdevices.com/su_downloads.html if you haven't already.  

If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.
Comment 8 James Richardson 2009-01-22 13:53:25 UTC 
Correction: SqueezeCenter version is 7.3.2
First Last Prev Next    This bug is not in your last search results.