Closed Bug 1166836 Opened 8 years ago Closed 8 years ago

Runaway plugin-container in NS_QuickSort while playing mp4 video


(Core :: Audio/Video, defect)

Not set



Tracking Status
firefox41 --- fixed


(Reporter: bent.mozilla, Assigned: jya)




(6 files, 8 obsolete files)

1.71 KB, text/plain
1.71 KB, text/plain
4.48 KB, patch
Details | Diff | Splinter Review
1.78 KB, patch
Details | Diff | Splinter Review
1.56 KB, patch
Details | Diff | Splinter Review
6.50 KB, patch
Details | Diff | Splinter Review
On today's nightly (win 8.1 x86_64, 64-bit firefox, e10s enabled) I was trying to watch this video:

The plugin-container process chews CPU incessantly and so all other tabs stop responding. I had to kill the process.

Stack attached.
jya: Is this stuff you added recently? Can you take a look?
Flags: needinfo?(jyavenard)
The MediaFormatReader will ask its demuxers to recalculate their buffered ranges when NotifyDataArrived() is called.

While I can optimise the mp4_demuxer to not use quicksort (and instead use the new IntervalSet object). Can also cache the values so that if the resource media range hasn't changed it doesn't recalculate the buffered range.

But there's still the issue on why NotifyDataArrived called so often?
Flags: needinfo?(jyavenard)
Assignee: nobody → jyavenard
Can you reproduce this problem?
(In reply to Ben Turner [:bent] (use the needinfo flag!) from comment #4)
> Can you reproduce this problem?

I have a fairly high CPU usage, but nothing out of the extraordinary. It's also no more when I disable the new MediaFormatReader and go back to using MP4Reader.

You can switch back to the older MP4 reader by setting media.format-reader.mp4 to false. Does it still happen for you?
Flags: needinfo?(bent.mozilla)
I've done some profiling...

When playing this video, during a 1 minute playback, 55.9% (62s CPU time) was spent in GetBuffered(). The main thread alone calculating GetBuffered().
All this time is spent in mp4_demuxer::Index::ConvertByteRangesToTimeRanges.

On the MediaFormatReader::MediaTaskQueue(), the combined time spent 30.8s to process GetBuffered().

The mp4_demuxer::Index keeps an array of samples, which is sorted by decode order.
It adds interatively all those samples (one at a time) to an array, and then sort it using QuickSort to get them in presentation order.

we end up with an array that has 69344 samples. For each sample it tests if it is contained in the mdat range (half the time is spent there).
Finally, QuickSort no matter how quick it is, when having to sort this several times per second ends up being (the other half)

When using MP4Reader, there's no real improvement as far as the main thread is concerned (and this is expected as Getbuffered() is mostly done while in the main thread). There's however something to take into account, as the demuxer is shared across all threads, the main thread may be locking while the reader task queue is calculating GetBuffered(). The overall CPU time is 60.2s. So less than MediaFormatReader but the mainthread would be waiting for GetBuffered for longer.

We only need to call GetBuffered() on the reader's taskqueue when using MediaSource, so we can optimise greatly the need for the second demuxer in calculating the time ranges.

The problem reported isn't being made worse by having the MediaFormatReader being the default reader. Yes, more CPU time is spent in total, but this is more spread across threads.

Ben, could you please confirm that when setting media.format-reader.mp4 to false, you're still experiencing the problem, and let me know if it's the same, much better or worse (theory is great, but actual usage is always better)

I have some ideas on how we could optimise GetBuffered() for MP4, I will run them by Anthony.
Interestingly, once download as completed (and as such we don't call GetBuffered() anymore), 15% of CPU time is spent in ReentrantMonitorAutoEnter::Wait. 8s worth...

worth looking into it IMHO.
Cache the buffered range for the main thread. It doesn't account for much savings, but the Chrome UI does call GetBuffered() from time to time which causes an unecessary recalculation.
Attachment #8608659 - Flags: review?(cpearce)
Only rescan the moof when we're about to calculate the buffered range.
Attachment #8608660 - Flags: review?(cpearce)
Profiler showed that this is the most common use of IntervalSet. Remove the need for looping in the array.
Attachment #8608662 - Flags: review?(matt.woodrow)
Comment on attachment 8608662 [details] [diff] [review]
Part3. Optimise most common addition to IntervalSet

got an idea, will merge that with it
Attachment #8608662 - Attachment is obsolete: true
Attachment #8608662 - Flags: review?(matt.woodrow)
Doh! regression introduced in bug 1163445. We are only supposed to calculate the buffered range for stream where the duration is unknown.
Attachment #8608728 - Flags: review?(cpearce)
Setting media.format-reader.mp4=false I still see the problem. The stack looks the same but with MP4Reader::GetBuffered instead of MediaFormatReader::GetBuffered, I think. Same hangup.
Flags: needinfo?(bent.mozilla)
Attachment #8608659 - Flags: review?(cpearce) → review+
Comment on attachment 8608660 [details] [diff] [review]
Part2. Cache and update our buffered range as much as possible

Review of attachment 8608660 [details] [diff] [review]:

::: dom/media/fmp4/MP4Demuxer.cpp
@@ +342,5 @@
>      ranges +=
>        media::TimeInterval(media::TimeUnit::FromMicroseconds(timeRanges[i].start),
>                            media::TimeUnit::FromMicroseconds(timeRanges[i].end));
>    }
> +  return buffered;

return ranges.
Attachment #8608660 - Flags: review?(cpearce) → review+
Attachment #8608728 - Flags: review?(cpearce) → review+
Never have the MDSM calls GetBuffered() on the main thread, as the time range is cached by the MediaFormatReader it's only calculated a few time. We had to make sure the buffered range time is updated immediately so that the next task running on the reader's queue gets the last value. With this we drop the CPU runtime (still during 1 minute playback) from 65s to 16s. Most of that time (6.6s) is spent in VsyncRefreshDriver. This could be more elegantly done with the state mirror mechanism
Attachment #8609098 - Flags: review?(cpearce)
Attachment #8609098 - Flags: review?(cpearce) → review+
Attachment #8608659 - Attachment is obsolete: true
Attachment #8608660 - Attachment is obsolete: true
Attachment #8608728 - Attachment is obsolete: true
Attachment #8609098 - Attachment is obsolete: true
Minor rewrite. NotifiedDataArriverd is called every 65kB downloaded. This causes up to 6000 tasks being queued on my machine before any of other tasks have a chance to run. That causes 6000 calls to GetBuffered() consecutively. Using ScheduleUpdate() allows us to slightly buffer those as it runs only one Update() par run. To ensure we have up to date buffered range in GetBuffered(), we force the update there if necessary
Attachment #8609231 - Attachment is obsolete: true
The patches depends on bug 1163227.

I will commit part4 now as it's the core reason of the high-cpu usage and will push the rest with 1163227
Depends on: 1163227
Keywords: leave-open
MDSM::NotifyDataArrived isn't always called, so we must set mCachedTimeRangesStale initially to true so the next call to GetBuffered() will force a refresh. I've merged the refresh of cached time range from part5.
Attachment #8609226 - Attachment is obsolete: true
Comment on attachment 8609233 [details] [diff] [review]
Part5. Don't call GetBuffered() on the main thread

This causes intermittent failure with some format that do not set the duration in the loadedmetadata phase and relies on the first MDSM::NotifyDataArrived to set the duration.

I believe the mochitests test the wrong behaviour but that's for a later.

At least with MediaFormatReader the buffered range is cache, so it won't cause high CPU usage even on the main thread.
Attachment #8609233 - Attachment is obsolete: true

super consistent on all version of mac and windows, still old intermittent with bug 1138555 on linux
Closed: 8 years ago
Keywords: leave-open
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.