1265978 - Add a method to HTMLMediaElement to print debugging information when mochitest times out

Status: RESOLVED FIXED

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

Description

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

We will add |void mozDumpDebugInfo()| to HTMLMediaElement.webidl.

The usage is like:

SimpleTest.registerTimeoutFunction(function() {
  for (var v of document.getElementsByTagName("video")) {
    v.mozDumpDebugInfo();
  }
  for (var a of document.getElementsByTagName("audio")) {
    a.mozDumpDebugInfo();
  }
});

This method will dump object states to PR logs to help debugging.

Comment 1

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

Attachment: 1265978_part1_add_mozDumpDebugInfo.patch

Comment 2

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

Attachment: 1265978_part2_add_DumpDebugInfo.patch

Comment 3

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

Attachment: 1265978_part3_add_test_logs.patch

Comment 4

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8744131 [details] [diff] [review]
1265978_part1_add_mozDumpDebugInfo.patch

We do not want to expose this to the web.  Either condition it on some pref that's set only when running tests or make it chrome-only and call it via SpecialPowers.wrap, or something.

Comment 5

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

Attachment: 1265978_part1_add_mozDumpDebugInfo.patch v2

Hide the function behind pref "media.test.dumpDebugInfo" which will be preffed on only during testing.

Comment 6

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8744148 [details] [diff] [review]
1265978_part1_add_mozDumpDebugInfo.patch v2

r=me

Comment 7

[Jean-Yves Avenard [:jya]]

Comment on attachment 8744132 [details] [diff] [review]
1265978_part2_add_DumpDebugInfo.patch

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

could you also display the content of MediaDecoder::GetMozDebugReaderData

it will be very useful for MSE debugging.

Comment 8

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

Sure. Let me have a try.

Comment 9

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

Attachment: 1265978_part2.5_dump_reader.patch

Comment 10

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

Attachment: 1265978_part3_add_test_logs.patch v2

Comment 11

[Jean-Yves Avenard [:jya]]

Comment on attachment 8744168 [details] [diff] [review]
1265978_part2.5_dump_reader.patch

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

::: dom/media/MediaDecoder.cpp
@@ +1879,5 @@
>  void
>  MediaDecoder::DumpDebugInfo()
>  {
>    DUMP_LOG("metadata: channels=%u rate=%u hasAudio=%d hasVideo=%d, "
>             "state: mPlayState=%s mIsDormant=%d, mShuttingDown=%d",

Do you need an end \n here? (I don't know how that function works)

Comment 12

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

Comment on attachment 8744168 [details] [diff] [review]
1265978_part2.5_dump_reader.patch

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

::: dom/media/MediaDecoder.cpp
@@ +1879,5 @@
>  void
>  MediaDecoder::DumpDebugInfo()
>  {
>    DUMP_LOG("metadata: channels=%u rate=%u hasAudio=%d hasVideo=%d, "
>             "state: mPlayState=%s mIsDormant=%d, mShuttingDown=%d",

DUMP_LOG calls NS_DebugBreak(NS_DEBUG_WARNING, ...) which appends '\n' at the end.
https://dxr.mozilla.org/mozilla-central/source/xpcom/base/nsDebugImpl.cpp#370

@@ +1885,5 @@
>             PlayStateStr(), mIsDormant, mShuttingDown);
> +
> +  nsString str;
> +  GetMozDebugReaderData(str);
> +  DUMP_LOG("reader data:\n%s", NS_ConvertUTF16toUTF8(str).get());

The string returned by GetMozDebugReaderData() already contains new lines. We insert a '\n' in the middle for pretty print.

With '\n' in the middle:
[Child 31890] WARNING: Decoder=7f627479f800 reader data:
audio decoder: ffmpeg audio decoder
audio frames decoded: 35
video decoder: ffmpeg video decoder
hardware video decoding: disabled
video frames decoded: 71 (skipped:0)
Dumping data for demuxer 7f627479fc00:
        Dumping Audio Track Buffer(audio/mp4a-latm): - mLastAudioTime: 1.625396
                NumSamples:53 Size:13628 NextGetSampleIndex:4294967295 NextInsertionIndex:53
                Buffered: ranges=[(0.000000, 1.625396), (3.204353, 4.040272)]
        Dumping Video Track Buffer(video/avc) - mLastVideoTime: 1.696666
                NumSamples:72 Size:79426 NextGetSampleIndex:48 NextInsertionIndex:72
                Buffered: ranges=[(0.095000, 1.696666), (3.298333, 4.100000)]

Without:
[Child 31890] WARNING: Decoder=7f627479f800 reader data:audio decoder: ffmpeg audio decoder
audio frames decoded: 35
video decoder: ffmpeg video decoder
hardware video decoding: disabled
video frames decoded: 71 (skipped:0)
Dumping data for demuxer 7f627479fc00:
        Dumping Audio Track Buffer(audio/mp4a-latm): - mLastAudioTime: 1.625396
                NumSamples:53 Size:13628 NextGetSampleIndex:4294967295 NextInsertionIndex:53
                Buffered: ranges=[(0.000000, 1.625396), (3.204353, 4.040272)]
        Dumping Video Track Buffer(video/avc) - mLastVideoTime: 1.696666
                NumSamples:72 Size:79426 NextGetSampleIndex:48 NextInsertionIndex:72
                Buffered: ranges=[(0.095000, 1.696666), (3.298333, 4.100000)]

Comment 13

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/b709b8c79756
https://hg.mozilla.org/integration/mozilla-inbound/rev/8dc7d569b770
https://hg.mozilla.org/integration/mozilla-inbound/rev/26fbf6f91bf9
https://hg.mozilla.org/integration/mozilla-inbound/rev/ad66fdaa938a

Comment 14

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/b709b8c79756
https://hg.mozilla.org/mozilla-central/rev/8dc7d569b770
https://hg.mozilla.org/mozilla-central/rev/26fbf6f91bf9
https://hg.mozilla.org/mozilla-central/rev/ad66fdaa938a