Shaka-player: Chromecast intermittently not playing from live edge for live media

[mattcroberts]

Have you read the FAQ and checked for duplicate open issues?
Yes

What version of Shaka Player are you using?
3.0.1

Can you reproduce the issue with our latest release version?
Yes

Are you using the demo app or your own custom app?
Custom

If custom app, can you reproduce the issue using our demo app?
No. No live media.

What browser and OS are you using?
Chromecast Gen 1/2

For embedded devices (smart TVs, etc.), what model and firmware version are you using?
Chromecast Gen 1/2. firmware 1.42.172094

What did you do?

1. Initialise chromecast
2. Load live stream with start time as 0 or null

OR

1. Initialise chromecast
2. Load stream with start time as 0 or null
3. Switch to another live stream with start time as 0 or null

shakaPlayer.load(<manifest URL>, null);

What did you expect to happen?
Stream to play from live edge.

What actually happened?

Most of the time, stream plays correctly from live edge. However sometimes it'll play from the start of the stream, not the live edge. This occurs intermittently, approx 1 in 4 times.

I cannot reproduce this bug on desktop chrome, only chromecast.

Using the debug version of shaka I can see the following log when the bug occurs:

Starting load of https://<redacted>
player.core.js:413 Found variant with audio and video content, so filtering out audio-only content.
player.core.js:413 switch_
player.core.js:413 Created MediaKeys object for key system com.widevine.alpha
47player.core.js:413 Ignoring duplicate init data.
player.core.js:413 switch_
player.core.js:413 codecs avc1-mp4a avg bandwidth 2882656
player.core.js:413 init: completed initial Stream setup
48player.core.js:413 Ignoring duplicate init data.
player.core.js:413 switch_
6player.core.js:413 switch_
player.core.js:413 switch_
2player.core.js:413 switch_
player.core.js:413 Jumping forward 1595350678.76 seconds to catch up with the seek range.
player.core.js:413 switch_
player.core.js:413 (audio:2) clear: handling right now
player.core.js:413 (audio:2) clearing buffer
player.core.js:413 (video:3) clear: currently updating
player.core.js:413 (video:3) skipping update and clearing the buffer
player.core.js:413 (video:3) clearing buffer
player.core.js:413 switch_
player.core.js:413 (video:3) clear: already clearing the buffer
player.core.js:413 (audio:2) cleared buffer
player.core.js:413 Updating manifest...
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 (video:3) cleared buffer
player.core.js:413 switch_
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 switch_
48player.core.js:413 Ignoring duplicate init data.
2player.core.js:413 switch_
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 switch_
2player.core.js:413 switch_
2player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 switch_
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
2player.core.js:413 switch_
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 switch_
2player.core.js:413 switch_
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 switch_
player.core.js:413 (all): seeked: buffered seek: presentationTime=1595350678.76
player.core.js:413 Failed to move playhead from 1595350678.76 to 1595350678.76

The relevant parts are player.core.js:413 Jumping forward 1595350678.76 seconds to catch up with the seek range. and player.core.js:413 Failed to move playhead from 1595350678.76 to 1595350678.76 where 1595350678.76 is the start time/offset of the stream.

[avelad]

I reproduced this in Tizen, but I didn't have time to report it.

[joeyparrish]

Load live stream with start time as 0 or null

There is a difference between 0 and null. A value of null for a live stream means "play from live edge", whereas a value of 0 means play from timestamp 0. Playing from 0 will be corrected later by jumping forward to catch up with the seek range, as noted in your logs.

Someone reported a similar issue through internal channels, and we determined it to be triggered by the specific makeup of the DASH manifest. Can either of you provide a manifest that will reproduce the issue? Or can you check to see if you are using a mix of SegmentBase in some periods with SegmentTemplate, SegmentTimeline, or SegmentList in others?

[avelad]

@joeyparrish , I sent you a stream by mail

[mattcroberts]

There is a difference between 0 and null. A value of null for a live stream means "play from live edge", whereas a value of 0 means play from timestamp 0. Playing from 0 will be corrected later by jumping forward to catch up with the seek range, as noted in your logs.

I have done some more digging and in our code we have the following line, so 0 start time isn't relevant in this case:

const resumeFrom = startTime > 0 ? startTime : null;
await this.shakaPlayer.load(src, resumeFrom);

Also I added some additional logging into shaka (v3.0.4) to investigate the internals of whats happening - replacing this function from https://github.com/google/shaka-player/blob/f5d58f6c7849bf46512e217a943049fe10c587ba/lib/media/playhead.js

  onPollWindow_() {
    // Don't catch up to the seek range when we are paused or empty.
    // The definition of "seeking" says that we are seeking until the buffered
    // data intersects with the playhead.  If we fall outside of the seek range,
    // it doesn't matter if we are in a "seeking" state.  We can and should go
    // ahead and catch up while seeking.
    if (this.mediaElement_.readyState == 0 || this.mediaElement_.paused) {
      return;
    }

    const currentTime = this.mediaElement_.currentTime;
    let seekStart = this.timeline_.getSeekRangeStart();
    const seekEnd = this.timeline_.getSeekRangeEnd();

    if (seekEnd - seekStart < this.minSeekRange_) {
      seekStart = seekEnd - this.minSeekRange_;
    }

    shaka.log.info(`
      MATT currentTime=${currentTime} 
      readyState=${this.mediaElement_.readyState}
    `);

    if (currentTime < seekStart) {
      // The seek range has moved past the playhead.  Move ahead to catch up.
      const targetTime = this.reposition_(currentTime);
      shaka.log.info('Jumping forward ' + (targetTime - currentTime) +
                     ' seconds to catch up with the seek range.');
      this.mediaElement_.currentTime = targetTime;
    }
  }

I've found that when this bug occurs, the currentTime is 0 and readyState is 1 (HAVE_METADATA).

MATT currentTime=0 readyState=1

This does not occur when the bug doesn't show, the currentTime is always > 0.

Full logs for happy and sad path are here: https://gist.github.com/mattcroberts/60893ccdda1ae1be8d1f492495c90f13

I hope this helps diagnosing the issue, please let me know if you need any further information.

[richsparks]

Does the information provided @mattcroberts match the findings of other investigations? Is any further information required? This issue can also be seen using Chrome with the same issue of zero currentTime triggering a seek to the start of the stream instead of the requested resumeFrom time.

[joeyparrish]

I believe this will be solved by PR #2849. Can anyone here test that and confirm?

[avelad]

@joeyparrish, I tested on Tizen 5.5 (Samsung 2020). And with the change, now it works fine!

[joeyparrish]

Great news. Thanks for the update!