Fix playback stalls when everything appears okay (#1100)

* add playback watcher check for unknown player waiting
* do not do unknownwaiting check when the tech fires a native waiting event
* dont track current time waiting when at the end of the buffer
* call techWaiting_ when we detect a stall at the end of buffer

src/playback-watcher.js

@@ -8,6 +8,7 @@
  * my life and honor to the Playback Watch, for this Player and all the Players to come.
  */
 
+import window from 'global/window';
 import Ranges from './ranges';
 import videojs from 'video.js';
 
@@ -43,7 +44,7 @@ export default class PlaybackWatcher {
     }
     this.logger_('initialize');
 
-    let waitingHandler = () => this.waiting_();
+    let waitingHandler = () => this.techWaiting_();
     let cancelTimerHandler = () => this.cancelTimer_();
     let fixesBadSeeksHandler = () => this.fixesBadSeeks_();
 
@@ -59,7 +60,7 @@ export default class PlaybackWatcher {
       this.tech_.off('waiting', waitingHandler);
       this.tech_.off(timerCancelEvents, cancelTimerHandler);
       if (this.checkCurrentTimeTimeout_) {
-        clearTimeout(this.checkCurrentTimeTimeout_);
+        window.clearTimeout(this.checkCurrentTimeTimeout_);
       }
       this.cancelTimer_();
     };
@@ -74,11 +75,11 @@ export default class PlaybackWatcher {
     this.checkCurrentTime_();
 
     if (this.checkCurrentTimeTimeout_) {
-      clearTimeout(this.checkCurrentTimeTimeout_);
+      window.clearTimeout(this.checkCurrentTimeTimeout_);
     }
 
     // 42 = 24 fps // 250 is what Webkit uses // FF uses 15
-    this.checkCurrentTimeTimeout_ = setTimeout(this.monitorCurrentTime_.bind(this), 250);
+    this.checkCurrentTimeTimeout_ = window.setTimeout(this.monitorCurrentTime_.bind(this), 250);
   }
 
   /**
@@ -100,6 +101,19 @@ export default class PlaybackWatcher {
     }
 
     let currentTime = this.tech_.currentTime();
+    let buffered = this.tech_.buffered();
+
+    if (this.lastRecordedTime === currentTime &&
+        (!buffered.length || currentTime + 0.1 >= buffered.end(buffered.length - 1))) {
+      // If current time is at the end of the final buffered region, then any playback
+      // stall is most likely caused by buffering in a low bandwidth environment. The tech
+      // should fire a `waiting` event in this scenario, but due to browser and tech
+      // inconsistencies (e.g. The Flash tech does not fire a `waiting` event when the end
+      // of the buffer is reached and has fallen off the live window). Calling
+      // `techWaiting_` here allows us to simulate responding to a native `waiting` event
+      // when the tech fails to emit one.
+      return this.techWaiting_();
+    }
 
     if (this.consecutiveUpdates >= 5 &&
         currentTime === this.lastRecordedTime) {
@@ -156,20 +170,62 @@ export default class PlaybackWatcher {
   }
 
   /**
-   * Handler for situations when we determine the player is waiting
+   * Handler for situations when we determine the player is waiting.
    *
    * @private
    */
   waiting_() {
+    if (this.techWaiting_()) {
+      return;
+    }
+
+    // All tech waiting checks failed. Use last resort correction
+    let currentTime = this.tech_.currentTime();
+    let buffered = this.tech_.buffered();
+    let currentRange = Ranges.findRange(buffered, currentTime);
+
+    // Sometimes the player can stall for unknown reasons within a contiguous buffered
+    // region with no indication that anything is amiss (seen in Firefox). Seeking to
+    // currentTime is usually enough to kickstart the player. This checks that the player
+    // is currently within a buffered region before attempting a corrective seek.
+    // Chrome does not appear to continue `timeupdate` events after a `waiting` event
+    // until there is ~ 3 seconds of forward buffer available. PlaybackWatcher should also
+    // make sure there is ~3 seconds of forward buffer before taking any corrective action
+    // to avoid triggering an `unknownwaiting` event when the network is slow.
+    if (currentRange.length && currentTime + 3 <= currentRange.end(0)) {
+      this.cancelTimer_();
+      this.tech_.setCurrentTime(currentTime);
+
+      this.logger_(`Stopped at ${currentTime} while inside a buffered region ` +
+        `[${currentRange.start(0)} -> ${currentRange.end(0)}]. Attempting to resume ` +
+        `playback by seeking to the current time.`);
+
+      // unknown waiting corrections may be useful for monitoring QoS
+      this.tech_.trigger('unknownwaiting');
+      return;
+    }
+  }
+
+  /**
+   * Handler for situations when the tech fires a `waiting` event
+   *
+   * @return {Boolean}
+   *         True if an action (or none) was needed to correct the waiting. False if no
+   *         checks passed
+   * @private
+   */
+  techWaiting_() {
     let seekable = this.seekable();
     let currentTime = this.tech_.currentTime();
 
     if (this.tech_.seeking() && this.fixesBadSeeks_()) {
-      return;
+      // Tech is seeking or bad seek fixed, no action needed
+      return true;
     }
 
     if (this.tech_.seeking() || this.timer_ !== null) {
-      return;
+      // Tech is seeking or already waiting on another action, no action needed
+      return true;
     }
 
     if (this.fellOutOfLiveWindow_(seekable, currentTime)) {
@@ -182,7 +238,7 @@ export default class PlaybackWatcher {
 
       // live window resyncs may be useful for monitoring QoS
       this.tech_.trigger('liveresync');
-      return;
+      return true;
     }
 
     let buffered = this.tech_.buffered();
@@ -198,7 +254,7 @@ export default class PlaybackWatcher {
 
       // video underflow may be useful for monitoring QoS
       this.tech_.trigger('videounderflow');
-      return;
+      return true;
     }
 
     // check for gap
@@ -211,7 +267,11 @@ export default class PlaybackWatcher {
       this.timer_ = setTimeout(this.skipTheGap_.bind(this),
                                difference * 1000,
                                currentTime);
+      return true;
     }
+
+    // All checks failed. Returning false to indicate failure to correct waiting
+    return false;
   }
 
   outsideOfSeekableWindow_(seekable, currentTime) {

test/playback-watcher.test.js

@@ -173,6 +173,148 @@ QUnit.test('seek to live point if we fall off the end of a live playlist', funct
   assert.equal(seeks[0], 45, 'player seeked to live point');
 });
 
+QUnit.test('seeks to current time when stuck inside buffered region', function(assert) {
+
+  // set an arbitrary live source
+  this.player.src({
+    src: 'liveStart30sBefore.m3u8',
+    type: 'application/vnd.apple.mpegurl'
+  });
+
+  // start playback normally
+  this.player.tech_.triggerReady();
+  this.clock.tick(1);
+  standardXHRResponse(this.requests.shift());
+  openMediaSource(this.player, this.clock);
+  this.player.tech_.trigger('play');
+  this.player.tech_.trigger('playing');
+  this.clock.tick(1);
+
+  this.player.currentTime(10);
+
+  let seeks = [];
+
+  this.player.tech_.setCurrentTime = (time) => {
+    seeks.push(time);
+  };
+
+  this.player.tech_.seeking = () => false;
+  this.player.tech_.buffered = () => videojs.createTimeRanges([[0, 30]]);
+  this.player.tech_.seekable = () => videojs.createTimeRanges([[0, 30]]);
+  this.player.tech_.paused = () => false;
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop has run through once, `lastRecordedTime` should have been recorded
+  // and `consecutiveUpdates` set to 0 to begin count
+  assert.equal(this.player.tech_.hls.playbackWatcher_.lastRecordedTime, 10,
+    'Playback Watcher stored current time');
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 0,
+    'consecutiveUpdates set to 0');
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop should increment consecutive updates until it is >= 5
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 1,
+    'consecutiveUpdates incremented');
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop should increment consecutive updates until it is >= 5
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 2,
+    'consecutiveUpdates incremented');
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop should increment consecutive updates until it is >= 5
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 3,
+    'consecutiveUpdates incremented');
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop should increment consecutive updates until it is >= 5
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 4,
+    'consecutiveUpdates incremented');
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop should increment consecutive updates until it is >= 5
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 5,
+    'consecutiveUpdates incremented');
+
+  // Playback watcher loop runs on a 250ms clock
+  this.clock.tick(250);
+
+  // Loop should see consecutive updates >= 5, call `waiting_`
+  assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 0,
+    'consecutiveUpdates reset');
+
+  // Playback watcher seeked to currentTime in `waiting_` to correct the `unknownwaiting`
+  assert.equal(seeks.length, 1, 'one seek');
+  assert.equal(seeks[0], 10, 'player seeked to currentTime');
+});
+
+QUnit.test('does not seek to current time when stuck near edge of buffered region',
+  function(assert) {
+    // set an arbitrary live source
+    this.player.src({
+      src: 'liveStart30sBefore.m3u8',
+      type: 'application/vnd.apple.mpegurl'
+    });
+
+    // start playback normally
+    this.player.tech_.triggerReady();
+    this.clock.tick(1);
+    standardXHRResponse(this.requests.shift());
+    openMediaSource(this.player, this.clock);
+    this.player.tech_.trigger('play');
+    this.player.tech_.trigger('playing');
+    this.clock.tick(1);
+
+    this.player.currentTime(29.98);
+
+    let seeks = [];
+
+    this.player.tech_.setCurrentTime = (time) => {
+      seeks.push(time);
+    };
+
+    this.player.tech_.seeking = () => false;
+    this.player.tech_.buffered = () => videojs.createTimeRanges([[0, 30]]);
+    this.player.tech_.seekable = () => videojs.createTimeRanges([[0, 30]]);
+    this.player.tech_.paused = () => false;
+
+    // Playback watcher loop runs on a 250ms clock
+    this.clock.tick(250);
+
+    // Loop has run through once, `lastRecordedTime` should have been recorded
+    // and `consecutiveUpdates` set to 0 to begin count
+    assert.equal(this.player.tech_.hls.playbackWatcher_.lastRecordedTime, 29.98,
+      'Playback Watcher stored current time');
+    assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 0,
+      'consecutiveUpdates set to 0');
+
+    // Playback watcher loop runs on a 250ms clock
+    this.clock.tick(250);
+
+    // Loop has run through a second time, should detect that currentTime hasn't made
+    // progress while at the end of the buffer. Since the currentTime is at the end of the
+    // buffer, `consecutiveUpdates` should not be incremented
+    assert.equal(this.player.tech_.hls.playbackWatcher_.lastRecordedTime, 29.98,
+      'Playback Watcher stored current time');
+    assert.equal(this.player.tech_.hls.playbackWatcher_.consecutiveUpdates, 0,
+      'consecutiveUpdates should still be 0');
+
+    // no corrective seek
+    assert.equal(seeks.length, 0, 'no seek');
+  });
+
 QUnit.test('fires notifications when activated', function(assert) {
   let buffered = [[]];
   let seekable = [[]];