Live edge calculation incorrect when UTCTiming element specified

[markogle]

Environment

• The MPD passes the DASH-IF Conformance Tool on http://dashif.org/conformance.html
• The stream has correct Access-Control-Allow-Origin headers (CORS)
• There are no network errors such as 404s in the browser console when trying to play the stream
• The issue observed is not mentioned on https://github.com/Dash-Industry-Forum/dash.js/wiki/FAQ
• The issue occurs in the latest reference client on http://dashif.org/reference/players/javascript/ and not just on my page

• Link to playable MPD file: http://live.unified-streaming.com/smptebitc/smptebitc.isml/.mpd
• Dash.js version: 2.4.1, 2.5.0, nightly
• Browser name/version: Chrome 58.0.3029.81
• OS name/version: macOS Sierra 10.12.4

Observed behaviour

When the UTCTiming element is specified the player seems to think the live edge is at the beginning of the DVR window rather than the end.

The example stream has a 5 minute DVR window, and has the UTC timestamp burnt in, so it is very easy to see that the player is running behind.

The stream works fine in dash.js up to 2.4.0, Shaka, and other players.

Console output

[28] [dash.js 2.5.0] MediaPlayer has been initialized 
Debug.js:108 [8670] Playback Initialized 
Debug.js:108 [8745] Parsing complete: ( xml2json: 12.4ms, objectiron: 12.3ms, total: 0.0248s) 
Debug.js:108 [8750] SegmentTimeline detected using calculated Live Edge Time 
Debug.js:108 [8751] Matching default timing source protocol to manifest protocol:  http://time.akamai.com/?iso 
Debug.js:108 [8753] Manifest has been refreshed at Fri May 05 2017 14:37:41 GMT+0200 (CEST)[1493987861.745]  
Debug.js:108 [8783] Local time:      Fri May 05 2017 14:37:41 GMT+0200 (CEST) 
Debug.js:108 [8784] Server time:     Fri May 05 2017 14:37:41 GMT+0200 (CEST) 
Debug.js:108 [8784] Difference (ms): -782 
Debug.js:108 [8793] MediaSource attached to element.  Waiting on open... 
Debug.js:108 [8800] MediaSource is open! 
Debug.js:108 [8800] Duration successfully set to: 1.7976931348623157e+308 
Debug.js:108 [8803] Added 0 inline events 
Debug.js:108 [8804] video codec: video/mp4;codecs="avc1.64001F" 
Debug.js:108 [8819] audio codec: audio/mp4;codecs="mp4a.40.2" 
Debug.js:108 [8821] No text data. 
Debug.js:108 [8821] No fragmentedText data. 
Debug.js:108 [8822] No embeddedText data. 
Debug.js:108 [8822] No muxed data. 
Debug.js:108 [8826] Getting the request for video time : 1493987564.08 
Debug.js:108 [8826] Index for video time 1493987564.08 is 5 
Debug.js:108 [8829] Schedule controller starting for video 
Debug.js:108 [8830] Getting the request for audio time : 1493987564.086077 
Debug.js:108 [8830] Index for audio time 1493987564.086077 is 4 
Debug.js:108 [8831] Schedule controller starting for audio 
Debug.js:108 [8831] Start Event Controller 
Debug.js:108 [8832] Native video element event: play 
Debug.js:108 [8833] Refresh manifest in 2 seconds. 
Debug.js:108 [8843] Top qualityvideo index has changed from undefined to 0 
Debug.js:108 [8846] AbrController (video) stay on 0/0 (buffer: 0) 
Debug.js:108 [8849] Top qualityaudio index has changed from undefined to 0 
Debug.js:108 [8850] AbrController (audio) stay on 0/0 (buffer: 0) 
Debug.js:108 [8867] Init fragment finished loading saving to video's init cache 
Debug.js:108 [8873] AbrController (video) stay on 0/0 (buffer: 0) 
Debug.js:108 [8873] Getting the request for video time : 1493987563.08 
Debug.js:108 [8874] Index for video time 1493987563.08 is 5 
Debug.js:108 [8874] SegmentTimeline: 1493987563.08 / Infinity 
Debug.js:108 [8878] Init fragment finished loading saving to audio's init cache 
Debug.js:108 [8880] Native video element event: loadedmetadata 
Debug.js:108 [8880] Requesting seek to time: 1493987563.08 
Debug.js:108 [8881] Starting playback at offset: 1493987563.08 
Debug.js:108 [8894] Seeking to: 1493987563.08 
Debug.js:108 [8903] Buffered Range for type: video : 1493987563.08  -  1493987564.08 
Debug.js:108 [8906] Got enough buffer to start. 
Debug.js:108 [8909] ThroughputRule requesting switch to index:  0 type:  video Average throughput 24876 kbps 
Debug.js:108 [8909] AbrController (video) stay on 0/0 (buffer: 1) 
Debug.js:108 [8910] Prior to making a request for time, NextFragmentRequestRule is aligning index handler's currentTime with bufferedRange.end. 1493987563.08  was changed to  1493987564.08 
Debug.js:108 [8910] Getting the request for video time : 1493987564.08 
Debug.js:108 [8910] Index for video time 1493987564.08 is 5 
Debug.js:108 [8911] SegmentTimeline: 1493987563.08 / Infinity 
Debug.js:108 [8911] Getting the next request at index: 6 
Debug.js:108 [8912] SegmentTimeline: 1493987564.08 / Infinity 
Debug.js:108 [8935] Buffered Range for type: video : 1493987563.08  -  1493987565.08 
Debug.js:108 [8938] ThroughputRule requesting switch to index:  0 type:  video Average throughput 49448 kbps 
Debug.js:108 [8938] AbrController (video) stay on 0/0 (buffer: 2) 
Debug.js:108 [8939] Getting the request for video time : 1493987565.08 
Debug.js:108 [8939] Index for video time 1493987565.08 is 6 
Debug.js:108 [8940] SegmentTimeline: 1493987564.08 / Infinity 
Debug.js:108 [8941] Getting the next request at index: 7 
Debug.js:108 [8941] SegmentTimeline: 1493987565.08 / Infinity 
Debug.js:108 [8965] Buffered Range for type: video : 1493987563.08  -  1493987566.08 
Debug.js:108 [8969] ThroughputRule requesting switch to index:  0 type:  video Average throughput 16624 kbps 
Debug.js:108 [8970] AbrController (video) stay on 0/0 (buffer: 3) 
Debug.js:108 [8971] Getting the request for video time : 1493987566.08 
Debug.js:108 [8971] Index for video time 1493987566.08 is 7 
Debug.js:108 [8972] SegmentTimeline: 1493987565.08 / Infinity 
Debug.js:108 [8972] Getting the next request at index: 8 
Debug.js:108 [8973] SegmentTimeline: 1493987566.08 / Infinity 
Debug.js:108 [8993] Buffered Range for type: video : 1493987563.08  -  1493987567.08 
Debug.js:108 [8995] ThroughputRule requesting switch to index:  0 type:  video Average throughput 49752 kbps 
Debug.js:108 [8996] AbrController (video) stay on 0/0 (buffer: 4) 

[davemevans]

Doesn't help the OP, but note this only seems to occur for SegmentTimeline - SegmentTemplate appears to work great e.g. http://24x7dash-i.akamaihd.net/dash/live/900080/dash-demo/dash.mpd

[TobbeEdgeware]

In the case of SegmentTimeline, dash.js deliberately does not look at UTCTiming at all. @wilaw intend to bring this up for discussion at DASH-IF face2face meeting next week. Some other players, notably shaka-player, uses UTCTiming also for SegmentTimeline.

[davemevans]

I have a feeling this might be down to suspect code generating the segment list in decideSegmentListRangeForTimeline. This was discussed briefly in #1270 (comment). Perhaps a problem still exists.

[TobbeEdgeware]

We have observed the same when introducing UTCTiming, so it is definitely not ignored. There seems to be more issues with SegmentTimeline as indicated by #1928.

[AxelDelmas]

We're having this issue as well. It also causes an exception if the user tries to set a latency > 10 segments.
Here's our manifest that reproduces the issue (90s DVR): http://wowza.streamroot.io/liveorigin/Sample-live.smil/manifest.mpd

It is indeed due to the maxSegmentsAhead in TimelineSegmentsGetter. Because of that this method only returns the first 10 segments of the DVR window, which is bad because the 1st time it's called the liveEdge is set to the timestamp of the last segment of this list (https://github.com/Dash-Industry-Forum/dash.js/blob/67a63fd/src/dash/DashHandler.js#L229-L235).

Regarding why it happens when UTCTiming is specified: maxSegmentsAhead is used when calculatedRange is null here: https://github.com/Dash-Industry-Forum/dash.js/blob/67a63fd/src/dash/utils/TimelineSegmentsGetter.js#L149-L159

calculatedRange is calculated by this method
timelineConverter.isTimeSyncCompleted() returns true in our case (I guess because UTCTiming is specified), so this method returns null instead of a range {start: 0, end: Infinity} that would cause TimelineSegmentsGetter to loop through all the segment instead of the 1st 10.