1673007 - Add more profile markers to help diagnose WMF Initialization failures

Status: RESOLVED FIXED

(Core :: Audio/Video: Playback, enhancement, P2)

Description

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Continue on the work from bug 1671477 and add more markers to help assess if we'll use hardware decoding, and if not, is it due to failures related to crash guards. This is targeted towards debugging out VPx decoding and trying to get more information around bugs like

• Bug 1570046
• Bug 1530083
• Bug 1638405
• Bug 1634991

Comment 1

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Attachment: Bug 1673007 - Add markers and logs for when we Init the WMFDecoderModule. r?alwu

We aggressively log and mark here to help diagnose hard to nail down problems
with hardware decoding.

Comment 2

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Attachment: Bug 1673007 - Add profiler markers for events that may lead to decoder recreation. r?alwu

This patch adds profiler markers to surface when

• The MediaFormatReader detects a change in stream id.
• The MediaChangeMonitor classes for h264 and/or vpx detect a stream change.

These scenarios typically take place before a decoder is recreated.

Because recreating a decoder is a non-trivial process that can fail and/or
result in performance issues, having these markers helps us relate such issues
to decoder recreation in profiles.

Depends on D94619

Comment 3

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Attachment: Bug 1673007 - Undef WMFAudioMFTManager's LOG macro at end of file. r?alwu

This stops the log leaking into other files during the unified build this is
desirable to avoid

• Other files relying on this log macro and then breaking when unified build
  boundaries shift.
• Other files getting this LOG definition unexpectedly and logging incorrectly
  and/or emitting warnings due to macro redefinitions.

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/31531b427014
Undef WMFAudioMFTManager's LOG macro at end of file. r=alwu
https://hg.mozilla.org/integration/autoland/rev/3e4e0172f644
Add markers and logs for when we Init the WMFDecoderModule. r=alwu
https://hg.mozilla.org/integration/autoland/rev/707208ad26de
Add profiler markers for events that may lead to decoder recreation. r=alwu

Comment 5

[Narcis Beleuzu [:NarcisB]]

Backed out for MinGW bustages on WMFDecoderModule.cpp

Backout link: https://hg.mozilla.org/integration/autoland/rev/962c35586bb504030b1d1cf5056752548bdbfb32
Log link: https://treeherder.mozilla.org/logviewer?job_id=320487906&repo=autoland&lineNumber=57587

Comment 6

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Acking backout. Not sure why the macro fails on MinGW -- there's some special handling in the macro for MinGW that I'll take a deeper look at. Holding NI while I finish out some other work then will return to this.

Comment 7

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Revisited this, think it should be good to land shortly. Clearing the NI. For posterity, the issue is I'd got the indices wrong on the printf attribute macro (good old off by one error).

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/bd4214a2141c
Undef WMFAudioMFTManager's LOG macro at end of file. r=alwu
https://hg.mozilla.org/integration/autoland/rev/401f8f230fcb
Add markers and logs for when we Init the WMFDecoderModule. r=alwu
https://hg.mozilla.org/integration/autoland/rev/4400a4cd77b7
Add profiler markers for events that may lead to decoder recreation. r=alwu

Comment 9

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/bd4214a2141c
https://hg.mozilla.org/mozilla-central/rev/401f8f230fcb
https://hg.mozilla.org/mozilla-central/rev/4400a4cd77b7

Comment 10

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Thank you for using the profiler. 😀

FYI: In bug 1675409, which should land next week after the un-freeze, I'm migrating to the new markers API, so I'll be modifying these files again. In particular, I'm removing some of the file-local macros to directly use the new PROFILER_MARKER_TEXT macro, I believe the extra macro layer is not really needed in most cases. Sneak peek.

Also, after that and bug 1666566, it will be much easier to create new marker types (example, documentation still being written), so instead of doing an expensive printf into a generic Text marker, you'll be able to more efficiently record JSON-friendly strings and numbers, and display them in a nice way on profiler.firefox.com...

Please contact me if you'd like to discuss any of this.

Comment 11

[Jean-Yves Avenard [:jya]]

FWIW, none of the errors mentioned in the description can happen following bug 1674043 ; those errors occurred because we kept loading the WMF framework in the content process.

This no longer occurs, we load it once in the parent process and in the RDD. that's it.

Also, all the errors above are errors related to failure to load the WMF framework, which occurs in the WMFDecoderModule; not in the actual WMFVideoMFTManager.

So I don't think those markers will give us any new informations.

Comment 12

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

(In reply to Gerald Squelart [:gerald] (he/him) from comment #10)

Thank you for using the profiler. 😀

FYI: In bug 1675409, which should land next week after the un-freeze, I'm migrating to the new markers API, so I'll be modifying these files again. In particular, I'm removing some of the file-local macros to directly use the new PROFILER_MARKER_TEXT macro, I believe the extra macro layer is not really needed in most cases. Sneak peek.

Also, after that and bug 1666566, it will be much easier to create new marker types (example, documentation still being written), so instead of doing an expensive printf into a generic Text marker, you'll be able to more efficiently record JSON-friendly strings and numbers, and display them in a nice way on profiler.firefox.com...

Please contact me if you'd like to discuss any of this.

Excellent, thanks for the heads up!

(In reply to Jean-Yves Avenard [:jya] from comment #11)

FWIW, none of the errors mentioned in the description can happen following bug 1674043 ; those errors occurred because we kept loading the WMF framework in the content process.

This no longer occurs, we load it once in the parent process and in the RDD. that's it.

Also, all the errors above are errors related to failure to load the WMF framework, which occurs in the WMFDecoderModule; not in the actual WMFVideoMFTManager.

So I don't think those markers will give us any new informations.

Most of the linked bugs have pretty sparse information on what's going on. I hope they're all resolved, but figure it can't hurt to have more markers in case we continue to see issues. This does add some markers to the WMFDecoderModule, though my expectation is in crash cases we won't see these in profile runs as they won't get sent back to the parent process due to the crash, so part of reading profile tea leaves in these cases will be looking for missing markers. Ideally we'd have markers for crash guards seeing that a crash happened, but I haven't gotten around to that. These patches should also give us some coverage for expensive events that may not be crashes, like decoder recreation -- we've had some profile runs where this had led to significant frame drops and making these easier to see based on markers would be helpful.