1116645 - MSE Compliance Test: Fail test 23: DurationAfterAppendAudio

Status: RESOLVED WORKSFORME

(Core :: Audio/Video: Playback, defect, P3)

Description

[Jean-Yves Avenard [:jya]]

TestRunner:  All tests are completed 
TestRunner:  Longest test is DurationAfterAppendAudio, it takes 0.029333333333333333 of its timeout. 
TestRunner:  Finished! 
TestRunner:  New longest test DurationAfterAppendAudio with timeout 30000 takes 880 
TestRunner:  TestRunner.prototype.error@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20141211110536.js:410:9
TestRunner.prototype.assert@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20141211110536.js:180:5
TestRunner.prototype.check@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20141211110536.js:197:5
TestRunner.prototype.checkApproxEq@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20141211110536.js:226:1
onFirstDurationChange@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/tests/2015/conformanceTest-20141211110536.js:470:1
ConformanceTest/createDurationAfterAppendTest/test.prototype.onsourceopen/xhr</updateCb@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/tests/2015/conformanceTest-20141211110536.js:480:27
 
DurationAfterAppendAudio:    0: (0, 65.875011) 
DurationAfterAppendAudio:  sb0.buffered.length 1 
DurationAfterAppendAudio:  ms.sb count = 1 
DurationAfterAppendAudio:  video.networkState = 2 
DurationAfterAppendAudio:  video.readyState = 0 
DurationAfterAppendAudio:  video.currentTime = 0 
TestRunner:  Assert failed: ms.duration is (32.9375055) which should between [65.375011, 66.375011] 
DurationAfterAppendAudio:  onFirstDurationChange called 
TestRunner:  checkNE passed: request index is (0). 
TestRunner:  checkEq passed: XHR requestType is (GET). 
TestRunner:  checkEq passed: request index is (-1). 
DurationAfterAppendAudio:  MS test started 
TestRunner:  Starting test 23:DurationAfterAppendAudio with timeout 30000

Comment 1

[Jean-Yves Avenard [:jya]]

The test for 23 and 24 available on:
http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/2015.html?timestamp=1421449617983

the source code for those is:
       {
            media.addEventListener(
                'durationchange', function onFirstDurationChange() {
              self.log('onFirstDurationChange called');
              media.removeEventListener('durationchange',
                                        onFirstDurationChange);
              // This will fail if the buffer hasn't been trimmed.
              runner.checkApproxEq(ms.duration, sb.buffered.end(0),
                                   'ms.duration');
              sb.addEventListener('update', function() {
                self.log('onSecondDurationChange called');
                runner.checkApproxEq(ms.duration, sb.buffered.end(0),
                                     'ms.duration');
                runner.succeed();
              });
              sb.appendBuffer(data);
            });
            ms.duration = sb.buffered.end(0) / 2;
          }
        };

        sb.addEventListener('update', updateCb);
        sb.appendBuffer(data);


So it does:
sb.appendBuffer(data) (this is a 1MB chunk, with both init segment and media segments).
For the audio test, this adds 65s worth of audio.
Following bug 1118123, we properly adjust the duration of the video element.

Then it does:
ms.duration = sb.buffered.end(0) / 2;

This will truncate the duration of the mediasource, which will adjust the size of the media element attached to the mediasource object.
And fire the "durationchange" event.

The test immediately checks upon durationchange that the ms.buffered.end(0) has been truncated by the Range Removal Algorithm.
This we will fail, as the sourcebuffer hasn't been trimmed yet upon firing durationchange.

My reading of the spec, is that there is no guarantee that upon the durationchange event we would have already trimmed the buffer, and that the test is wrong.

http://w3c.github.io/media-source/#duration-change-algorithm
2.4.6 Duration change

Follow these steps when duration needs to change to a new duration.

	• If the current value of duration is equal to new duration, then return.
	• Set old duration to the current value of duration.
	• Update duration to new duration.
	• If the new duration is less than old duration, then run the range removal algorithm with new duration and old duration as the start and end of the removal range.
	• If a user agent is unable to partially render audio frames or text cues that start before and end after the duration, then run the following steps:
		• Update new duration to the highest end time reported by the buffered attribute across all SourceBuffer objects in sourceBuffers.
		• Update duration to new duration.
	• Update the media controller duration to new duration and run the HTMLMediaElement duration change algorithm.

The Range Removal Algorithm according to the spec:
http://w3c.github.io/media-source/#sourcebuffer-range-removal

3.5.7 Range Removal

Follow these steps when a caller needs to initiate a JavaScript visible range removal operation that blocks other SourceBuffer updates:

	• Let start equal the starting presentation timestamp for the removal range.
	• Let end equal the end presentation timestamp for the removal range.
	• Set the updating attribute to true.
	• Queue a task to fire a simple event named updatestart at this SourceBuffer object.
	• Return control to the caller and run the rest of the steps asynchronously.
	• Run the coded frame removal algorithm with start and end as the start and end of the removal range.
	• Set the updating attribute to false.
	• Queue a task to fire a simple event named update at this SourceBuffer object.
	• Queue a task to fire a simple event named updateend at this SourceBuffer object.

Note the: "Return control to the caller and run the rest of the steps asynchronously."

Range Removal being run asynchronously, there's no guarantee that upon firing durationchange it would have completed.
When Range Removal Algorithm has completed, it will fire the "updateend" event ; and this is what the test should rely on before testing the size of the buffered range.

If I modify the code in bug 1118126 so that the Range Removal Algorithm is run synchronously ; then we pass this YouTube's test.

YouTube would need to fix var createDurationAfterAppendTest() test in http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/tests/2015/conformanceTest-20141211110536.js

Karl, could you please check if my analysis is correct ? thanks

Comment 2

[Karl Tomlinson (:karlt)]

(In reply to Jean-Yves Avenard [:jya] from comment #1)
> Then it does:
> ms.duration = sb.buffered.end(0) / 2;
> 
> This will truncate the duration of the mediasource, which will adjust the
> size of the media element attached to the mediasource object.
> And fire the "durationchange" event.

This should queue the "durationchange" event instead of firing it.
That is bug 123189.

> Note the: "Return control to the caller and run the rest of the steps
> asynchronously."
> 
> Range Removal being run asynchronously, there's no guarantee that upon
> firing durationchange it would have completed.
> When Range Removal Algorithm has completed, it will fire the "updateend"
> event ; and this is what the test should rely on before testing the size of
> the buffered range.

"update" or "updateend", yes.

AFAICT the MediaSource spec does not seem clear on what is meant by
"asynchronously".

Some algorithms in HTML5 explicitly describe awaiting a stable state [1], which
seems to be a time to run processing (a so-called "synchronous section")
before any other (asynchronous) tasks are run.  These algorithms seem explicit
about what is run in the synchronous section and when subsequent async tasks
are run.  However Media Source Extensions are not similarly specified.

If the asynchronous parts of the range removal algorithm are run using the
usual task queue then they would be queued before the durationchange event is
queued and so the test would pass.  I don't know whether this is what is
intended by the spec or whether the spec expects this to happen on another
thread and so might happen out of order with tasks on the task queue.

Given the effort to provide update and updateend events I suspect that the
timing of "asynchronous" parts of algorithms is not intended to be
predictable, and so I would agree with your analysis.

> If I modify the code in bug 1118126 so that the Range Removal Algorithm is
> run synchronously ; then we pass this YouTube's test.

I haven't seen this code, but I suspect that this test would happen to pass if
range removal happens to be implemented using the main thread task queue and
"durationchange" is queued appropriately (bug 123189).

[1] http://www.w3.org/html/wg/drafts/html/master/webappapis.html#await-a-stable-state

Comment 3

[Jean-Yves Avenard [:jya]]

(In reply to Karl Tomlinson (back 19 Jan :karlt) from comment #2)
> (In reply to Jean-Yves Avenard [:jya] from comment #1)
> > Then it does:
> > ms.duration = sb.buffered.end(0) / 2;
> > 
> > This will truncate the duration of the mediasource, which will adjust the
> > size of the media element attached to the mediasource object.
> > And fire the "durationchange" event.
> 
> This should queue the "durationchange" event instead of firing it.
> That is bug 123189.

Even if you did queue the durationchange ; there's still no guarantee that the Range Removal algorithm would have run its course (see below)

> I haven't seen this code, but I suspect that this test would happen to pass
> if
> range removal happens to be implemented using the main thread task queue and
> "durationchange" is queued appropriately (bug 123189).

the code is still in my queue as I'm still trying to fix why bug 1118589 still causes the EME mochi to fail

Yes, if we were to queue duration change after we've queued the Range Removal task it would indeed work. That's only assuming they both are queued on the main thread.
That's an assumption I believe we need to break from, especially in regards to appendBuffer that could take a considerable more amount of time compare to what it is now (ref bug 1119208).

Queueing the duration change for mediasource would be a step forward already. Especially now that ReadMetadata won't fire a durationchange (bug 1120282).

And that would make it pass this particular case.

Comment 4

[Takanori MATSUURA]

This seems to be fixed.

TestRunner:  All tests are completed 
TestRunner:  Longest test is DurationAfterAppendAudio, it takes 0.0019666666666666665 of its timeout. 
TestRunner:  Finished! 
TestRunner:  New longest test DurationAfterAppendAudio with timeout 30000 takes 59 
TestRunner:  Test DurationAfterAppendAudio succeeded. 
TestRunner:  checkApproxEq passed: ms.duration is (32.9375055). 
DurationAfterAppendAudio:  onSecondDurationChange called 
TestRunner:  checkApproxEq passed: ms.duration is (32.9375055). 
DurationAfterAppendAudio:  onFirstDurationChange called 
TestRunner:  checkNE passed: request index is (0). 
TestRunner:  checkEq passed: XHR requestType is (GET). 
TestRunner:  checkEq passed: request index is (-1). 
DurationAfterAppendAudio:  MS test started 
TestRunner:  Starting test 23:DurationAfterAppendAudio with timeout 30000 
TestRunner:  Media Source and Encrypted Media Conformance Tests (version 20150326133122-e5cOEaP8ocqTCH34)

Comment 5

[Takanori MATSUURA]

Log using ver. 20150729140035-uXMqKELDmjp4d9N5:

TestRunner:  All tests are completed 
TestRunner:  Longest test is DurationAfterAppendAudio, it takes 0.0015333333333333334 of its timeout. 
TestRunner:  Finished! 
TestRunner:  New longest test DurationAfterAppendAudio with timeout 30000 takes 46 
TestRunner:  TestRunner.prototype.error@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:411:9
TestRunner.prototype.assert@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:181:5
TestRunner.prototype.check@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:198:5
TestRunner.prototype.checkApproxEq@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:227:1
onFirstDurationChange@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/tests/2015/conformanceTest-20150729140035.js:422:1
EventListener.handleEvent*TestRunner.prototype.startNextTest/this.currentTest.video.addEventListener@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:378:9
ConformanceTest/createDurationAfterAppendTest/test.prototype.onsourceopen/xhr</updateCb@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/tests/2015/conformanceTest-20150729140035.js:416:1
EventListener.handleEvent*ConformanceTest/createDurationAfterAppendTest/test.prototype.onsourceopen/xhr<@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/tests/2015/conformanceTest-20150729140035.js:436:9
Request/this.open/<@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/xhr-20150729140035.js:63:14
EventListener.handleEvent*Request/this.open@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/xhr-20150729140035.js:61:5
EventListener.handleEvent*window.createMSTest/t.prototype.start@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:136:1
TestRunner.prototype.startNextTest@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:388:3
EventHandlerNonNull*Test/this.createElement@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/compactTestList-20150729140035.js:56:5
TestList/createExtraCompactTable/createTestCells@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/compactTestList-20150729140035.js:173:7
TestList/createExtraCompactTable@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/compactTestList-20150729140035.js:219:7
TestList/this.generate@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/compactTestList-20150729140035.js:243:7
TestView/this.generate@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/testView-20150729140035.js:170:5
CompactTestView/this.generate@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/compactTestView-20150729140035.js:52:5
TestRunner.prototype.initialize@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/test-20150729140035.js:288:3
startRunner@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/main-20150729140035.js:145:3
window.startMseTest@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/js/harness/main-20150729140035.js:161:3
@http://yt-dash-mse-test.commondatastorage.googleapis.com/unit-tests/2015.html?timestamp=1439370090215&tests=23:48:7
 
DurationAfterAppendAudio:    0: (0, 32.949115) 
DurationAfterAppendAudio:  sb0.buffered.length 1 
DurationAfterAppendAudio:  ms.sb count = 1 
DurationAfterAppendAudio:  video.networkState = 2 
DurationAfterAppendAudio:  video.readyState = 2 
DurationAfterAppendAudio:  video.currentTime = 0 
TestRunner:  Assert failed: ms.duration is (32.9375055) which should between [65.375011, 66.375011] 
DurationAfterAppendAudio:  onFirstDurationChange called 
TestRunner:  checkNE passed: request index is (0). 
TestRunner:  checkEq passed: XHR requestType is (GET). 
TestRunner:  checkEq passed: request index is (-1). 
DurationAfterAppendAudio:  MS test started 
TestRunner:  Starting test 23:DurationAfterAppendAudio with timeout 30000 
TestRunner:  Media Source and Encrypted Media Conformance Tests (version 20150729140035-uXMqKELDmjp4d9N5)

Comment 6

[Jean-Yves Avenard [:jya]]

the test is wrong.

It tests that data has been evicted immediately after changing the mediasource.element

This is incorrect, as the Coded Frame Removal algorithm is to run asynchronously.

this was all explained in comment 3

Comment 7

[Takanori MATSUURA]

Test passed.

TTestRunner:  All tests are completed
TestRunner:  Longest test is DurationAfterAppendAudio, it takes 0.010333333333333333 of its timeout.
TestRunner:  Finished!
TestRunner:  New longest test DurationAfterAppendAudio with timeout 30000 takes 310
TestRunner:  Test DurationAfterAppendAudio succeeded.
TestRunner:  checkApproxEq passed: ms.duration is (32.9375055).
DurationAfterAppendAudio:  onSecondDurationChange called
TestRunner:  checkApproxEq passed: ms.duration is (32.9375055).
DurationAfterAppendAudio:  onFirstDurationChange called
TestRunner:  checkNE passed: request index is (0).
TestRunner:  checkEq passed: XHR requestType is (GET).
TestRunner:  checkEq passed: request index is (-1).
DurationAfterAppendAudio:  MS test started
TestRunner:  Starting test 23:DurationAfterAppendAudio with timeout 30000
TestRunner:  Media Source and Encrypted Media Conformance Tests (version 20151028103055-eGWzMcOnijcb7b0S)