Closed Bug 1387679 Opened 7 years ago Closed 3 years ago

Intermittent dom/media/test/test_eme_pssh_in_moof.html | Test timed out.

Categories

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

x86_64
Unspecified
defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
(In reply to Sebastian Hengst [:aryx][:archaeopteryx] (needinfo on intermittent or backout) from comment #4) > https://treeherder.mozilla.org/logviewer.html#?job_id=137684247&repo=autoland Windows 10 timeout.
Depends on: 1407553
OS: Unspecified → Windows 10
Hardware: Unspecified → x86_64
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

This failure has been observed on experimental Debian 10 test image:

[task 2019-08-22T18:28:44.562Z] 18:28:44     INFO - TEST-START | dom/media/test/test_eme_pssh_in_moof.html
[task 2019-08-22T18:28:44.875Z] 18:28:44     INFO - GECKO(4698) | [Child 4753, MediaDecoderStateMachine #1] WARNING: Decoder=7f9ed40ea400 Decode error: NS_ERROR_DOM_MEDIA_DECODE_ERR (0x806e0004) - virtual mozilla::MediaResult mozilla::FFmpegAudioDecoder<58>::DoDecode(mozilla::MediaRawData *, uint8_t *, int, bool *, mozilla::MediaDataDecoder::DecodedData &): FFmpeg audio error:-1094995529: file /builds/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 3305
[task 2019-08-22T18:31:44.619Z] 18:31:44     INFO - TEST-INFO | started process screentopng
[task 2019-08-22T18:31:44.817Z] 18:31:44     INFO - TEST-INFO | screentopng: exit 0
[task 2019-08-22T18:31:44.819Z] 18:31:44     INFO - Buffered messages logged at 18:28:44
[task 2019-08-22T18:31:44.819Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | A valid string reason is expected 
[task 2019-08-22T18:31:44.819Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | Reason cannot be empty 
[task 2019-08-22T18:31:44.819Z] 18:31:44     INFO - Started Thu Aug 22 2019 18:28:44 GMT+0000 (Coordinated Universal Time) (1566498524.608s)
[task 2019-08-22T18:31:44.819Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bear-640x360-cenc-key-rotation-0 t=0.003] Length of array should match number of running tests 
[task 2019-08-22T18:31:44.820Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bipbop-clearkey-keyrotation-clear-lead-1 t=0.014] Length of array should match number of running tests 
[task 2019-08-22T18:31:44.820Z] 18:31:44     INFO - [18:28:44.668] bear-640x360-cenc-key-rotation-0 sourceopen
[task 2019-08-22T18:31:44.821Z] 18:31:44     INFO - [18:28:44.668] bear-640x360-cenc-key-rotation-0 video: addSourceBuffer(video/mp4; codecs="avc1.64000d")
[task 2019-08-22T18:31:44.821Z] 18:31:44     INFO - [18:28:44.669] bear-640x360-cenc-key-rotation-0 video: addNextFragment() fetching next fragment bear-640x360-v_frag-cenc-key_rotation.mp4
[task 2019-08-22T18:31:44.823Z] 18:31:44     INFO - [18:28:44.670] bear-640x360-cenc-key-rotation-0 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.670] bear-640x360-cenc-key-rotation-0 audio: addNextFragment() fetching next fragment bear-640x360-a_frag-cenc-key_rotation.mp4
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.676] bipbop-clearkey-keyrotation-clear-lead-1 sourceopen
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.676] bipbop-clearkey-keyrotation-clear-lead-1 video: addSourceBuffer(video/mp4; codecs="avc1.4d4015")
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.676] bipbop-clearkey-keyrotation-clear-lead-1 video: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-video.mp4
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.678] bipbop-clearkey-keyrotation-clear-lead-1 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.678] bipbop-clearkey-keyrotation-clear-lead-1 audio: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-audio.mp4
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.782] bipbop-clearkey-keyrotation-clear-lead-1 audio: fetch of bipbop-clearkey-keyrotation-clear-lead-audio.mp4 complete, appending
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.785] bipbop-clearkey-keyrotation-clear-lead-1 audio: updateend for bipbop-clearkey-keyrotation-clear-lead-audio.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-10.03102, audioTracks=-, videoTracks=-}
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.785] bipbop-clearkey-keyrotation-clear-lead-1 audio: end of track
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.806] bear-640x360-cenc-key-rotation-0 audio: fetch of bear-640x360-a_frag-cenc-key_rotation.mp4 complete, appending
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.809] bear-640x360-cenc-key-rotation-0 audio: updateend for bear-640x360-a_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-2.80399, audioTracks=-, videoTracks=-}
[task 2019-08-22T18:31:44.824Z] 18:31:44     INFO - [18:28:44.809] bear-640x360-cenc-key-rotation-0 audio: end of track
[task 2019-08-22T18:31:44.828Z] 18:31:44     INFO - [18:28:44.850] bear-640x360-cenc-key-rotation-0 video: fetch of bear-640x360-v_frag-cenc-key_rotation.mp4 complete, appending
[task 2019-08-22T18:31:44.828Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2019-08-22T18:31:44.836Z] 18:31:44     INFO - [18:28:44.855] bear-640x360-cenc-key-rotation-0 encrypted event => len=850 000000347073736800000000fde979fd4aa3fd27fdfd1d21fd000000140801121030313233343536373839303132333435000002fd7073736800000000fd04fd79fd4042fdfdfdfd5bfdfd5ffd000002fdfd02000001000100fd023c00570052004d00480045004100440045005200200078006d006c006e0073003d00220068007400740070003a002f002f0073006300680065006d00610073002e006d006900630072006f0073006f00660074002e0063006f006d002f00440052004d002f0032003000300037002f00300033002f0050006c00610079005200650061006400790048006500610064006500720022002000760065007200730069006f006e003d00220034002e0030002e0030002e00300022003e003c0044004100540041003e003c00500052004f00540045004300540049004e0046004f003e003c004b00450059004c0045004e003e00310036003c002f004b00450059004c0045004e003e003c0041004c004700490044003e004100450053004300540052003c002f0041004c004700490044003e003c002f00500052004f00540045004300540049004e0046004f003e003c004b00490044003e004d007a00490078004d004400550030004e007a00590034004f005400410078004d006a004d0030004e0051003d003d003c002f004b00490044003e003c0043004800450043004b00530055004d003e0044004d0039004c00590079006d003000470049006f003d003c002f0043004800450043004b00530055004d003e003c004c0041005f00550052004c003e00680074007400700073003a002f002f007700770077002e0079006f00750074007500620065002e0063006f006d002f006100700069002f00640072006d002f0070006c0061007900720065006100640079003f0073006f0075007200630065003d0059004f0055005400550042004500260061006d0070003b0076006900640065006f005f00690064003d00540065007300740056006900640065006f00490064003c002f004c0041005f00550052004c003e003c002f0044004100540041003e003c002f00570052004d004800450041004400450052003e000000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000013031323334353637383930313233343500000000
[task 2019-08-22T18:31:44.836Z] 18:31:44     INFO - [18:28:44.862] bear-640x360-cenc-key-rotation-0 video: updateend for bear-640x360-v_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.033-2.769066, audioTracks=-, videoTracks=-}
[task 2019-08-22T18:31:44.837Z] 18:31:44     INFO - [18:28:44.862] bear-640x360-cenc-key-rotation-0 video: end of track
[task 2019-08-22T18:31:44.837Z] 18:31:44     INFO - [18:28:44.862] bear-640x360-cenc-key-rotation-0 Tracks loaded, calling MediaSource.endOfStream()
[task 2019-08-22T18:31:44.838Z] 18:31:44     INFO - [18:28:44.874] bipbop-clearkey-keyrotation-clear-lead-1 video: fetch of bipbop-clearkey-keyrotation-clear-lead-video.mp4 complete, appending
[task 2019-08-22T18:31:44.838Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2019-08-22T18:31:44.839Z] 18:31:44     INFO - [18:28:44.879] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000010011223344556677fdfdfdfdfdfdfdfd00000000
[task 2019-08-22T18:31:44.839Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2019-08-22T18:31:44.839Z] 18:31:44     INFO - [18:28:44.879] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b0000000111223344556677fdfdfdfdfdfdfdfd0000000000
[task 2019-08-22T18:31:44.839Z] 18:31:44     INFO - [18:28:44.880] bipbop-clearkey-keyrotation-clear-lead-1 video: updateend for bipbop-clearkey-keyrotation-clear-lead-video.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.095-9.971677, audioTracks=-, videoTracks=-}
[task 2019-08-22T18:31:44.840Z] 18:31:44     INFO - [18:28:44.880] bipbop-clearkey-keyrotation-clear-lead-1 video: end of track
[task 2019-08-22T18:31:44.840Z] 18:31:44     INFO - [18:28:44.880] bipbop-clearkey-keyrotation-clear-lead-1 Tracks loaded, calling MediaSource.endOfStream()
[task 2019-08-22T18:31:44.841Z] 18:31:44     INFO - Buffered messages logged at 18:28:55
[task 2019-08-22T18:31:44.842Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | Should get one 'encrypted' event per run of contiguous PSSH boxes in media. 
[task 2019-08-22T18:31:44.842Z] 18:31:44     INFO - [finished bipbop-clearkey-keyrotation-clear-lead-1] remaining= bear-640x360-cenc-key-rotation-0
[task 2019-08-22T18:31:44.842Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bipbop-clearkey-keyrotation-clear-lead-1 t=11.138] Length of array should match number of running tests 
[task 2019-08-22T18:31:44.843Z] 18:31:44     INFO - Buffered messages finished
[task 2019-08-22T18:31:44.846Z] 18:31:44     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_pssh_in_moof.html | Test timed out! 
[task 2019-08-22T18:31:44.846Z] 18:31:44     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:277:18
[task 2019-08-22T18:31:44.846Z] 18:31:44     INFO - onTimeout@https://example.com/tests/dom/media/test/manifest.js:1760:9
[task 2019-08-22T18:31:44.847Z] 18:31:44     INFO - setTimeout handler*MediaTestManager/this.started@https://example.com/tests/dom/media/test/manifest.js:1767:57
[task 2019-08-22T18:31:44.847Z] 18:31:44     INFO - startTest@https://example.com/tests/dom/media/test/test_eme_pssh_in_moof.html:84:15
[task 2019-08-22T18:31:44.848Z] 18:31:44     INFO - MediaTestManager/this.nextTest@https://example.com/tests/dom/media/test/manifest.js:1816:12
[task 2019-08-22T18:31:44.848Z] 18:31:44     INFO - MediaTestManager/this.runTests/<@https://example.com/tests/dom/media/test/manifest.js:1736:12
[task 2019-08-22T18:31:44.849Z] 18:31:44     INFO - Async*MediaTestManager/this.runTests@https://example.com/tests/dom/media/test/manifest.js:1735:19
[task 2019-08-22T18:31:44.850Z] 18:31:44     INFO - @https://example.com/tests/dom/media/test/test_eme_pssh_in_moof.html:137:13
[task 2019-08-22T18:31:44.850Z] 18:31:44     INFO - bear-640x360-cenc-key-rotation-0 timed out!
[task 2019-08-22T18:31:44.850Z] 18:31:44     INFO - [finished bear-640x360-cenc-key-rotation-0] remaining= 
[task 2019-08-22T18:31:44.852Z] 18:31:44     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bear-640x360-cenc-key-rotation-0 t=180.005] Length of array should match number of running tests 
[task 2019-08-22T18:31:44.852Z] 18:31:44     INFO - Finished at Thu Aug 22 2019 18:31:44 GMT+0000 (Coordinated Universal Time) (1566498704.675s)
[task 2019-08-22T18:31:44.852Z] 18:31:44     INFO - Running time: 180.068s
[task 2019-08-22T18:31:44.853Z] 18:31:44     INFO - GECKO(4698) | MEMORY STAT | vsize 2546MB | residentFast 181MB | heapAllocated 20MB
[task 2019-08-22T18:31:44.853Z] 18:31:44     INFO - TEST-OK | dom/media/test/test_eme_pssh_in_moof.html | took 180127ms

It may need to be skipped for Debian 10 platform.

Blocks: 1572247
No longer depends on: 1572247

:bvandyk - this is a failure that I've been able to consistently observe on the experimental Debian 10 test image, which I am working on as a migration path from the current Ubuntu 16.04 image.

Try: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&revision=13513111a9183259074f1cfeaf773f37146be166&selectedJob=271937777
Log: https://taskcluster-artifacts.net/NDSvqcXrR9WLy11EN2eqqQ/0/public/logs/live_backing.log

Excerpt:

[task 2019-10-18T17:37:48.781Z] 17:37:48     INFO - TEST-START | dom/media/test/test_eme_pssh_in_moof.html
[task 2019-10-18T17:37:49.101Z] 17:37:49     INFO - GECKO(5080) | [Child 5134, MediaDecoderStateMachine #1] WARNING: Decoder=7f6ee789e400 Decode error: NS_ERROR_DOM_MEDIA_DECODE_ERR (0x806e0004) - virtual mozilla::MediaResult mozilla::FFmpegAudioDecoder<58>::DoDecode(mozilla::MediaRawData *, uint8_t *, int, bool *, mozilla::MediaDataDecoder::DecodedData &): FFmpeg audio error:-1094995529: file /builds/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 3308
[task 2019-10-18T17:40:48.843Z] 17:40:48     INFO - TEST-INFO | started process screentopng
[task 2019-10-18T17:40:49.014Z] 17:40:49     INFO - TEST-INFO | screentopng: exit 0
[task 2019-10-18T17:40:49.014Z] 17:40:49     INFO - Buffered messages logged at 17:37:48
[task 2019-10-18T17:40:49.014Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | A valid string reason is expected 
[task 2019-10-18T17:40:49.014Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | Reason cannot be empty 
[task 2019-10-18T17:40:49.014Z] 17:40:49     INFO - Started Fri Oct 18 2019 17:37:48 GMT+0000 (Coordinated Universal Time) (1571420268.828s)
[task 2019-10-18T17:40:49.015Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bear-640x360-cenc-key-rotation-0 t=0.005] Length of array should match number of running tests 
[task 2019-10-18T17:40:49.015Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bipbop-clearkey-keyrotation-clear-lead-1 t=0.013] Length of array should match number of running tests 
[task 2019-10-18T17:40:49.016Z] 17:40:49     INFO - [17:37:48.886] bear-640x360-cenc-key-rotation-0 sourceopen
[task 2019-10-18T17:40:49.016Z] 17:40:49     INFO - [17:37:48.887] bear-640x360-cenc-key-rotation-0 video: addSourceBuffer(video/mp4; codecs="avc1.64000d")
[task 2019-10-18T17:40:49.017Z] 17:40:49     INFO - [17:37:48.888] bear-640x360-cenc-key-rotation-0 video: addNextFragment() fetching next fragment bear-640x360-v_frag-cenc-key_rotation.mp4
[task 2019-10-18T17:40:49.018Z] 17:40:49     INFO - [17:37:48.889] bear-640x360-cenc-key-rotation-0 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2019-10-18T17:40:49.018Z] 17:40:49     INFO - [17:37:48.889] bear-640x360-cenc-key-rotation-0 audio: addNextFragment() fetching next fragment bear-640x360-a_frag-cenc-key_rotation.mp4
[task 2019-10-18T17:40:49.019Z] 17:40:49     INFO - [17:37:48.889] bipbop-clearkey-keyrotation-clear-lead-1 sourceopen
[task 2019-10-18T17:40:49.020Z] 17:40:49     INFO - [17:37:48.889] bipbop-clearkey-keyrotation-clear-lead-1 video: addSourceBuffer(video/mp4; codecs="avc1.4d4015")
[task 2019-10-18T17:40:49.020Z] 17:40:49     INFO - [17:37:48.890] bipbop-clearkey-keyrotation-clear-lead-1 video: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-video.mp4
[task 2019-10-18T17:40:49.021Z] 17:40:49     INFO - [17:37:48.890] bipbop-clearkey-keyrotation-clear-lead-1 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2019-10-18T17:40:49.022Z] 17:40:49     INFO - [17:37:48.890] bipbop-clearkey-keyrotation-clear-lead-1 audio: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-audio.mp4
[task 2019-10-18T17:40:49.023Z] 17:40:49     INFO - Buffered messages logged at 17:37:49
[task 2019-10-18T17:40:49.024Z] 17:40:49     INFO - [17:37:49.8]   bipbop-clearkey-keyrotation-clear-lead-1 audio: fetch of bipbop-clearkey-keyrotation-clear-lead-audio.mp4 complete, appending
[task 2019-10-18T17:40:49.026Z] 17:40:49     INFO - [17:37:49.10]  bipbop-clearkey-keyrotation-clear-lead-1 audio: updateend for bipbop-clearkey-keyrotation-clear-lead-audio.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-10.03102, audioTracks=-, videoTracks=-}
[task 2019-10-18T17:40:49.026Z] 17:40:49     INFO - [17:37:49.10]  bipbop-clearkey-keyrotation-clear-lead-1 audio: end of track
[task 2019-10-18T17:40:49.027Z] 17:40:49     INFO - [17:37:49.28]  bear-640x360-cenc-key-rotation-0 audio: fetch of bear-640x360-a_frag-cenc-key_rotation.mp4 complete, appending
[task 2019-10-18T17:40:49.027Z] 17:40:49     INFO - [17:37:49.30]  bear-640x360-cenc-key-rotation-0 audio: updateend for bear-640x360-a_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-2.80399, audioTracks=-, videoTracks=-}
[task 2019-10-18T17:40:49.028Z] 17:40:49     INFO - [17:37:49.30]  bear-640x360-cenc-key-rotation-0 audio: end of track
[task 2019-10-18T17:40:49.028Z] 17:40:49     INFO - [17:37:49.80]  bear-640x360-cenc-key-rotation-0 video: fetch of bear-640x360-v_frag-cenc-key_rotation.mp4 complete, appending
[task 2019-10-18T17:40:49.030Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2019-10-18T17:40:49.031Z] 17:40:49     INFO - [17:37:49.84]  bear-640x360-cenc-key-rotation-0 encrypted event => len=850 000000347073736800000000fde979fd4aa3fd27fdfd1d21fd000000140801121030313233343536373839303132333435000002fd7073736800000000fd04fd79fd4042fdfdfdfd5bfdfd5ffd000002fdfd02000001000100fd023c00570052004d00480045004100440045005200200078006d006c006e0073003d00220068007400740070003a002f002f0073006300680065006d00610073002e006d006900630072006f0073006f00660074002e0063006f006d002f00440052004d002f0032003000300037002f00300033002f0050006c00610079005200650061006400790048006500610064006500720022002000760065007200730069006f006e003d00220034002e0030002e0030002e00300022003e003c0044004100540041003e003c00500052004f00540045004300540049004e0046004f003e003c004b00450059004c0045004e003e00310036003c002f004b00450059004c0045004e003e003c0041004c004700490044003e004100450053004300540052003c002f0041004c004700490044003e003c002f00500052004f00540045004300540049004e0046004f003e003c004b00490044003e004d007a00490078004d004400550030004e007a00590034004f005400410078004d006a004d0030004e0051003d003d003c002f004b00490044003e003c0043004800450043004b00530055004d003e0044004d0039004c00590079006d003000470049006f003d003c002f0043004800450043004b00530055004d003e003c004c0041005f00550052004c003e00680074007400700073003a002f002f007700770077002e0079006f00750074007500620065002e0063006f006d002f006100700069002f00640072006d002f0070006c0061007900720065006100640079003f0073006f0075007200630065003d0059004f0055005400550042004500260061006d0070003b0076006900640065006f005f00690064003d00540065007300740056006900640065006f00490064003c002f004c0041005f00550052004c003e003c002f0044004100540041003e003c002f00570052004d004800450041004400450052003e000000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000013031323334353637383930313233343500000000
[task 2019-10-18T17:40:49.032Z] 17:40:49     INFO - [17:37:49.90]  bear-640x360-cenc-key-rotation-0 video: updateend for bear-640x360-v_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.033-2.769066, audioTracks=-, videoTracks=-}
[task 2019-10-18T17:40:49.033Z] 17:40:49     INFO - [17:37:49.90]  bear-640x360-cenc-key-rotation-0 video: end of track
[task 2019-10-18T17:40:49.041Z] 17:40:49     INFO - [17:37:49.90]  bear-640x360-cenc-key-rotation-0 Tracks loaded, calling MediaSource.endOfStream()
[task 2019-10-18T17:40:49.041Z] 17:40:49     INFO - [17:37:49.97]  bipbop-clearkey-keyrotation-clear-lead-1 video: fetch of bipbop-clearkey-keyrotation-clear-lead-video.mp4 complete, appending
[task 2019-10-18T17:40:49.043Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2019-10-18T17:40:49.044Z] 17:40:49     INFO - [17:37:49.106] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000010011223344556677fdfdfdfdfdfdfdfd00000000
[task 2019-10-18T17:40:49.046Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2019-10-18T17:40:49.047Z] 17:40:49     INFO - [17:37:49.108] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b0000000111223344556677fdfdfdfdfdfdfdfd0000000000
[task 2019-10-18T17:40:49.048Z] 17:40:49     INFO - [17:37:49.109] bipbop-clearkey-keyrotation-clear-lead-1 video: updateend for bipbop-clearkey-keyrotation-clear-lead-video.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.095-9.971677, audioTracks=-, videoTracks=-}
[task 2019-10-18T17:40:49.049Z] 17:40:49     INFO - [17:37:49.109] bipbop-clearkey-keyrotation-clear-lead-1 video: end of track
[task 2019-10-18T17:40:49.049Z] 17:40:49     INFO - [17:37:49.110] bipbop-clearkey-keyrotation-clear-lead-1 Tracks loaded, calling MediaSource.endOfStream()
[task 2019-10-18T17:40:49.050Z] 17:40:49     INFO - Buffered messages logged at 17:37:59
[task 2019-10-18T17:40:49.051Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | Should get one 'encrypted' event per run of contiguous PSSH boxes in media. 
[task 2019-10-18T17:40:49.055Z] 17:40:49     INFO - [finished bipbop-clearkey-keyrotation-clear-lead-1] remaining= bear-640x360-cenc-key-rotation-0
[task 2019-10-18T17:40:49.056Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bipbop-clearkey-keyrotation-clear-lead-1 t=11.123] Length of array should match number of running tests 
[task 2019-10-18T17:40:49.056Z] 17:40:49     INFO - Buffered messages finished
[task 2019-10-18T17:40:49.057Z] 17:40:49     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_pssh_in_moof.html | Test timed out! 
[task 2019-10-18T17:40:49.057Z] 17:40:49     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:277:18
[task 2019-10-18T17:40:49.057Z] 17:40:49     INFO - onTimeout@https://example.com/tests/dom/media/test/manifest.js:1760:9
[task 2019-10-18T17:40:49.058Z] 17:40:49     INFO - setTimeout handler*MediaTestManager/this.started@https://example.com/tests/dom/media/test/manifest.js:1767:57
[task 2019-10-18T17:40:49.058Z] 17:40:49     INFO - startTest@https://example.com/tests/dom/media/test/test_eme_pssh_in_moof.html:84:15
[task 2019-10-18T17:40:49.059Z] 17:40:49     INFO - MediaTestManager/this.nextTest@https://example.com/tests/dom/media/test/manifest.js:1816:12
[task 2019-10-18T17:40:49.059Z] 17:40:49     INFO - MediaTestManager/this.runTests/<@https://example.com/tests/dom/media/test/manifest.js:1736:12
[task 2019-10-18T17:40:49.059Z] 17:40:49     INFO - Async*MediaTestManager/this.runTests@https://example.com/tests/dom/media/test/manifest.js:1735:19
[task 2019-10-18T17:40:49.059Z] 17:40:49     INFO - @https://example.com/tests/dom/media/test/test_eme_pssh_in_moof.html:137:13
[task 2019-10-18T17:40:49.060Z] 17:40:49     INFO - bear-640x360-cenc-key-rotation-0 timed out!
[task 2019-10-18T17:40:49.060Z] 17:40:49     INFO - [finished bear-640x360-cenc-key-rotation-0] remaining= 
[task 2019-10-18T17:40:49.060Z] 17:40:49     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bear-640x360-cenc-key-rotation-0 t=180.007] Length of array should match number of running tests 
[task 2019-10-18T17:40:49.061Z] 17:40:49     INFO - Finished at Fri Oct 18 2019 17:40:48 GMT+0000 (Coordinated Universal Time) (1571420448.893s)
[task 2019-10-18T17:40:49.061Z] 17:40:49     INFO - Running time: 180.066s
[task 2019-10-18T17:40:49.062Z] 17:40:49     INFO - GECKO(5080) | MEMORY STAT | vsize 2546MB | residentFast 176MB | heapAllocated 19MB
[task 2019-10-18T17:40:49.064Z] 17:40:49     INFO - TEST-OK | dom/media/test/test_eme_pssh_in_moof.html | took 180123ms

Failure location:

What are some of the intricacies involved in this test (screen resolution, audio device, video codec, etc)? Perhaps that could help me understand if the failure is with the test or the image.

Flags: needinfo?(bvandyk)
OS: Windows 10 → Unspecified

Edwin and I discussed this a bit elsewhere:

  • It looks like the test is timing out, specifically the first of the two media files (the bear one).
  • It's not yet clear why. There are ffmpeg warnings in the logs, but I would expect other tests to fail if ffmpeg is not decoding audio properly.
  • On the images Edwin is testing the failure repros 100% of the time.
    • My understanding is that because of this another bug to track the permafail may be created, while this bug is left to track the intermittent issue.

My understanding is that we're going to try testing with different ffmpeg versions to see if that makes a difference -- this may be tracked on the other bug. Please NI me on this or the other bug if you would like me to look further at anything.

Flags: needinfo?(bvandyk)

Removing the debian10 blocker due to the issue being resolved with the base image being changed to ubuntu1804.

Status: REOPENED → RESOLVED
Closed: 7 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=314607460&repo=mozilla-beta&lineNumber=4191

[task 2020-09-01T21:08:10.777Z] 21:08:10 INFO - TEST-START | dom/media/test/test_eme_pssh_in_moof.html
[task 2020-09-01T21:08:57.725Z] 21:08:57 INFO - JavaScript error: resource://gre/modules/PlacesExpiration.jsm, line 892: TypeError: this._db is undefined
[task 2020-09-01T21:11:10.860Z] 21:11:10 INFO - TEST-INFO | started process screenshot
[task 2020-09-01T21:11:10.952Z] 21:11:10 INFO - TEST-INFO | screenshot: exit 0
[task 2020-09-01T21:11:10.953Z] 21:11:10 INFO - Buffered messages logged at 21:08:10
[task 2020-09-01T21:11:10.953Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | A valid string reason is expected
[task 2020-09-01T21:11:10.954Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | Reason cannot be empty
[task 2020-09-01T21:11:10.954Z] 21:11:10 INFO - Started Tue Sep 01 2020 21:08:10 GMT+0000 (Greenwich Mean Time) (1598994490.835s)
[task 2020-09-01T21:11:10.954Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bear-640x360-cenc-key-rotation-0 t=0.004] Length of array should match number of running tests
[task 2020-09-01T21:11:10.955Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bipbop-clearkey-keyrotation-clear-lead-1 t=0.013] Length of array should match number of running tests
[task 2020-09-01T21:11:10.955Z] 21:11:10 INFO - [21:08:10.893] bear-640x360-cenc-key-rotation-0 sourceopen
[task 2020-09-01T21:11:10.956Z] 21:11:10 INFO - [21:08:10.894] bear-640x360-cenc-key-rotation-0 video: addSourceBuffer(video/mp4; codecs="avc1.64000d")
[task 2020-09-01T21:11:10.956Z] 21:11:10 INFO - [21:08:10.896] bear-640x360-cenc-key-rotation-0 video: addNextFragment() fetching next fragment bear-640x360-v_frag-cenc-key_rotation.mp4
[task 2020-09-01T21:11:10.958Z] 21:11:10 INFO - [21:08:10.896] bear-640x360-cenc-key-rotation-0 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2020-09-01T21:11:10.958Z] 21:11:10 INFO - [21:08:10.896] bear-640x360-cenc-key-rotation-0 audio: addNextFragment() fetching next fragment bear-640x360-a_frag-cenc-key_rotation.mp4
[task 2020-09-01T21:11:10.959Z] 21:11:10 INFO - [21:08:10.897] bipbop-clearkey-keyrotation-clear-lead-1 sourceopen
[task 2020-09-01T21:11:10.959Z] 21:11:10 INFO - [21:08:10.897] bipbop-clearkey-keyrotation-clear-lead-1 video: addSourceBuffer(video/mp4; codecs="avc1.4d4015")
[task 2020-09-01T21:11:10.960Z] 21:11:10 INFO - [21:08:10.897] bipbop-clearkey-keyrotation-clear-lead-1 video: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-video.mp4
[task 2020-09-01T21:11:10.961Z] 21:11:10 INFO - [21:08:10.898] bipbop-clearkey-keyrotation-clear-lead-1 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2020-09-01T21:11:10.961Z] 21:11:10 INFO - [21:08:10.898] bipbop-clearkey-keyrotation-clear-lead-1 audio: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-audio.mp4
[task 2020-09-01T21:11:10.962Z] 21:11:10 INFO - [21:08:10.988] bipbop-clearkey-keyrotation-clear-lead-1 audio: fetch of bipbop-clearkey-keyrotation-clear-lead-audio.mp4 complete, appending
[task 2020-09-01T21:11:10.963Z] 21:11:10 INFO - [21:08:10.991] bipbop-clearkey-keyrotation-clear-lead-1 audio: updateend for bipbop-clearkey-keyrotation-clear-lead-audio.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-10.03102, audioTracks=-, videoTracks=-}
[task 2020-09-01T21:11:10.964Z] 21:11:10 INFO - [21:08:10.991] bipbop-clearkey-keyrotation-clear-lead-1 audio: end of track
[task 2020-09-01T21:11:10.964Z] 21:11:10 INFO - Buffered messages logged at 21:08:11
[task 2020-09-01T21:11:10.964Z] 21:11:10 INFO - [21:08:11.10] bear-640x360-cenc-key-rotation-0 audio: fetch of bear-640x360-a_frag-cenc-key_rotation.mp4 complete, appending
[task 2020-09-01T21:11:10.964Z] 21:11:10 INFO - [21:08:11.11] bear-640x360-cenc-key-rotation-0 audio: updateend for bear-640x360-a_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-2.80399, audioTracks=-, videoTracks=-}
[task 2020-09-01T21:11:10.964Z] 21:11:10 INFO - [21:08:11.12] bear-640x360-cenc-key-rotation-0 audio: end of track
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - [21:08:11.52] bear-640x360-cenc-key-rotation-0 video: fetch of bear-640x360-v_frag-cenc-key_rotation.mp4 complete, appending
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - [21:08:11.58] bear-640x360-cenc-key-rotation-0 encrypted event => len=850 000000347073736800000000fde979fd4aa3fd27fdfd1d21fd000000140801121030313233343536373839303132333435000002fd7073736800000000fd04fd79fd4042fdfdfdfd5bfdfd5ffd000002fdfd02000001000100fd023c00570052004d00480045004100440045005200200078006d006c006e0073003d00220068007400740070003a002f002f0073006300680065006d00610073002e006d006900630072006f0073006f00660074002e0063006f006d002f00440052004d002f0032003000300037002f00300033002f0050006c00610079005200650061006400790048006500610064006500720022002000760065007200730069006f006e003d00220034002e0030002e0030002e00300022003e003c0044004100540041003e003c00500052004f00540045004300540049004e0046004f003e003c004b00450059004c0045004e003e00310036003c002f004b00450059004c0045004e003e003c0041004c004700490044003e004100450053004300540052003c002f0041004c004700490044003e003c002f00500052004f00540045004300540049004e0046004f003e003c004b00490044003e004d007a00490078004d004400550030004e007a00590034004f005400410078004d006a004d0030004e0051003d003d003c002f004b00490044003e003c0043004800450043004b00530055004d003e0044004d0039004c00590079006d003000470049006f003d003c002f0043004800450043004b00530055004d003e003c004c0041005f00550052004c003e00680074007400700073003a002f002f007700770077002e0079006f00750074007500620065002e0063006f006d002f006100700069002f00640072006d002f0070006c0061007900720065006100640079003f0073006f0075007200630065003d0059004f0055005400550042004500260061006d0070003b0076006900640065006f005f00690064003d00540065007300740056006900640065006f00490064003c002f004c0041005f00550052004c003e003c002f0044004100540041003e003c002f00570052004d004800450041004400450052003e000000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000013031323334353637383930313233343500000000
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - [21:08:11.59] bipbop-clearkey-keyrotation-clear-lead-1 video: fetch of bipbop-clearkey-keyrotation-clear-lead-video.mp4 complete, appending
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - [21:08:11.63] bear-640x360-cenc-key-rotation-0 video: updateend for bear-640x360-v_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.033-2.769066, audioTracks=-, videoTracks=-}
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - [21:08:11.63] bear-640x360-cenc-key-rotation-0 video: end of track
[task 2020-09-01T21:11:10.965Z] 21:11:10 INFO - [21:08:11.63] bear-640x360-cenc-key-rotation-0 Tracks loaded, calling MediaSource.endOfStream()
[task 2020-09-01T21:11:10.966Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType
[task 2020-09-01T21:11:10.966Z] 21:11:10 INFO - [21:08:11.66] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000010011223344556677fdfdfdfdfdfdfdfd00000000
[task 2020-09-01T21:11:10.966Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType
[task 2020-09-01T21:11:10.966Z] 21:11:10 INFO - [21:08:11.67] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b0000000111223344556677fdfdfdfdfdfdfdfd0000000000
[task 2020-09-01T21:11:10.966Z] 21:11:10 INFO - [21:08:11.68] bipbop-clearkey-keyrotation-clear-lead-1 video: updateend for bipbop-clearkey-keyrotation-clear-lead-video.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.095-9.971677, audioTracks=-, videoTracks=-}
[task 2020-09-01T21:11:10.966Z] 21:11:10 INFO - [21:08:11.68] bipbop-clearkey-keyrotation-clear-lead-1 video: end of track
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - [21:08:11.68] bipbop-clearkey-keyrotation-clear-lead-1 Tracks loaded, calling MediaSource.endOfStream()
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - Buffered messages finished
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_pssh_in_moof.html | Test timed out!
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - onTimeout@https://example.com/tests/dom/media/test/manifest.js:2110:9
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - bear-640x360-cenc-key-rotation-0 timed out!
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - [finished bear-640x360-cenc-key-rotation-0] remaining= bipbop-clearkey-keyrotation-clear-lead-1
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bear-640x360-cenc-key-rotation-0 t=180.021] Length of array should match number of running tests
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-09-01T21:11:10.967Z] 21:11:10 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_pssh_in_moof.html | Test timed out!
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - onTimeout@https://example.com/tests/dom/media/test/manifest.js:2110:9
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - bipbop-clearkey-keyrotation-clear-lead-1 timed out!
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - [finished bipbop-clearkey-keyrotation-clear-lead-1] remaining=
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bipbop-clearkey-keyrotation-clear-lead-1 t=180.028] Length of array should match number of running tests
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - Finished at Tue Sep 01 2020 21:11:10 GMT+0000 (Greenwich Mean Time) (1598994670.899s)
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - Running time: 180.064s
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - GECKO(4296) | MEMORY STAT | vsize 2103803MB | vsizeMaxContiguous 72389865MB | residentFast 95MB | heapAllocated 10MB
[task 2020-09-01T21:11:10.968Z] 21:11:10 INFO - TEST-OK | dom/media/test/test_eme_pssh_in_moof.html | took 180159ms

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=351049441&repo=mozilla-esr78&lineNumber=4252

[task 2021-09-09T17:12:34.335Z] 17:12:34     INFO - TEST-START | dom/media/test/test_eme_pssh_in_moof.html
[task 2021-09-09T17:13:50.160Z] 17:13:50     INFO -  JavaScript error: resource://gre/modules/PlacesExpiration.jsm, line 897: TypeError: this._db is undefined
[task 2021-09-09T17:15:34.430Z] 17:15:34     INFO - TEST-INFO | started process screenshot
[task 2021-09-09T17:15:34.500Z] 17:15:34     INFO - TEST-INFO | screenshot: exit 0
[task 2021-09-09T17:15:34.501Z] 17:15:34     INFO - Buffered messages logged at 17:12:34
[task 2021-09-09T17:15:34.501Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | A valid string reason is expected 
[task 2021-09-09T17:15:34.501Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | Reason cannot be empty 
[task 2021-09-09T17:15:34.502Z] 17:15:34     INFO - Started Thu Sep 09 2021 17:12:34 GMT+0000 (Greenwich Mean Time) (1631207554.378s)
[task 2021-09-09T17:15:34.502Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bear-640x360-cenc-key-rotation-0 t=0.004] Length of array should match number of running tests 
[task 2021-09-09T17:15:34.502Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [started bipbop-clearkey-keyrotation-clear-lead-1 t=0.013] Length of array should match number of running tests 
[task 2021-09-09T17:15:34.503Z] 17:15:34     INFO - [17:12:34.437] bear-640x360-cenc-key-rotation-0 sourceopen
[task 2021-09-09T17:15:34.503Z] 17:15:34     INFO - [17:12:34.437] bear-640x360-cenc-key-rotation-0 video: addSourceBuffer(video/mp4; codecs="avc1.64000d")
[task 2021-09-09T17:15:34.504Z] 17:15:34     INFO - [17:12:34.438] bear-640x360-cenc-key-rotation-0 video: addNextFragment() fetching next fragment bear-640x360-v_frag-cenc-key_rotation.mp4
[task 2021-09-09T17:15:34.504Z] 17:15:34     INFO - [17:12:34.439] bear-640x360-cenc-key-rotation-0 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2021-09-09T17:15:34.505Z] 17:15:34     INFO - [17:12:34.439] bear-640x360-cenc-key-rotation-0 audio: addNextFragment() fetching next fragment bear-640x360-a_frag-cenc-key_rotation.mp4
[task 2021-09-09T17:15:34.505Z] 17:15:34     INFO - [17:12:34.439] bipbop-clearkey-keyrotation-clear-lead-1 sourceopen
[task 2021-09-09T17:15:34.505Z] 17:15:34     INFO - [17:12:34.440] bipbop-clearkey-keyrotation-clear-lead-1 video: addSourceBuffer(video/mp4; codecs="avc1.4d4015")
[task 2021-09-09T17:15:34.506Z] 17:15:34     INFO - [17:12:34.440] bipbop-clearkey-keyrotation-clear-lead-1 video: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-video.mp4
[task 2021-09-09T17:15:34.506Z] 17:15:34     INFO - [17:12:34.440] bipbop-clearkey-keyrotation-clear-lead-1 audio: addSourceBuffer(audio/mp4; codecs="mp4a.40.2")
[task 2021-09-09T17:15:34.507Z] 17:15:34     INFO - [17:12:34.441] bipbop-clearkey-keyrotation-clear-lead-1 audio: addNextFragment() fetching next fragment bipbop-clearkey-keyrotation-clear-lead-audio.mp4
[task 2021-09-09T17:15:34.507Z] 17:15:34     INFO - [17:12:34.523] bipbop-clearkey-keyrotation-clear-lead-1 audio: fetch of bipbop-clearkey-keyrotation-clear-lead-audio.mp4 complete, appending
[task 2021-09-09T17:15:34.508Z] 17:15:34     INFO - [17:12:34.525] bipbop-clearkey-keyrotation-clear-lead-1 audio: updateend for bipbop-clearkey-keyrotation-clear-lead-audio.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-10.03102, audioTracks=-, videoTracks=-}
[task 2021-09-09T17:15:34.508Z] 17:15:34     INFO - [17:12:34.525] bipbop-clearkey-keyrotation-clear-lead-1 audio: end of track
[task 2021-09-09T17:15:34.509Z] 17:15:34     INFO - [17:12:34.538] bear-640x360-cenc-key-rotation-0 audio: fetch of bear-640x360-a_frag-cenc-key_rotation.mp4 complete, appending
[task 2021-09-09T17:15:34.509Z] 17:15:34     INFO - [17:12:34.539] bear-640x360-cenc-key-rotation-0 audio: updateend for bear-640x360-a_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0-2.80399, audioTracks=-, videoTracks=-}
[task 2021-09-09T17:15:34.509Z] 17:15:34     INFO - [17:12:34.539] bear-640x360-cenc-key-rotation-0 audio: end of track
[task 2021-09-09T17:15:34.509Z] 17:15:34     INFO - [17:12:34.570] bear-640x360-cenc-key-rotation-0 video: fetch of bear-640x360-v_frag-cenc-key_rotation.mp4 complete, appending
[task 2021-09-09T17:15:34.509Z] 17:15:34     INFO - [17:12:34.572] bipbop-clearkey-keyrotation-clear-lead-1 video: fetch of bipbop-clearkey-keyrotation-clear-lead-video.mp4 complete, appending
[task 2021-09-09T17:15:34.509Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - [17:12:34.576] bear-640x360-cenc-key-rotation-0 encrypted event => len=850 000000347073736800000000fde979fd4aa3fd27fdfd1d21fd000000140801121030313233343536373839303132333435000002fd7073736800000000fd04fd79fd4042fdfdfdfd5bfdfd5ffd000002fdfd02000001000100fd023c00570052004d00480045004100440045005200200078006d006c006e0073003d00220068007400740070003a002f002f0073006300680065006d00610073002e006d006900630072006f0073006f00660074002e0063006f006d002f00440052004d002f0032003000300037002f00300033002f0050006c00610079005200650061006400790048006500610064006500720022002000760065007200730069006f006e003d00220034002e0030002e0030002e00300022003e003c0044004100540041003e003c00500052004f00540045004300540049004e0046004f003e003c004b00450059004c0045004e003e00310036003c002f004b00450059004c0045004e003e003c0041004c004700490044003e004100450053004300540052003c002f0041004c004700490044003e003c002f00500052004f00540045004300540049004e0046004f003e003c004b00490044003e004d007a00490078004d004400550030004e007a00590034004f005400410078004d006a004d0030004e0051003d003d003c002f004b00490044003e003c0043004800450043004b00530055004d003e0044004d0039004c00590079006d003000470049006f003d003c002f0043004800450043004b00530055004d003e003c004c0041005f00550052004c003e00680074007400700073003a002f002f007700770077002e0079006f00750074007500620065002e0063006f006d002f006100700069002f00640072006d002f0070006c0061007900720065006100640079003f0073006f0075007200630065003d0059004f0055005400550042004500260061006d0070003b0076006900640065006f005f00690064003d00540065007300740056006900640065006f00490064003c002f004c0041005f00550052004c003e003c002f0044004100540041003e003c002f00570052004d004800450041004400450052003e000000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000013031323334353637383930313233343500000000
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - [17:12:34.580] bear-640x360-cenc-key-rotation-0 video: updateend for bear-640x360-v_frag-cenc-key_rotation.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.033-2.769066, audioTracks=-, videoTracks=-}
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - [17:12:34.580] bear-640x360-cenc-key-rotation-0 video: end of track
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - [17:12:34.580] bear-640x360-cenc-key-rotation-0 Tracks loaded, calling MediaSource.endOfStream()
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - [17:12:34.583] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b000000010011223344556677fdfdfdfdfdfdfdfd00000000
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | 'encrypted' event should have 'cenc' initDataType 
[task 2021-09-09T17:15:34.510Z] 17:15:34     INFO - [17:12:34.583] bipbop-clearkey-keyrotation-clear-lead-1 encrypted event => len=52 0000003470737368010000001077fdfdfdfd4d02fdfd3c1e52fdfd4b0000000111223344556677fdfdfdfdfdfdfdfd0000000000
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - [17:12:34.583] bipbop-clearkey-keyrotation-clear-lead-1 video: updateend for bipbop-clearkey-keyrotation-clear-lead-video.mp4, SourceBuffer{AppendMode=-, updating=false, buffered=0.095-9.971677, audioTracks=-, videoTracks=-}
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - [17:12:34.583] bipbop-clearkey-keyrotation-clear-lead-1 video: end of track
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - [17:12:34.584] bipbop-clearkey-keyrotation-clear-lead-1 Tracks loaded, calling MediaSource.endOfStream()
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - Buffered messages finished
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_pssh_in_moof.html | Test timed out! 
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:299:16
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - onTimeout@https://example.com/tests/dom/media/test/manifest.js:2110:9
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - bear-640x360-cenc-key-rotation-0 timed out!
[task 2021-09-09T17:15:34.511Z] 17:15:34     INFO - [finished bear-640x360-cenc-key-rotation-0] remaining= bipbop-clearkey-keyrotation-clear-lead-1
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bear-640x360-cenc-key-rotation-0 t=180.049] Length of array should match number of running tests 
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_pssh_in_moof.html | Test timed out! 
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:299:16
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - onTimeout@https://example.com/tests/dom/media/test/manifest.js:2110:9
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - bipbop-clearkey-keyrotation-clear-lead-1 timed out!
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - [finished bipbop-clearkey-keyrotation-clear-lead-1] remaining= 
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - TEST-PASS | dom/media/test/test_eme_pssh_in_moof.html | [finished bipbop-clearkey-keyrotation-clear-lead-1 t=180.057] Length of array should match number of running tests 
[task 2021-09-09T17:15:34.512Z] 17:15:34     INFO - Finished at Thu Sep 09 2021 17:15:34 GMT+0000 (Greenwich Mean Time) (1631207734.47s)
[task 2021-09-09T17:15:34.513Z] 17:15:34     INFO - Running time: 180.092s
[task 2021-09-09T17:15:34.513Z] 17:15:34     INFO - GECKO(6024) | MEMORY STAT | vsize 2103801MB | vsizeMaxContiguous 72300363MB | residentFast 94MB | heapAllocated 10MB
[task 2021-09-09T17:15:34.513Z] 17:15:34     INFO - TEST-OK | dom/media/test/test_eme_pssh_in_moof.html | took 180180ms
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.