fix: more conservative stalled download check, better logging (#884)

src/playback-watcher.js

@@ -170,7 +170,7 @@ export default class PlaybackWatcher {
  const loader = this.masterPlaylistController_[`${type}SegmentLoader_`];
 
  if (this[`${type}StalledDownloads_`] > 0) {
- this.logger_(`resetting stalled downloads for ${type} loader`);
+ this.logger_(`resetting possible stalled download count for ${type} loader`);
  }
  this[`${type}StalledDownloads_`] = 0;
  this[`${type}Buffered_`] = loader.buffered_();
@@ -204,16 +204,18 @@ export default class PlaybackWatcher {
 
  this[`${type}StalledDownloads_`]++;
 
- this.logger_(`found stalled download #${this[`${type}StalledDownloads_`]} for ${type} loader`);
- // We will technically get past this on the fourth bad append
- // rather than the third. As the first will almost always cause
- // buffered to change which means that StalledDownloads_ will
- // not be incremented
- if (this[`${type}StalledDownloads_`] < 3) {
+ this.logger_(`found #${this[`${type}StalledDownloads_`]} ${type} appends that did not increase buffer (possible stalled download)`, {
+ playlistId: loader.playlist_ && loader.playlist_.id,
+ buffered: Ranges.timeRangesToArray(buffered)
+
+ });
+
+ // after 10 possibly stalled appends with no reset, exclude
+ if (this[`${type}StalledDownloads_`] < 10) {
  return;
  }
 
- this.logger_(`${type} loader download exclusion`);
+ this.logger_(`${type} loader stalled download exclusion`);
  this.resetSegmentDownloads_(type);
  this.tech_.trigger({type: 'usage', name: `vhs-${type}-download-exclusion`});
 

src/segment-loader.js

@@ -2481,7 +2481,6 @@ export default class SegmentLoader extends videojs.EventTarget {
  * @private
  */
  handleAppendsDone_() {
- this.trigger('appendsdone');
  if (!this.pendingSegment_) {
  this.state = 'READY';
  // TODO should this move into this.checkForAbort to speed up requests post abort in
@@ -2492,6 +2491,8 @@ export default class SegmentLoader extends videojs.EventTarget {
  return;
  }
 
+ this.trigger('appendsdone');
+
  const segmentInfo = this.pendingSegment_;
 
  // Now that the end of the segment has been reached, we can set the end time. It's

test/playback-watcher.test.js

@@ -786,6 +786,8 @@ QUnit.test('jumps to buffered content if seeking just before', function(assert)
 
 const loaderTypes = ['audio', 'main', 'subtitle'];
 
+const EXCLUDE_APPEND_COUNT = 10;
+
 QUnit.module('PlaybackWatcher download detection', {
  beforeEach(assert) {
  this.env = useFakeEnvironment(assert);
@@ -872,17 +874,15 @@ loaderTypes.forEach(function(type) {
  }
 
  this.setBuffered(videojs.createTimeRanges([[0, 30]]));
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 0, '1st append 0 stalled downloads');
-
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 1, '2nd append 1 stalled downloads');
-
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 2, '3rd append 2 stalled downloads');
 
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 0, '4th append 0 stalled downloads');
+ for (let i = 0; i <= EXCLUDE_APPEND_COUNT; i++) {
+ loader.trigger('appendsdone');
+ if (i === EXCLUDE_APPEND_COUNT) {
+ assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 0, `append #${i} resets stalled downloads to 0`);
+ } else {
+ assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], i, `append #${i + 1} ${i} stalled downloads`);
+ }
+ }
 
  const expectedUsage = {};
 
@@ -927,16 +927,18 @@ loaderTypes.forEach(function(type) {
  const loader = this.mpc[`${type}SegmentLoader_`];
  const playlists = this.mpc.master().playlists;
  const excludeAndVerify = () => {
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 1, '1st append 1 stalled downloads');
-
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 2, '2nd append 1 stalled downloads');
-
- const oldPlaylist = this.mpc.media();
-
- loader.trigger('appendsdone');
- assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 0, '3rd append 0 stalled downloads');
+ let oldPlaylist;
+ // this test only needs 9 appends, since we do an intial append
+
+ for (let i = 0; i < EXCLUDE_APPEND_COUNT; i++) {
+ oldPlaylist = this.mpc.media();
+ loader.trigger('appendsdone');
+ if (i === EXCLUDE_APPEND_COUNT - 1) {
+ assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], 0, `append #${i} resets stalled downloads to 0`);
+ } else {
+ assert.equal(this.playbackWatcher[`${type}StalledDownloads_`], i + 1, `append #${i + 1} ${i + 1} stalled downloads`);
+ }
+ }
 
  const expectedUsage = {};
 

test/segment-loader.test.js

@@ -763,6 +763,83 @@ QUnit.module('SegmentLoader', function(hooks) {
  });
  });
 
+ QUnit.test('appendsdone happens after appends complete', function(assert) {
+ const done = assert.async();
+
+ return setupMediaSource(loader.mediaSource_, loader.sourceUpdater_).then(() => {
+ let appendsdone = false;
+
+ loader.playlist(playlistWithDuration(20));
+ loader.load();
+ this.clock.tick(1);
+
+ standardXHRResponse(this.requests.shift(), muxedSegment());
+ loader.one('appendsdone', () => {
+ appendsdone = true;
+ });
+
+ let appends = 0;
+
+ const finish = function() {
+ appends++;
+
+ if (appends < 2) {
+ return;
+ }
+
+ assert.ok(appendsdone, 'appendsdone triggered');
+ done();
+ };
+
+ loader.sourceUpdater_.videoBuffer.addEventListener('updateend', () => {
+ loader.sourceUpdater_.videoQueueCallback(finish);
+ });
+
+ loader.sourceUpdater_.audioBuffer.addEventListener('updateend', () => {
+ loader.sourceUpdater_.audioQueueCallback(finish);
+ });
+ });
+ });
+
+ QUnit.test('appendsdone does not happen after abort during append', function(assert) {
+ const done = assert.async();
+
+ return setupMediaSource(loader.mediaSource_, loader.sourceUpdater_).then(() => {
+ let appendsdone = false;
+
+ loader.playlist(playlistWithDuration(20));
+ loader.load();
+ this.clock.tick(1);
+
+ standardXHRResponse(this.requests.shift(), muxedSegment());
+ loader.one('appendsdone', () => {
+ appendsdone = true;
+ });
+
+ loader.one('appending', () => {
+ loader.abort();
+ });
+
+ let appends = 0;
+
+ const finish = function() {
+ appends++;
+
+ if (appends < 2) {
+ return;
+ }
+
+ assert.notOk(appendsdone, 'appendsdone triggered');
+ done();
+ };
+
+ loader.sourceUpdater_.videoBuffer.addEventListener('updateend', () => {
+ loader.sourceUpdater_.videoQueueCallback(finish);
+ loader.sourceUpdater_.audioQueueCallback(finish);
+ });
+ });
+ });
+
  QUnit.test('audio loader waits to request segment until it has enough info', function(assert) {
  loader.dispose();
  loader = new SegmentLoader(LoaderCommonSettings.call(this, {