995090 - Cloned media element should be able to play till the end even after the src attribute of the original is changed

Status: RESOLVED FIXED

(Core :: Audio/Video, defect)

Description

[JW Wang [:jwwang] [:jw_wang]]

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/32.0.1700.102 Chrome/32.0.1700.102 Safari/537.36

Steps to reproduce:

When the 'src' attribute is reset, the underlying decoder will be destroyed as well as the MediaResource. If the MediaResource is destroyed before download complete, the cloned MediaResource will not have enough data for the cloned media element to play till the end.

Comment 1

[JW Wang [:jwwang] [:jw_wang]]

Attachment: part1_addtest.patch

test case.

Comment 2

[JW Wang [:jwwang] [:jw_wang]]

(In reply to JW Wang [:jwwang] from comment #1)
> Created attachment 8405207 [details] [diff] [review]
> part1_addtest.patch
> 
> test case.

This test case tries to clone a media element and see if the cloned one can play till the end after the source of the original element is reset. (which will implicitly destroys the underlying decoder and MediaResource of the original element)

Comment 3

[JW Wang [:jwwang] [:jw_wang]]

try: https://tbpl.mozilla.org/php/getParsedLog.php?id=37612991&tree=Try

1243 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_clone_media_element.html | vp9cake.webm-35: ended event not received.
1281 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_clone_media_element.html | gizmo.mp4-48: ended event not received.

Comment 4

[Chris Pearce [:cpearce (Not reading bugmail)]]

Wow. Good catch!

Comment 5

[Robert O'Callahan (:roc) (email my personal email if necessary)]

This is supposed to work. If the cloned media element needs to read data that's not in the media cache, and there is no ChannelMediaResource currently reading, then we will wake up one of the ChannelMediaResources for that resource and ask it to open a channel to read.

Comment 6

[JW Wang [:jwwang] [:jw_wang]]

(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #5)
> This is supposed to work. If the cloned media element needs to read data
> that's not in the media cache, and there is no ChannelMediaResource
> currently reading, then we will wake up one of the ChannelMediaResources for
> that resource and ask it to open a channel to read.

Can you show me the code snippet which wake up the reader?

Comment 7

[Robert O'Callahan (:roc) (email my personal email if necessary)]

The logic in MediaCache::Update computes for each MediaCacheStream whether it should be reading or not. For your cloned stream, it should compute enableReading == true sometimes. While the original ChannelMediaResource exists, we will reach the code commented
            // This block is already going to be read by the other stream.
            // So don't try to read it from this stream as well.
and set enableReading to false to not wake up the clone's ChannelMediaResource. But when the original has gone away, we should keep going and set actions[i] to RESUME or SEEK_AND_RESUME, causing us to call ChannelMediaResource::CacheClientSeek or ChannelMediaResource::CacheClientResume.

Comment 8

[Benjamin Chen [:bechen]]

I have tried the testcase patch and enable the prlog in MediaCache and MedaiResource.
Found that the timeout is triggered by not receive ontimeupdate for 10 seconds.
I'll try to figure out why the timeupdate is not fired.

Comment 9

[JW Wang [:jwwang] [:jw_wang]]

Ok, I figure out what's going on. Here is the log:

 0:14.40 2014-04-22 10:29:01.034557 UTC - 2022004480[7ff15d941da0]: Stream 7ff15cdb14b8 read wait <-- MediaCacheStream::Read, the cloned stream blocks for no data has been read yet
 0:14.40 2014-04-22 10:29:01.034594 UTC - -1916147904[7ff18c9194a0]: MediaCache::Update (1)
 0:14.40 2014-04-22 10:29:01.034598 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15b20b4b8 feeding reader
 0:14.40 2014-04-22 10:29:01.034600 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15cdb14b8 catching up
 0:14.40 2014-04-22 10:29:01.034601 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15cdb14b8 waiting on same block (0) from stream 7ff15b20b4b8 <-- waiting for this block to be filled by the original stream
 0:14.40 2014-04-22 10:29:01.034604 UTC - -1916147904[7ff18c9194a0]: MediaCache::Update (2)
 0:14.40 2014-04-22 10:29:01.034605 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15b20b4b8 action=0
 0:14.40 2014-04-22 10:29:01.034606 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15cdb14b8 action=0
 0:14.40 2014-04-22 10:29:01.034608 UTC - -1916147904[7ff18c9194a0]: MediaCache::Update (3)
 0:14.40 2014-04-22 10:29:01.034789 UTC - -1916147904[7ff18c9194a0]: Decoder=7ff15b2671a0 Changed state to SHUTDOWN <-- reset the src attribute of the original element
 0:14.40 2014-04-22 10:29:01.034799 UTC - -1916147904[7ff18c9194a0]: MediaCacheStream::Close=7ff15b20b4b8 <-- MediaCacheStream::Close called by ChannelMediaResource::Close
 0:14.40 2014-04-22 10:29:01.034814 UTC - 2022004480[7ff15d941da0]: Stream 7ff15cdb14b8 read wait <-- the cloned stream still blocks for no data has been read yet
 0:14.40 [26046] WARNING: Resource read failed: file /home/jwwang/codebase/mozilla-central2/content/media/wave/WaveReader.cpp, line 305 <-- read failed for the original stream is closed
 0:14.40 2014-04-22 10:29:01.034861 UTC - 2032355072[7ff15c97c8a0]: Decoder=7ff15b2671a0 SetReaderIdle() audioQueue=0 videoQueue=0
 0:14.40 31 INFO TEST-PASS | /tests/content/media/test/test_load_same_resource.html | Clone loaded OK
 0:14.40 32 INFO TEST-PASS | /tests/content/media/test/test_load_same_resource.html | Clone http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav duration: 1 expected: 1
 0:14.40 2014-04-22 10:29:01.035647 UTC - 1881851648[7ff15ae1b040]: Decoder=7ff15b268640 StartPlayback()
 0:14.40 2014-04-22 10:29:01.035720 UTC - 1885558528[7ff15d942460]: Decoder=7ff15b268640 Begun audio thread/loop
 0:14.40 2014-04-22 10:29:01.036668 UTC - 1885558528[7ff15d942460]: Decoder=7ff15b268640 playing 2048 frames of data to stream for AudioData at 0
 0:14.40 2014-04-22 10:29:01.037051 UTC - -1916147904[7ff18c9194a0]: MediaCache::Update (1)
 0:14.40 2014-04-22 10:29:01.037057 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15cdb14b8 catching up
 0:14.40 2014-04-22 10:29:01.037060 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15cdb14b8 waiting on same block (0) from stream 7ff15b20b4b8
 0:14.40 2014-04-22 10:29:01.037062 UTC - -1916147904[7ff18c9194a0]: MediaCache::Update (2)
 0:14.40 2014-04-22 10:29:01.037064 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15b20b4b8 action=0
 0:14.40 2014-04-22 10:29:01.037065 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15cdb14b8 action=0
 0:14.40 2014-04-22 10:29:01.037067 UTC - -1916147904[7ff18c9194a0]: MediaCache::Update (3)
 0:14.40 2014-04-22 10:29:01.037234 UTC - -1916147904[7ff18c9194a0]: Stream 7ff15b20b4b8 closed <-- MediaCache::ReleaseStream, the original stream is removed from the array of MediaCache


I think the fix is to call MediaCache::Update again in MediaCache::ReleaseStream, otherwise MediaCache::Update will not see the change in MediaCache::mStreams and the cloned stream will still wait for the block to be filled by the original stream.

Comment 10

[Robert O'Callahan (:roc) (email my personal email if necessary)]

That sounds right! But call gMediaCache->QueueUpdate() instead of calling Update() directly.

Comment 11

[JW Wang [:jwwang] [:jw_wang]]

Attachment: 995090_fix.patch

See comment 9 for this fix.

Comment 12

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Comment on attachment 8410199 [details] [diff] [review]
995090_fix.patch

Review of attachment 8410199 [details] [diff] [review]:
-----------------------------------------------------------------

Please modify the comment to explicitly say that we need to re-run Update() to ensure streams reading from the same resource as the removed stream get a chance to continue reading.

Comment 13

[JW Wang [:jwwang] [:jw_wang]]

Attachment: 995090_fix-v2.patch

Comment 14

[JW Wang [:jwwang] [:jw_wang]]

Please check in 995090_fix-v2.patch only. Thanks.

Comment 15

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/b2g-inbound/rev/55c4e39a1e38

Did we still want to land the test attached here at some point?

Comment 16

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/55c4e39a1e38

Comment 17

[JW Wang [:jwwang] [:jw_wang]]

(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #15)
> https://hg.mozilla.org/integration/b2g-inbound/rev/55c4e39a1e38
> 
> Did we still want to land the test attached here at some point?

When running tests in parallel (PARALLEL_TESTS = 2 in content/media/test/manifest.js), other original/clone streams will also update MediaCache which will hide the fact that MediaCache::ReleaseStream doesn't update MediaCache after changing |mStreams|. I will modify the test case to meet that condition.

Comment 18

[JW Wang [:jwwang] [:jw_wang]]

Attachment: 995090_testcase.patch

test case - test if cloned media element should be able to play till the end even after the src attribute of the original is changed.

try: https://tbpl.mozilla.org/?tree=Try&rev=3ceb44f417c0
no failures on all platforms.

Comment 19

[JW Wang [:jwwang] [:jw_wang]]

Please check in 995090_testcase.patch only. Thanks.

Comment 20

[Carsten Book [:Tomcat]]

(In reply to JW Wang [:jwwang] from comment #19)
> Please check in 995090_testcase.patch only. Thanks.

done! https://hg.mozilla.org/integration/mozilla-inbound/rev/c8b374bf936b

Comment 21

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/c8b374bf936b