Set media duration when attaching after level update

Fixes cause of intermittent functional test failures (+1 squashed commit)
Improve VOD seek functional test: fail on non-finite duration.
Logging fixes

src/controller/base-stream-controller.ts

@@ -337,7 +337,7 @@ export default class BaseStreamController extends TaskLoop implements NetworkCom
         }
         this.tick();
       }).catch(reason => {
-        logger.warn(reason);
+        this.warn(reason);
       });
   }
 
@@ -780,7 +780,7 @@ export default class BaseStreamController extends TaskLoop implements NetworkCom
         if (parsedDuration <= 0) {
           // Destroy the transmuxer after it's next time offset failed to advance because duration was <= 0.
           // The new transmuxer will be configured with a time offset matching the next fragment start, preventing the timeline from shifting.
-          logger.warn(`Could not parse fragment ${frag.sn} ${type} duration reliably (${parsedDuration}) resetting transmuxer to fallback to playlist timing`);
+          this.warn(`Could not parse fragment ${frag.sn} ${type} duration reliably (${parsedDuration}) resetting transmuxer to fallback to playlist timing`);
           if (this.transmuxer) {
             this.transmuxer.destroy();
             this.transmuxer = null;
@@ -803,7 +803,7 @@ export default class BaseStreamController extends TaskLoop implements NetworkCom
     const previousState = this._state;
     if (previousState !== nextState) {
       this._state = nextState;
-      this.log(`${previousState}->${nextState}`);
+      // this.log(`${previousState}->${nextState}`);
     }
   }
 

src/controller/buffer-controller.ts

@@ -19,9 +19,9 @@ import type Hls from '../hls';
 const MediaSource = getMediaSource();
 
 export default class BufferController implements ComponentAPI {
-  // the value that we have set mediasource.duration to
-  // (the actual duration may be tweaked slighly by the browser)
-  private _msDuration: number | null = null;
+  // The value mediasource.duration should have
+  // (the browser may return a slightly different value for mediasource.duration after being set)
+  private duration: number | null = null;
   // the target duration of the current media playlist
   private _levelTargetDuration: number | null = null;
   // current stream state: true - for live broadcast, false - for VoD content
@@ -114,7 +114,7 @@ export default class BufferController implements ComponentAPI {
       codecEvents = 1;
     }
     this.bufferCodecEventsExpected = this._bufferCodecEventsTotal = codecEvents;
-
+    this.duration = null;
     logger.log(`${this.bufferCodecEventsExpected} bufferCodec event(s) expected`);
   }
 
@@ -480,28 +480,26 @@ export default class BufferController implements ComponentAPI {
    */
   private updateMediaElementDuration (levelDuration: number) {
     if (!this.media || !this.mediaSource || this.mediaSource.readyState !== 'open') {
+      this.duration = levelDuration;
       return;
     }
-    const { hls, _live, media, mediaSource, _msDuration } = this;
+    const { hls, _live, media, mediaSource, duration } = this;
     const mediaDuration = media.duration;
-
-    // initialise to the value that the media source is reporting
-    let msDuration = _msDuration;
-    if (msDuration === null) {
-      this._msDuration = msDuration = mediaSource.duration;
-    }
+    const msDuration = duration === null ? mediaSource.duration : duration;
 
     if (_live && hls.config.liveDurationInfinity) {
       // Override duration to Infinity
       logger.log('[buffer-controller]: Media Source duration is set to Infinity');
-      this._msDuration = mediaSource.duration = Infinity;
+      this.duration = mediaSource.duration = Infinity;
     } else if ((levelDuration > msDuration && levelDuration > mediaDuration) || !Number.isFinite(mediaDuration)) {
       // levelDuration was the last value we set.
       // not using mediaSource.duration as the browser may tweak this value
       // only update Media Source duration if its value increase, this is to avoid
       // flushing already buffered portion when switching between quality level
       logger.log(`[buffer-controller]: Updating Media Source duration to ${levelDuration.toFixed(3)}`);
-      this._msDuration = mediaSource.duration = levelDuration;
+      this.duration = mediaSource.duration = levelDuration;
+    } else {
+      this.duration = msDuration;
     }
   }
 
@@ -584,6 +582,9 @@ export default class BufferController implements ComponentAPI {
     const { hls, media, mediaSource } = this;
     logger.log('[buffer-controller]: Media source opened');
     if (media) {
+      if (this.duration !== null) {
+        this.updateMediaElementDuration(this.duration);
+      }
       hls.trigger(Events.MEDIA_ATTACHED, { media });
     }
 

tests/functional/auto/setup.js

@@ -156,7 +156,7 @@ async function testSeekOnLive (url, config) {
     const video = self.video;
     video.onloadeddata = function () {
       self.setTimeout(function () {
-        video.currentTime = video.duration - 5;
+        video.currentTime = video.seekable.end(0) - 5;
       }, 5000);
     };
     video.onseeked = function () {
@@ -171,9 +171,20 @@ async function testSeekOnVOD (url, config) {
     const callback = arguments[arguments.length - 1];
     self.startStream(url, config, callback);
     const video = self.video;
+    video.ondurationchange = function () {
+      console.log('[test] > video  "durationchange": ' + video.duration);
+    };
     video.onloadeddata = function () {
+      console.log('[test] > video  "loadeddata"');
       self.setTimeout(function () {
         const duration = video.duration;
+        if (!isFinite(duration)) {
+          callback({
+            code: 'non-finite-duration',
+            duration,
+            logs: self.logString
+          });
+        }
         // After seeking timeout if paused after 5 seconds
         video.onseeked = function () {
           self.setTimeout(function () {
@@ -183,7 +194,7 @@ async function testSeekOnVOD (url, config) {
             }
           }, 5000);
         };
-        video.currentTime = duration - 5;
+        video.currentTime = video.seekable.end(0) - 5;
         // Fail test early if more than 2 buffered ranges are found (with configured exceptions)
         const allowedBufferedRanges = config.allowedBufferedRangesInSeekTest || 2;
         video.onprogress = function () {

tests/unit/controller/buffer-controller-operations.ts

@@ -20,10 +20,15 @@ const sandbox = sinon.createSandbox();
 
 class MockMediaSource {
   public readyState: string = 'open';
-  public duration: number = 0;
+  public duration: number = Infinity;
+
   addSourceBuffer () : MockSourceBuffer {
     return new MockSourceBuffer();
   }
+
+  addEventListener () {}
+
+  removeEventListener () {}
 }
 
 class MockSourceBuffer extends EventTarget {
@@ -57,7 +62,7 @@ class MockMediaElement {
 
 const queueNames: Array<SourceBufferName> = ['audio', 'video'];
 
-describe('BufferController SourceBuffer operation queueing', function () {
+describe('BufferController', function () {
   let hls;
   let bufferController;
   let operationQueue;
@@ -88,7 +93,7 @@ describe('BufferController SourceBuffer operation queueing', function () {
     sandbox.restore();
   });
 
-  it('cycles the queue on updateend', function () {
+  it('cycles the SourceBuffer operation queue on updateend', function () {
     const currentOnComplete = sandbox.spy();
     const currentOperation: BufferOperation = {
       execute: () => {},
@@ -114,7 +119,7 @@ describe('BufferController SourceBuffer operation queueing', function () {
     });
   });
 
-  it('does not cycle the queue on error', function () {
+  it('does not cycle the SourceBuffer operation queue on error', function () {
     const onError = sandbox.spy();
     const operation: BufferOperation = {
       execute: () => {},
@@ -173,7 +178,7 @@ describe('BufferController SourceBuffer operation queueing', function () {
       });
     });
 
-    it('should cycle the queue if the sourceBuffer does not exist while appending', function () {
+    it('should cycle the SourceBuffer operation queue if the sourceBuffer does not exist while appending', function () {
       const queueAppendSpy = sandbox.spy(operationQueue, 'append');
       queueNames.forEach((name, i) => {
         bufferController.sourceBuffer = {};
@@ -361,7 +366,7 @@ describe('BufferController SourceBuffer operation queueing', function () {
         totalduration: 5,
         fragments: [{ start: 5 }]
       });
-      mockMediaSource.duration = 0;
+      mockMediaSource.duration = Infinity;
       data = { details };
     });
 
@@ -397,12 +402,29 @@ describe('BufferController SourceBuffer operation queueing', function () {
       // Updating the duration is aync and has no event to signal completion, so we are unable to test for it directly
     });
 
-    it('synchronously updates the duration if no SourceBuffers exist', function () {
+    it('synchronously sets media duration if no SourceBuffers exist', function () {
       bufferController.sourceBuffer = {};
       bufferController.onLevelUpdated(Events.LEVEL_UPDATED, data);
       expect(queueAppendBlockerSpy).to.have.not.been.called;
       expect(mockMediaSource.duration, 'mediaSource.duration').to.equal(10);
-      expect(bufferController._msDuration, '_msDuration').to.equal(10);
+      expect(bufferController.duration, 'duration').to.equal(10);
+    });
+
+    it('sets media duration when attaching after level update', function () {
+      bufferController.sourceBuffer = {};
+      const media = bufferController.media;
+      // media is null prior to attaching
+      bufferController.media = null;
+      expect(mockMediaSource.duration, 'mediaSource.duration').to.equal(Infinity);
+      expect(bufferController.duration, 'duration').to.equal(null);
+      bufferController.onLevelUpdated(Events.LEVEL_UPDATED, data);
+      expect(mockMediaSource.duration, 'mediaSource.duration').to.equal(Infinity);
+      expect(bufferController.duration, 'duration').to.equal(10);
+      // simulate attach and open source buffers
+      bufferController.media = media;
+      bufferController._onMediaSourceOpen();
+      expect(mockMediaSource.duration, 'mediaSource.duration').to.equal(10);
+      expect(bufferController.duration, 'duration').to.equal(10);
     });
   });