1184429 - WebM playback performance issue.

Status: RESOLVED FIXED

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

Description

[Benjamin Chen [:bechen]]

See bug 1183955 comment 8, bug 1110922 comment 56, comment 58.

Comment 1

[Benjamin Chen [:bechen]]

There is another weird behavior from the log I saw.
During the seeking, 
|MediaDecoderReader::DispatchNotifyDataArrived| is invoked with the same arguments repeatedly. Then I saw many 
|ThrottledNotifyDataArrived| were executed with the same argument.

For example: The DispatchNotifyDataArrived notify the WebMReader with argument offset 0, length 8192, 3 times. So the WebMReader read the same offset 3 times then send the data into WebMBufferParser.

Comment 2

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

Can you check if data is evicted from MediaCache so that the http channel is closed and opened again to download the data that was already downloaded before?

Comment 3

[Benjamin Chen [:bechen]]

(In reply to JW Wang [:jwwang] from comment #2)
> Can you check if data is evicted from MediaCache so that the http channel is
> closed and opened again to download the data that was already downloaded
> before?

Yes, I will check it later.
Now I'm going to write a patch in WebMBufferedParser for reducing the |SilentReadAt| if the data chunk had already sent into WebMBufferedParser.

Comment 4

[Jean-Yves Avenard [:jya]]

(In reply to Benjamin Chen [:bechen] from comment #3)
> (In reply to JW Wang [:jwwang] from comment #2)
> > Can you check if data is evicted from MediaCache so that the http channel is
> > closed and opened again to download the data that was already downloaded
> > before?
> 
> Yes, I will check it later.
> Now I'm going to write a patch in WebMBufferedParser for reducing the
> |SilentReadAt| if the data chunk had already sent into WebMBufferedParser.

It would be much better to find out the *why* those are happening rather than just getting around the problem in the WebMReader

There are several readers using NotifyDataArrived mechanism to find out what is available for playback.

WebMReader is also going away very soon (bug 1148102)

Comment 5

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

For WebMReader will go away soon, I don't think it is worth the effort to find a workaround for it.

Comment 6

[Benjamin Chen [:bechen]]

(In reply to Jean-Yves Avenard [:jya] from comment #4)
> (In reply to Benjamin Chen [:bechen] from comment #3)
> > (In reply to JW Wang [:jwwang] from comment #2)
> > > Can you check if data is evicted from MediaCache so that the http channel is
> > > closed and opened again to download the data that was already downloaded
> > > before?

I enable the MediaCache's NSPR log to see the detail in MediaCache.
The root cause is that: there are 2 seek operations in the funcion |SilentReadAt|.

For example: test_played.html + seek.webm (duration is 4s)
1. The data is dowloaded from offset 0 because we need metadata.
2. After metadataloaded, the testcase trigger a "seek to 2.6s"
3. Since the |SEEK_VS_READ_THRESHOLD| is 32k, the "seek to 2.6s" correspond to offset 131072 => trigger RecreateChannel
4. The |NotifyDataArrivedInternal| on the other thread from step 1 be executed for offset 8192
=> call SilentReadAt => "seek to 0"  => "seek to 131072"
The "seek to 0" and "seek to 131072" also trigger ReCreateChannel and also dispatch another |NotifyDataArrivedInternal| tasks that are redundant for the WebMBufferedParser

Comment 7

[Jean-Yves Avenard [:jya]]

That could be easily fixed in MediaDecoderReader::ThrottledNotifyDataArrived

if the new range isn't contiguous with the previous one, it does:

  } else if (!mThrottledInterval.ref().Contiguous(aInterval)) {
    DoThrottledNotify();
    mThrottledInterval.emplace(aInterval);
  } else {

We simply need to add before, something like
mThrottledInterval.Contains(aInterval) and do nothing then...

That should do the trick.

Comment 8

[Jean-Yves Avenard [:jya]]

Attachment: Don't dispatch NotifyDataArrived if previously dispatched with same range.

Comment 9

[Jean-Yves Avenard [:jya]]

Please try the attached patch... let me know if that does it.

Comment 10

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

I wonder why don't we call MediaResource::GetCachedRanges to determine the buffer range which has no side effect like re-creating http channels?

Comment 11

[Jean-Yves Avenard [:jya]]

it already does...

It's SilentReadAt which appear to not be very silent after all :)

Comment 12

[Jean-Yves Avenard [:jya]]

What SilentReadAt could do instead is attempt to use ReadFromCache first, and only if it couldn't read all the data would it default to MediaResource::Read

Comment 13

[Jean-Yves Avenard [:jya]]

Benjamin, do you mind if I take this bug? 

I'm going to rework MediaReadAt/SilentReadAt so it first attempt to only read from the cache

Comment 14

[Benjamin Chen [:bechen]]

(In reply to Jean-Yves Avenard [:jya] from comment #9)
> Please try the attached patch... let me know if that does it.

I'll try it tomorrow, but I guess the patch doesn't work.

Consider the seek case:
When we press seek generate the task1, but the task2 is dispatched by http channel.

task 1: seek to offset 102400 => ReCreatechannel to offset 102400
task 2: DoThrottledNotify for offset 8192 => ReCreatechannel to offset 8192, ReCreatechannel to offset 102400

comment 12 may be the solution.
Or can we generate a nsRefPtr<MediaByteBuffer> here https://dxr.mozilla.org/mozilla-central/source/dom/media/MediaResource.cpp#466, then send it to reader?

Comment 15

[Benjamin Chen [:bechen]]

Comment on attachment 8634662 [details] [diff] [review]
Don't dispatch NotifyDataArrived if previously dispatched with same range.


>+  } else if (mThrottledInterval.ref().Contains(aInterval)) {
>+    return;

I have tried the patch, it doesn't work.
During the testcase, there is no chance to go into this code block.

Comment 16

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

(In reply to Benjamin Chen [:bechen] from comment #6)
> For example: test_played.html + seek.webm (duration is 4s)
> 1. The data is dowloaded from offset 0 because we need metadata.
> 2. After metadataloaded, the testcase trigger a "seek to 2.6s"
> 3. Since the |SEEK_VS_READ_THRESHOLD| is 32k, the "seek to 2.6s" correspond to offset 131072 => trigger RecreateChannel
> 4. The |NotifyDataArrivedInternal| on the other thread from step 1 be executed for offset 8192 => call SilentReadAt => "seek to 0"  => "seek to 131072"
> The "seek to 0" and "seek to 131072" also trigger ReCreateChannel and also dispatch another |NotifyDataArrivedInternal| tasks that are redundant for the WebMBufferedParser

It makes sense to ReCreateChannel when seeking to offset 131072 since the data is not yet downloaded. However why did it ReCreateChannel when seeking to offset 0? Wasn't the data already downloaded when reading metadata?

Comment 17

[Jean-Yves Avenard [:jya]]

Ben, would you have a particular video that exhibits that behaviour ?

is it just one of the mochitest?

Comment 18

[Jean-Yves Avenard [:jya]]

Attachment: P1. Don't dispatch NotifyDataArrived if previously dispatched with same range.

Comment 19

[Jean-Yves Avenard [:jya]]

Attachment: P2. MediaResource::SilentReadAt to read from cache first.

In practice, it will always read from the cache. This allows SilentReadAt to really be silent and prevent unecessary NotifyDataArrived callbacks.

Comment 20

[Jean-Yves Avenard [:jya]]

 https://treeherder.mozilla.org/#/jobs?repo=try&revision=f34a18879e66

Comment 21

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

Hi Benjamin,
Do you have any idea about comment 16?

Comment 22

[Benjamin Chen [:bechen]]

(In reply to Jean-Yves Avenard [:jya] from comment #17)
> Ben, would you have a particular video that exhibits that behaviour ?
> 
> is it just one of the mochitest?

Just a mochitest.
dom/media/test/test_played.html (I run the "test 6" only) with seek.webm only (In manifest.js |gPlayedTests|)

> (In reply to JW Wang [:jwwang] from comment #16)
> It makes sense to ReCreateChannel when seeking to offset 131072 since the
> data is not yet downloaded. However why did it ReCreateChannel when seeking
> to offset 0? Wasn't the data already downloaded when reading metadata?

I'll check it.

Comment 23

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/a438f0060869
https://hg.mozilla.org/integration/mozilla-inbound/rev/00008b664c22

Comment 24

[Benjamin Chen [:bechen]]

(In reply to JW Wang [:jwwang] from comment #16)
> (In reply to Benjamin Chen [:bechen] from comment #6)
> > For example: test_played.html + seek.webm (duration is 4s)
> > 1. The data is dowloaded from offset 0 because we need metadata.
> > 2. After metadataloaded, the testcase trigger a "seek to 2.6s"
> > 3. Since the |SEEK_VS_READ_THRESHOLD| is 32k, the "seek to 2.6s" correspond to offset 131072 => trigger RecreateChannel
> > 4. The |NotifyDataArrivedInternal| on the other thread from step 1 be executed for offset 8192 => call SilentReadAt => "seek to 0"  => "seek to 131072"
> > The "seek to 0" and "seek to 131072" also trigger ReCreateChannel and also dispatch another |NotifyDataArrivedInternal| tasks that are redundant for the WebMBufferedParser
> 
> It makes sense to ReCreateChannel when seeking to offset 131072 since the
> data is not yet downloaded. However why did it ReCreateChannel when seeking
> to offset 0? Wasn't the data already downloaded when reading metadata?

https://dxr.mozilla.org/mozilla-central/source/dom/media/MediaCache.cpp?from=MediaCache.cpp#1178

Because the |GetCachedDataEndInternal| only check the "seek offset (stream->mStreamOffset)" is at the end of block(mChannelOffset) or not. If the "seek offset" is located at the end of block means that the data will arrive soon or had been store in the end block.
Now the code logic doesn't check the whole cache.

Comment 25

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/a438f0060869
https://hg.mozilla.org/mozilla-central/rev/00008b664c22

Comment 26

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

(In reply to Benjamin Chen [:bechen] from comment #24)
> (In reply to JW Wang [:jwwang] from comment #16)
> > (In reply to Benjamin Chen [:bechen] from comment #6)
> > > For example: test_played.html + seek.webm (duration is 4s)
> > > 1. The data is dowloaded from offset 0 because we need metadata.
> > > 2. After metadataloaded, the testcase trigger a "seek to 2.6s"
> > > 3. Since the |SEEK_VS_READ_THRESHOLD| is 32k, the "seek to 2.6s" correspond to offset 131072 => trigger RecreateChannel
> > > 4. The |NotifyDataArrivedInternal| on the other thread from step 1 be executed for offset 8192 => call SilentReadAt => "seek to 0"  => "seek to 131072"
> > > The "seek to 0" and "seek to 131072" also trigger ReCreateChannel and also dispatch another |NotifyDataArrivedInternal| tasks that are redundant for the WebMBufferedParser
> > 
> > It makes sense to ReCreateChannel when seeking to offset 131072 since the
> > data is not yet downloaded. However why did it ReCreateChannel when seeking
> > to offset 0? Wasn't the data already downloaded when reading metadata?
> 
> https://dxr.mozilla.org/mozilla-central/source/dom/media/MediaCache.
> cpp?from=MediaCache.cpp#1178
> 
> Because the |GetCachedDataEndInternal| only check the "seek offset
> (stream->mStreamOffset)" is at the end of block(mChannelOffset) or not. If
> the "seek offset" is located at the end of block means that the data will
> arrive soon or had been store in the end block.
> Now the code logic doesn't check the whole cache.

I see why. 8192 bytes do not make a full block and a partial block won't go into the cache. That is why bytes downloaded for metadata are discarded when seeking.