diff --git a/src/controller/eme-controller.ts b/src/controller/eme-controller.ts index 306f1da612d..3ef8c86e4ce 100644 --- a/src/controller/eme-controller.ts +++ b/src/controller/eme-controller.ts @@ -228,7 +228,7 @@ class EMEController extends EventHandler { logger.log('Got EME message event, creating license request'); this._requestLicense(message, (data: ArrayBuffer) => { - logger.log('Received license data, updating key-session'); + logger.log(`Received license data (length: ${data ? data.byteLength : data}), updating key-session`); keySession.update(data); }); } diff --git a/src/controller/gap-controller.js b/src/controller/gap-controller.js index 8e67ede8bba..5f4aaa05b08 100644 --- a/src/controller/gap-controller.js +++ b/src/controller/gap-controller.js @@ -3,8 +3,10 @@ import { ErrorTypes, ErrorDetails } from '../errors'; import Event from '../events'; import { logger } from '../utils/logger'; -const stallDebounceInterval = 1000; -const jumpThreshold = 0.5; // tolerance needed as some browsers stalls playback before reaching buffered range end +export const STALL_MINIMUM_DURATION_MS = 250; +export const MAX_START_GAP_JUMP = 2.0; +export const SKIP_BUFFER_HOLE_STEP_SECONDS = 0.1; +export const SKIP_BUFFER_RANGE_START = 0.05; export default class GapController { constructor (config, media, fragmentTracker, hls) { @@ -12,61 +14,109 @@ export default class GapController { this.media = media; this.fragmentTracker = fragmentTracker; this.hls = hls; + this.nudgeRetry = 0; this.stallReported = false; + this.stalled = null; + this.moved = false; + this.seeking = false; } /** * Checks if the playhead is stuck within a gap, and if so, attempts to free it. * A gap is an unbuffered range between two buffered ranges (or the start and the first buffered range). - * @param lastCurrentTime - * @param buffered + * + * @param {number} lastCurrentTime Previously read playhead position */ - poll (lastCurrentTime, buffered) { - const { config, media } = this; - const currentTime = media.currentTime; - const tnow = window.performance.now(); + poll (lastCurrentTime) { + const { config, media, stalled } = this; + const { currentTime, seeking } = media; + const seeked = this.seeking && !seeking; + const beginSeek = !this.seeking && seeking; + + this.seeking = seeking; + // The playhead is moving, no-op if (currentTime !== lastCurrentTime) { - // The playhead is now moving, but was previously stalled - if (this.stallReported) { - logger.warn(`playback not stuck anymore @${currentTime}, after ${Math.round(tnow - this.stalled)}ms`); - this.stallReported = false; + this.moved = true; + if (stalled !== null) { + // The playhead is now moving, but was previously stalled + if (this.stallReported) { + const stalledDuration = self.performance.now() - stalled; + logger.warn(`playback not stuck anymore @${currentTime}, after ${Math.round(stalledDuration)}ms`); + this.stallReported = false; + } + this.stalled = null; + this.nudgeRetry = 0; } - this.stalled = null; - this.nudgeRetry = 0; return; } - if (media.ended || !media.buffered.length || media.readyState > 2) { + // Clear stalled state when beginning or finishing seeking so that we don't report stalls coming out of a seek + if (beginSeek || seeked) { + this.stalled = null; + } + + // The playhead should not be moving + if (media.paused || media.ended || media.playbackRate === 0 || !media.buffered.length) { return; } - if (media.seeking && BufferHelper.isBuffered(media, currentTime)) { + const bufferInfo = BufferHelper.bufferInfo(media, currentTime, 0); + const isBuffered = bufferInfo.len > 0; + const nextStart = bufferInfo.nextStart || 0; + + // There is no playable buffer (waiting for buffer append) + if (!isBuffered && !nextStart) { return; } - // The playhead isn't moving but it should be - // Allow some slack time to for small stalls to resolve themselves - const stalledDuration = tnow - this.stalled; - const bufferInfo = BufferHelper.bufferInfo(media, currentTime, config.maxBufferHole); - if (!this.stalled) { + if (seeking) { + // Waiting for seeking in a buffered range to complete + const hasEnoughBuffer = bufferInfo.len > MAX_START_GAP_JUMP; + // Next buffered range is too far ahead to jump to while still seeking + const noBufferGap = !nextStart || nextStart - currentTime > MAX_START_GAP_JUMP; + if (hasEnoughBuffer || noBufferGap) { + return; + } + // Reset moved state when seeking to a point in or before a gap + this.moved = false; + } + + // Skip start gaps if we haven't played, but the last poll detected the start of a stall + // The addition poll gives the browser a chance to jump the gap for us + if (!this.moved && this.stalled) { + // Jump start gaps within jump threshold + const startJump = Math.max(nextStart, bufferInfo.start || 0) - currentTime; + if (startJump > 0 && startJump <= MAX_START_GAP_JUMP) { + this._trySkipBufferHole(null); + return; + } + } + + // Start tracking stall time + const tnow = self.performance.now(); + if (stalled === null) { this.stalled = tnow; return; - } else if (stalledDuration >= stallDebounceInterval) { + } + + const stalledDuration = tnow - stalled; + if (!seeking && stalledDuration >= STALL_MINIMUM_DURATION_MS) { // Report stalling after trying to fix this._reportStall(bufferInfo.len); } - this._tryFixBufferStall(bufferInfo, stalledDuration); + const bufferedWithHoles = BufferHelper.bufferInfo(media, currentTime, config.maxBufferHole); + this._tryFixBufferStall(bufferedWithHoles, stalledDuration); } /** * Detects and attempts to fix known buffer stalling issues. * @param bufferInfo - The properties of the current buffer. - * @param stalledDuration - The amount of time Hls.js has been stalling for. + * @param stalledDurationMs - The amount of time Hls.js has been stalling for. * @private */ - _tryFixBufferStall (bufferInfo, stalledDuration) { + _tryFixBufferStall (bufferInfo, stalledDurationMs) { const { config, fragmentTracker, media } = this; const currentTime = media.currentTime; @@ -74,10 +124,21 @@ export default class GapController { if (partial) { // Try to skip over the buffer hole caused by a partial fragment // This method isn't limited by the size of the gap between buffered ranges - this._trySkipBufferHole(partial); + const targetTime = this._trySkipBufferHole(partial); + // we return here in this case, meaning + // the branch below only executes when we don't handle a partial fragment + if (targetTime) { + return; + } } - if (bufferInfo.len > jumpThreshold && stalledDuration > config.highBufferWatchdogPeriod * 1000) { + // if we haven't had to skip over a buffer hole of a partial fragment + // we may just have to "nudge" the playlist as the browser decoding/rendering engine + // needs to cross some sort of threshold covering all source-buffers content + // to start playing properly. + if (bufferInfo.len > config.maxBufferHole && + stalledDurationMs > config.highBufferWatchdogPeriod * 1000) { + logger.warn('Trying to nudge playhead over buffer-hole'); // Try to nudge currentTime over a buffer hole if we've been stalling for the configured amount of seconds // We only try to jump the hole if it's under the configured size // Reset stalled so to rearm watchdog timer @@ -112,27 +173,32 @@ export default class GapController { * @private */ _trySkipBufferHole (partial) { - const { hls, media } = this; + const { config, hls, media } = this; const currentTime = media.currentTime; let lastEndTime = 0; // Check if currentTime is between unbuffered regions of partial fragments for (let i = 0; i < media.buffered.length; i++) { - let startTime = media.buffered.start(i); - if (currentTime >= lastEndTime && currentTime < startTime) { - media.currentTime = Math.max(startTime, media.currentTime + 0.1); - logger.warn(`skipping hole, adjusting currentTime from ${currentTime} to ${media.currentTime}`); + const startTime = media.buffered.start(i); + if (currentTime + config.maxBufferHole >= lastEndTime && currentTime < startTime) { + const targetTime = Math.max(startTime + SKIP_BUFFER_RANGE_START, media.currentTime + SKIP_BUFFER_HOLE_STEP_SECONDS); + logger.warn(`skipping hole, adjusting currentTime from ${currentTime} to ${targetTime}`); + this.moved = true; this.stalled = null; - hls.trigger(Event.ERROR, { - type: ErrorTypes.MEDIA_ERROR, - details: ErrorDetails.BUFFER_SEEK_OVER_HOLE, - fatal: false, - reason: `fragment loaded with buffer holes, seeking from ${currentTime} to ${media.currentTime}`, - frag: partial - }); - return; + media.currentTime = targetTime; + if (partial) { + hls.trigger(Event.ERROR, { + type: ErrorTypes.MEDIA_ERROR, + details: ErrorDetails.BUFFER_SEEK_OVER_HOLE, + fatal: false, + reason: `fragment loaded with buffer holes, seeking from ${currentTime} to ${targetTime}`, + frag: partial + }); + } + return targetTime; } lastEndTime = media.buffered.end(i); } + return 0; } /** @@ -147,16 +213,17 @@ export default class GapController { if (nudgeRetry < config.nudgeMaxRetry) { const targetTime = currentTime + nudgeRetry * config.nudgeOffset; - logger.log(`adjust currentTime from ${currentTime} to ${targetTime}`); // playback stalled in buffered area ... let's nudge currentTime to try to overcome this + logger.warn(`Nudging 'currentTime' from ${currentTime} to ${targetTime}`); media.currentTime = targetTime; + hls.trigger(Event.ERROR, { type: ErrorTypes.MEDIA_ERROR, details: ErrorDetails.BUFFER_NUDGE_ON_STALL, fatal: false }); } else { - logger.error(`still stuck in high buffer @${currentTime} after ${config.nudgeMaxRetry}, raise fatal error`); + logger.error(`Playhead still not moving while enough data buffered @${currentTime} after ${config.nudgeMaxRetry} nudges`); hls.trigger(Event.ERROR, { type: ErrorTypes.MEDIA_ERROR, details: ErrorDetails.BUFFER_STALLED_ERROR, diff --git a/src/controller/stream-controller.js b/src/controller/stream-controller.js index a5e40078578..532b0f62e04 100644 --- a/src/controller/stream-controller.js +++ b/src/controller/stream-controller.js @@ -347,65 +347,68 @@ class StreamController extends BaseStreamController { return frag; } - _findFragment (start, fragPrevious, fragLen, fragments, bufferEnd, end, levelDetails) { + _findFragment (start, fragPreviousLoad, fragmentIndexRange, fragments, bufferEnd, end, levelDetails) { const config = this.hls.config; - let frag; + let fragNextLoad; if (bufferEnd < end) { const lookupTolerance = (bufferEnd > end - config.maxFragLookUpTolerance) ? 0 : config.maxFragLookUpTolerance; // Remove the tolerance if it would put the bufferEnd past the actual end of stream // Uses buffer and sequence number to calculate switch segment (required if using EXT-X-DISCONTINUITY-SEQUENCE) - frag = findFragmentByPTS(fragPrevious, fragments, bufferEnd, lookupTolerance); + fragNextLoad = findFragmentByPTS(fragPreviousLoad, fragments, bufferEnd, lookupTolerance); } else { // reach end of playlist - frag = fragments[fragLen - 1]; + fragNextLoad = fragments[fragmentIndexRange - 1]; } - if (frag) { - const curSNIdx = frag.sn - levelDetails.startSN; - const sameLevel = fragPrevious && frag.level === fragPrevious.level; - const prevFrag = fragments[curSNIdx - 1]; - const nextFrag = fragments[curSNIdx + 1]; + + if (fragNextLoad) { + const curSNIdx = fragNextLoad.sn - levelDetails.startSN; + const sameLevel = fragPreviousLoad && fragNextLoad.level === fragPreviousLoad.level; + const prevSnFrag = fragments[curSNIdx - 1]; + const nextSnFrag = fragments[curSNIdx + 1]; + // logger.log('find SN matching with pos:' + bufferEnd + ':' + frag.sn); - if (fragPrevious && frag.sn === fragPrevious.sn) { - if (sameLevel && !frag.backtracked) { - if (frag.sn < levelDetails.endSN) { - let deltaPTS = fragPrevious.deltaPTS; + if (fragPreviousLoad && fragNextLoad.sn === fragPreviousLoad.sn) { + if (sameLevel && !fragNextLoad.backtracked) { + if (fragNextLoad.sn < levelDetails.endSN) { + let deltaPTS = fragPreviousLoad.deltaPTS; // if there is a significant delta between audio and video, larger than max allowed hole, // and if previous remuxed fragment did not start with a keyframe. (fragPrevious.dropped) // let's try to load previous fragment again to get last keyframe // then we will reload again current fragment (that way we should be able to fill the buffer hole ...) - if (deltaPTS && deltaPTS > config.maxBufferHole && fragPrevious.dropped && curSNIdx) { - frag = prevFrag; - logger.warn('SN just loaded, with large PTS gap between audio and video, maybe frag is not starting with a keyframe ? load previous one to try to overcome this'); + if (deltaPTS && deltaPTS > config.maxBufferHole && fragPreviousLoad.dropped && curSNIdx) { + fragNextLoad = prevSnFrag; + logger.warn('Previous fragment was dropped with large PTS gap between audio and video. Maybe fragment is not starting with a keyframe? Loading previous one to try to overcome this'); } else { - frag = nextFrag; - logger.log(`SN just loaded, load next one: ${frag.sn}`, frag); + fragNextLoad = nextSnFrag; + logger.log(`Re-loading fragment with SN: ${fragNextLoad.sn}`); } } else { - frag = null; + fragNextLoad = null; } - } else if (frag.backtracked) { + } else if (fragNextLoad.backtracked) { // Only backtrack a max of 1 consecutive fragment to prevent sliding back too far when little or no frags start with keyframes - if (nextFrag && nextFrag.backtracked) { - logger.warn(`Already backtracked from fragment ${nextFrag.sn}, will not backtrack to fragment ${frag.sn}. Loading fragment ${nextFrag.sn}`); - frag = nextFrag; + if (nextSnFrag && nextSnFrag.backtracked) { + logger.warn(`Already backtracked from fragment ${nextSnFrag.sn}, will not backtrack to fragment ${fragNextLoad.sn}. Loading fragment ${nextSnFrag.sn}`); + fragNextLoad = nextSnFrag; } else { // If a fragment has dropped frames and it's in a same level/sequence, load the previous fragment to try and find the keyframe // Reset the dropped count now since it won't be reset until we parse the fragment again, which prevents infinite backtracking on the same segment logger.warn('Loaded fragment with dropped frames, backtracking 1 segment to find a keyframe'); - frag.dropped = 0; - if (prevFrag) { - frag = prevFrag; - frag.backtracked = true; + fragNextLoad.dropped = 0; + if (prevSnFrag) { + fragNextLoad = prevSnFrag; + fragNextLoad.backtracked = true; } else if (curSNIdx) { // can't backtrack on very first fragment - frag = null; + fragNextLoad = null; } } } } } - return frag; + + return fragNextLoad; } _loadKey (frag) { @@ -450,7 +453,7 @@ class StreamController extends BaseStreamController { if (this.state !== nextState) { const previousState = this.state; this._state = nextState; - logger.log(`main stream:${previousState}->${nextState}`); + logger.log(`main stream-controller: ${previousState}->${nextState}`); this.hls.trigger(Event.STREAM_STATE_TRANSITION, { previousState, nextState }); } } @@ -685,6 +688,7 @@ class StreamController extends BaseStreamController { } }); } + // remove video listeners if (media) { media.removeEventListener('seeking', this.onvseeking); @@ -692,6 +696,7 @@ class StreamController extends BaseStreamController { media.removeEventListener('ended', this.onvended); this.onvseeking = this.onvseeked = this.onvended = null; } + this.fragmentTracker.removeAllFragments(); this.media = this.mediaBuffer = null; this.loadedmetadata = false; @@ -699,7 +704,8 @@ class StreamController extends BaseStreamController { } onMediaSeeked () { - const media = this.media, currentTime = media ? media.currentTime : undefined; + const media = this.media; + const currentTime = media ? media.currentTime : undefined; if (Number.isFinite(currentTime)) { logger.log(`media seeked to ${currentTime.toFixed(3)}`); } diff --git a/src/controller/subtitle-stream-controller.js b/src/controller/subtitle-stream-controller.js index 8e313d9d8b9..65b8d68b297 100644 --- a/src/controller/subtitle-stream-controller.js +++ b/src/controller/subtitle-stream-controller.js @@ -83,6 +83,9 @@ export class SubtitleStreamController extends BaseStreamController { } onMediaDetaching () { + if (!this.media) { + return; + } this.media.removeEventListener('seeking', this._onMediaSeeking); this.fragmentTracker.removeAllFragments(); this.currentTrackId = -1; diff --git a/src/utils/buffer-helper.ts b/src/utils/buffer-helper.ts index 766f8f4a1c2..a3ce5e78042 100644 --- a/src/utils/buffer-helper.ts +++ b/src/utils/buffer-helper.ts @@ -92,30 +92,34 @@ export class BufferHelper { }); let buffered2: BufferTimeRange[] = []; - // there might be some small holes between buffer time range - // consider that holes smaller than maxHoleDuration are irrelevant and build another - // buffer time range representations that discards those holes - for (let i = 0; i < buffered.length; i++) { - let buf2len = buffered2.length; - if (buf2len) { - let buf2end = buffered2[buf2len - 1].end; - // if small hole (value between 0 or maxHoleDuration ) or overlapping (negative) - if ((buffered[i].start - buf2end) < maxHoleDuration) { - // merge overlapping time ranges - // update lastRange.end only if smaller than item.end - // e.g. [ 1, 15] with [ 2,8] => [ 1,15] (no need to modify lastRange.end) - // whereas [ 1, 8] with [ 2,15] => [ 1,15] ( lastRange should switch from [1,8] to [1,15]) - if (buffered[i].end > buf2end) { - buffered2[buf2len - 1].end = buffered[i].end; + if (maxHoleDuration) { + // there might be some small holes between buffer time range + // consider that holes smaller than maxHoleDuration are irrelevant and build another + // buffer time range representations that discards those holes + for (let i = 0; i < buffered.length; i++) { + let buf2len = buffered2.length; + if (buf2len) { + let buf2end = buffered2[buf2len - 1].end; + // if small hole (value between 0 or maxHoleDuration ) or overlapping (negative) + if ((buffered[i].start - buf2end) < maxHoleDuration) { + // merge overlapping time ranges + // update lastRange.end only if smaller than item.end + // e.g. [ 1, 15] with [ 2,8] => [ 1,15] (no need to modify lastRange.end) + // whereas [ 1, 8] with [ 2,15] => [ 1,15] ( lastRange should switch from [1,8] to [1,15]) + if (buffered[i].end > buf2end) { + buffered2[buf2len - 1].end = buffered[i].end; + } + } else { + // big hole + buffered2.push(buffered[i]); } } else { - // big hole + // first value buffered2.push(buffered[i]); } - } else { - // first value - buffered2.push(buffered[i]); } + } else { + buffered2 = buffered; } let bufferLen = 0; diff --git a/tests/functional/auto/setup.js b/tests/functional/auto/setup.js index ca10ae7e42e..05adc4a48b7 100644 --- a/tests/functional/auto/setup.js +++ b/tests/functional/auto/setup.js @@ -89,7 +89,7 @@ async function testLoadedData (url, config) { url, config ); - expect(result.code).to.equal('loadeddata'); + expect(result, JSON.stringify(result, null, 2)).to.have.property('code').which.equals('loadeddata'); } async function testSmoothSwitch (url, config) { @@ -121,7 +121,7 @@ async function testSmoothSwitch (url, config) { url, config ); - expect(result.code).to.be.true; + expect(result, JSON.stringify(result, null, 2)).to.have.property('code').which.equals(true); } async function testSeekOnLive (url, config) { @@ -142,7 +142,7 @@ async function testSeekOnLive (url, config) { url, config ); - expect(result.code).to.equal('seeked'); + expect(result, JSON.stringify(result, null, 2)).to.have.property('code').which.equals('seeked'); } async function testSeekOnVOD (url, config) { @@ -163,7 +163,7 @@ async function testSeekOnVOD (url, config) { url, config ); - expect(result.code).to.equal('ended'); + expect(result, JSON.stringify(result, null, 2)).to.have.property('code').which.equals('ended'); } async function testSeekEndVOD (url, config) { @@ -184,7 +184,7 @@ async function testSeekEndVOD (url, config) { url, config ); - expect(result.code).to.equal('ended'); + expect(result, JSON.stringify(result, null, 2)).to.have.property('code').which.equals('ended'); } async function testIsPlayingVOD (url, config) { @@ -218,7 +218,37 @@ async function testIsPlayingVOD (url, config) { url, config ); - expect(result.playing).to.be.true; + expect(result, JSON.stringify(result, null, 2)).to.have.property('playing').which.is.true; +} + +async function testSeekBackToStart (url, config) { + const result = await browser.executeAsyncScript( + (url, config) => { + let callback = arguments[arguments.length - 1]; + window.startStream(url, config, callback); + const video = window.video; + video.ontimeupdate = function () { + if (video.currentTime > 0 && !video.paused) { + window.setTimeout(function () { + video.onseeked = function () { + delete video.onseeked; + video.ontimeupdate = function () { + if (video.currentTime > 0 && !video.paused) { + delete video.ontimeupdate; + callback({ playing: true }); + } + }; + }; + video.currentTime = 0; + delete video.ontime; + }, 500); + } + }; + }, + url, + config + ); + expect(result, JSON.stringify(result, null, 2)).to.have.property('playing').which.is.true; } describe(`testing hls.js playback in the browser on "${browserDescription}"`, function () { @@ -330,6 +360,13 @@ describe(`testing hls.js playback in the browser on "${browserDescription}"`, fu testLoadedData.bind(null, url, config) ); + if (stream.startSeek) { + it( + `seek back to start and play for ${stream.description}`, + testSeekBackToStart.bind(null, url, config) + ); + } + if (stream.abr) { it( `should "smooth switch" to highest level and still play(readyState === 4) after 12s for ${stream.description}`, diff --git a/tests/test-streams.js b/tests/test-streams.js index e530e5b7d8d..ac4f4589f4e 100644 --- a/tests/test-streams.js +++ b/tests/test-streams.js @@ -183,5 +183,11 @@ module.exports = { altAudioAndTracks: { url: 'https://wowzaec2demo.streamlock.net/vod-multitrack/_definst_/smil:ElephantsDream/elephantsdream2.smil/playlist.m3u', description: 'Alternate audio tracks, and multiple VTT tracks' + }, + altAudioWithPdtAndStartGap: { + url: 'https://playertest.longtailvideo.com/adaptive/hls-test-streams/test-audio-pdt/playlist.m3u8', + description: 'PDT before each segment, 1.59s start gap', + abr: true, + startSeek: true } }; diff --git a/tests/unit/controller/gap-controller.js b/tests/unit/controller/gap-controller.js index 34c7c50d9ce..b2cd1b01816 100644 --- a/tests/unit/controller/gap-controller.js +++ b/tests/unit/controller/gap-controller.js @@ -1,10 +1,15 @@ +import sinon from 'sinon'; + import Hls from '../../../src/hls'; -import GapController from '../../../src/controller/gap-controller'; + +import GapController, { STALL_MINIMUM_DURATION_MS, SKIP_BUFFER_RANGE_START } from '../../../src/controller/gap-controller'; import { FragmentTracker } from '../../../src/controller/fragment-tracker'; + import Event from '../../../src/events'; + import { ErrorTypes, ErrorDetails } from '../../../src/errors'; -describe('checkBuffer', function () { +describe('GapController', function () { let gapController; let config; let media; @@ -108,73 +113,228 @@ describe('checkBuffer', function () { }); }); - describe('poll', function () { + describe('media clock polling', function () { + const TIMER_STEP_MS = 1234; + const STALL_HANDLING_RETRY_PERIOD_MS = 1000; + let mockMedia; + let mockTimeRanges; + let mockTimeRangesData; let reportStallSpy; let lastCurrentTime; - let buffered; + let isStalling; + let wallClock; + beforeEach(function () { - mockMedia = { - buffered: { - length: 1 + wallClock = sandbox.useFakeTimers(0); + isStalling = false; + mockTimeRangesData = [[0.1, 0.2], [0.4, 0.5]]; + mockTimeRanges = { + length: mockTimeRangesData.length, + start (index) { + return mockTimeRangesData[index][0]; + }, + end (index) { + return mockTimeRangesData[index][1]; } }; + + // by default the media + // is setup in a "playable" state + // note that the initial current time + // is within the range of buffered data info + mockMedia = { + currentTime: 0, + paused: false, + seeking: false, + readyState: 4, + buffered: mockTimeRanges, + addEventListener () {} + }; + gapController.media = mockMedia; reportStallSpy = sandbox.spy(gapController, '_reportStall'); - buffered = mockMedia.buffered; }); - function setStalling () { - mockMedia.paused = false; - mockMedia.readyState = 1; - mockMedia.currentTime = 4; - lastCurrentTime = 4; + // tickMediaClock emulates the behavior + // of our external polling schedule + // which would progress as the media clock + // is altered (or not) + // when isStalling is false the media clock + // will not progress while the poll call is done + function tickMediaClock (incrementSec = 0.1) { + lastCurrentTime = mockMedia.currentTime; + if (!isStalling) { + mockMedia.currentTime += incrementSec; + } + gapController.poll(lastCurrentTime); } - function setNotStalling () { - mockMedia.paused = false; - mockMedia.readyState = 4; - mockMedia.currentTime = 5; - lastCurrentTime = 4; - } + it('should progress internally as specified to handle a stalled playable media properly as wall clock advances', function () { + wallClock.tick(TIMER_STEP_MS); - it('should try to fix a stall if expected to be playing', function () { const fixStallStub = sandbox.stub(gapController, '_tryFixBufferStall'); - setStalling(); - gapController.poll(lastCurrentTime, buffered); - // The first poll call made while stalling just sets stall flags - expect(gapController.stalled).to.be.a('number'); - expect(gapController.stallReported).to.be.false; + expect(gapController.moved).to.equal(false); + + // we need to play a bit to get past the moved check + tickMediaClock(); + // check the moved flag has turned true + expect(gapController.moved).to.equal(true); + + // check that stall detection flags are still reset + expect(gapController.stalled).to.equal(null); + expect(gapController.stallReported).to.equal(false); - gapController.poll(lastCurrentTime, buffered); + // set stalling and tick media again + isStalling = true; + tickMediaClock(); + + // check that stall has been detected + expect(gapController.stalled).to.equal(TIMER_STEP_MS); + // check that stall has not been flagged reported + expect(gapController.stallReported).to.equal(false); + + expect(reportStallSpy).to.not.have.been.called; + expect(fixStallStub).to.not.have.been.called; + + wallClock.tick(STALL_MINIMUM_DURATION_MS / 2); + tickMediaClock(); + + // if stall was only sustained for below min duration, flags should be unchanged + // and no stall reported yet + expect(gapController.stalled).to.equal(TIMER_STEP_MS); + expect(gapController.stallReported).to.equal(false); + // nudge is attempted expect(fixStallStub).to.have.been.calledOnce; + + // more polling calls may happen without sys clock changing necessarily + tickMediaClock(); + // nudge is attempted + expect(fixStallStub).to.have.been.calledTwice; + + tickMediaClock(); + + // if stall was only sustained for below min duration, flags should be unchanged + // and no stall reported yet + expect(gapController.stalled).to.equal(TIMER_STEP_MS); + expect(gapController.stallReported).to.equal(false); + // nudge is attempted + expect(fixStallStub).to.have.been.calledThrice; + + // advance wall clock above threshold and tick media clock + wallClock.tick(STALL_MINIMUM_DURATION_MS / 2); + tickMediaClock(); + + // now more time has passed than the min stall duration + // which is threshold for reporting + // initial detection time is unchanged + expect(gapController.stalled).to.equal(TIMER_STEP_MS); + expect(gapController.stallReported).to.equal(true); + expect(reportStallSpy).to.have.been.calledOnce; + expect(fixStallStub).to.have.callCount(4); + + tickMediaClock(); + tickMediaClock(); + wallClock.tick(STALL_HANDLING_RETRY_PERIOD_MS / 2); + tickMediaClock(); + + expect(reportStallSpy).to.have.been.callCount(4); + expect(fixStallStub).to.have.callCount(7); + + wallClock.tick(STALL_HANDLING_RETRY_PERIOD_MS / 2); + tickMediaClock(); + + expect(reportStallSpy).to.have.been.callCount(5); + expect(fixStallStub).to.have.callCount(8); }); it('should reset stall flags when no longer stalling', function () { - setNotStalling(); gapController.stallReported = true; gapController.nudgeRetry = 1; gapController.stalled = 4200; + const fixStallStub = sandbox.stub(gapController, '_tryFixBufferStall'); - gapController.poll(lastCurrentTime, buffered); - expect(gapController.stalled).to.not.exist; + gapController.poll(lastCurrentTime); + + expect(gapController.stalled).to.equal(null); expect(gapController.nudgeRetry).to.equal(0); - expect(gapController.stallReported).to.be.false; - expect(fixStallStub).to.not.have.been.called; + expect(gapController.stallReported).to.equal(false); + + expect(reportStallSpy).to.have.not.been.called; + + expect(fixStallStub).to.have.not.been.called; }); - it('should trigger reportStall when stalling for 1 second or longer', function () { - setStalling(); - const clock = sandbox.useFakeTimers(0); - clock.tick(1000); - gapController.stalled = 1; - gapController.poll(lastCurrentTime, buffered); - expect(reportStallSpy).to.not.have.been.called; - clock.tick(1001); - gapController.poll(lastCurrentTime, buffered); - expect(reportStallSpy).to.have.been.calledOnce; + it('should not detect stalls when ended, unbuffered or seeking', function () { + wallClock.tick(TIMER_STEP_MS); + + // we need to play a bit to get past the moved check + tickMediaClock(); + + isStalling = true; + mockMedia.ended = true; + + tickMediaClock(); + expect(gapController.stalled).to.equal(null, 'ended'); + wallClock.tick(2 * STALL_HANDLING_RETRY_PERIOD_MS); + + mockMedia.ended = false; + mockMedia.buffered.length = 0; + + tickMediaClock(); + expect(gapController.stalled).to.equal(null, 'empty buffer'); + wallClock.tick(2 * STALL_HANDLING_RETRY_PERIOD_MS); + + mockMedia.buffered.length = mockTimeRangesData.length; + mockMedia.seeking = true; + + // tickMediaClock(100) + expect(gapController.stalled).to.equal(null, 'seeking'); + wallClock.tick(2 * STALL_HANDLING_RETRY_PERIOD_MS); + }); + + it('should not handle a stall (clock not advancing) when media has played before and is now paused', function () { + wallClock.tick(TIMER_STEP_MS); + + tickMediaClock(); + + expect(gapController.moved).to.equal(true); + expect(gapController.stalled).to.equal(null); + + mockMedia.paused = true; + isStalling = true; + + tickMediaClock(); + + expect(gapController.stalled).to.equal(null); + + mockMedia.paused = false; + + tickMediaClock(); + + expect(gapController.stalled).to.equal(TIMER_STEP_MS); + }); + + it('should skip any initial gap before playing on the second poll (so that Chrome can jump the gap first)', function () { + wallClock.tick(TIMER_STEP_MS); + + mockMedia.currentTime = 0; + + isStalling = true; + + tickMediaClock(); + + expect(gapController.moved).to.equal(false); + expect(gapController.stalled).to.equal(1234); + expect(mockMedia.currentTime).to.equal(0); + + tickMediaClock(); + + expect(gapController.moved).to.equal(true); + expect(gapController.stalled).to.equal(null); + expect(mockMedia.currentTime).to.equal(0.1 + SKIP_BUFFER_RANGE_START); }); }); });