1571821 - Intermittent Assertion failure: percentage >= 0, at dom/media/mediacapabilities/DecoderBenchmark.cpp:38 | application crashed [@ mozilla::DecoderBenchmark::StoreScore(nsTSubstring<char> const&, nsTSubstring<char> const&, RefPtr<mozilla::FrameStatistics>)]

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: aciure [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=260150420&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/MNjYWrOTQ_-w_WZRYYk9lA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-08-06T17:28:22.662Z] 17:28:22 INFO - PID 1981 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/cw/whlfv6ld5xx18dpvhc9cft18000017/T/tmpPASla_.mozrunner/runtests_leaks_1471_gmplugin_pid2017.log
[task 2019-08-06T17:28:22.662Z] 17:28:22 INFO - PID 1981 | [2017, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-08-06T17:28:22.662Z] 17:28:22 INFO - PID 1981 | [2017, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-08-06T17:28:22.662Z] 17:28:22 INFO - PID 1981 | [GMP 2017, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/workspace/build/src/modules/libpref/Preferences.cpp, line 4448
[task 2019-08-06T17:28:22.663Z] 17:28:22 INFO - PID 1981 | [GMP 2017, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/workspace/build/src/modules/libpref/Preferences.cpp, line 4448
[task 2019-08-06T17:28:22.663Z] 17:28:22 INFO - PID 1981 | [GMP 2017, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/workspace/build/src/modules/libpref/Preferences.cpp, line 4448
[task 2019-08-06T17:28:28.780Z] 17:28:28 INFO - PID 1981 | Assertion failure: percentage >= 0, at /builds/worker/workspace/build/src/dom/media/mediacapabilities/DecoderBenchmark.cpp:38
[task 2019-08-06T17:28:30.811Z] 17:28:30 INFO - mozcrash .
[task 2019-08-06T17:28:30.812Z] 17:28:30 INFO - mozcrash Copy/paste: /Users/cltbld/tasks/task_1565111528/build/macosx64-minidump_stackwalk /var/folders/cw/whlfv6ld5xx18dpvhc9cft18000017/T/tmpPASla_.mozrunner/minidumps/F0D92009-D8D8-4869-B59E-B730B61D2F81.dmp /Users/cltbld/tasks/task_1565111528/build/symbols
[task 2019-08-06T17:28:38.178Z] 17:28:38 INFO - mozcrash Saved minidump as /Users/cltbld/tasks/task_1565111528/build/blobber_upload_dir/F0D92009-D8D8-4869-B59E-B730B61D2F81.dmp
[task 2019-08-06T17:28:38.178Z] 17:28:38 INFO - mozcrash Saved app info as /Users/cltbld/tasks/task_1565111528/build/blobber_upload_dir/F0D92009-D8D8-4869-B59E-B730B61D2F81.extra
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - PROCESS-CRASH | /encrypted-media/clearkey-mp4-playback-temporary-multikey-sequential-readyState.https.html | application crashed [@ mozilla::DecoderBenchmark::StoreScore(nsTSubstring<char> const&, nsTSubstring<char> const&, RefPtr<mozilla::FrameStatistics>)]
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - Crash dump filename: /var/folders/cw/whlfv6ld5xx18dpvhc9cft18000017/T/tmpPASla_.mozrunner/minidumps/F0D92009-D8D8-4869-B59E-B730B61D2F81.dmp
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - Operating system: Mac OS X
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - 10.14.5 18F132
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - CPU: amd64
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - family 6 model 69 stepping 1
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - 4 CPUs
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO -
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO - GPU: UNKNOWN
[task 2019-08-06T17:28:38.310Z] 17:28:38 INFO -
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - Crash reason: EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - Crash address: 0x0
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - Process uptime: 62 seconds
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO -
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - Thread 0 (crashed)
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - 0 XUL!mozilla::DecoderBenchmark::StoreScore(nsTSubstring<char> const&, nsTSubstring<char> const&, RefPtr<mozilla::FrameStatistics>) [DecoderBenchmark.cpp:747f5a90f7d8a627d157b6b21861a8ec309d31b7 : 38 + 0x29]
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - rax = 0x00000001163c8382 rdx = 0x0000000000000000
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - rcx = 0x000000010e1bbde8 rbx = 0x000000000000003b
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - rsi = 0x00000000000120a8 rdi = 0x00007fff99bec028
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - rbp = 0x00007ffee1abce50 rsp = 0x00007ffee1abce10
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - r8 = 0x00000000000130a8 r9 = 0x00007fff99bec048
[task 2019-08-06T17:28:38.311Z] 17:28:38 INFO - r10 = 0x0000000000000000 r11 = 0x00007fff99bec040
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - r12 = 0x000000012756b560 r13 = 0x00000001265b6e88
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - r14 = 0x000000000000007a r15 = 0x00000001265b6e80
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - rip = 0x0000000111ad5abd
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - Found by: given as instruction pointer in context
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - 1 XUL!mozilla::DecoderBenchmark::Store(mozilla::DecoderBenchmarkInfo const&, RefPtr<mozilla::FrameStatistics>) [DecoderBenchmark.cpp:747f5a90f7d8a627d157b6b21861a8ec309d31b7 : 168 + 0x58]
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - rbp = 0x00007ffee1abcea0 rsp = 0x00007ffee1abce60
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - rip = 0x0000000111ad6ae9
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - Found by: previous frame's frame pointer
[task 2019-08-06T17:28:38.312Z] 17:28:38 INFO - 2 XUL!mozilla::MediaDecoder::OnStoreDecoderBenchmark(mozilla::VideoInfo const&) [MediaDecoder.cpp:747f5a90f7d8a627d157b6b21861a8ec309d31b7 : 525 + 0x8]
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - rbp = 0x00007ffee1abcf10 rsp = 0x00007ffee1abceb0
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - rip = 0x00000001118b2e9e
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - Found by: previous frame's frame pointer
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - 3 XUL!mozilla::detail::RunnableMethodImpl<mozilla::detail::Listener<mozilla::VideoInfo>, void (mozilla::detail::Listener<mozilla::VideoInfo>::)(mozilla::VideoInfo&&), true, (mozilla::RunnableKind)0, mozilla::VideoInfo&&>::Run() [nsThreadUtils.h:747f5a90f7d8a627d157b6b21861a8ec309d31b7 : 1176 + 0x1e]
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - rbp = 0x00007ffee1abcf20 rsp = 0x00007ffee1abcf20
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - rip = 0x000000011198a57a
[task 2019-08-06T17:28:38.313Z] 17:28:38 INFO - Found by: previous frame's frame pointer

Comment 3

[Intermittent Failures Robot]

6 failures in 4666 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• mozilla-inbound: 1
• autoland: 4

Platform breakdown:

• macosx1014-64: 1
• android-em-7-0-x86_64: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-08-05&endday=2019-08-11&tree=all

Comment 4

[Alex Chronopoulos [:achronop]]

Android:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=81de2b245cbbd4fab98ff336b55cd7f257e0ca51
OSX:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d91ed03d987c704534e648fbab9c0f05431d883b

Comment 5

[Alex Chronopoulos [:achronop]]

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

Comment 6

[Alex Chronopoulos [:achronop]]

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

Comment 7

[Alex Chronopoulos [:achronop]]

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

Comment 8

[Intermittent Failures Robot]

19 failures in 4839 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 12
• mozilla-inbound: 4
• mozilla-central: 1
• try: 2

Platform breakdown:

• android-em-7-0-x86_64: 17
• macosx1014-64: 1
• windows10-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-08-12&endday=2019-08-18&tree=all

Comment 9

[Intermittent Failures Robot]

6 failures in 5073 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3
• mozilla-inbound: 3

Platform breakdown:

• android-em-7-0-x86_64: 5
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-08-19&endday=2019-08-25&tree=all

Comment 10

[Intermittent Failures Robot]

4 failures in 5047 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4

Platform breakdown:

• macosx1014-64: 1
• android-em-7-0-x86_64: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-08-26&endday=2019-09-01&tree=all

Comment 13

[Alex Chronopoulos [:achronop]]

Attachment: Bug 1571821 - Use total frames instead of parsed frames to calculate benchmark. r?alwu

The problem reproduces when the system is loaded and the decoder is dropping most of the frames. When there are two benchmark calculations close to each other, the measured parsed frames of the first calculation can be buffered in the decoder and reported as dropped frames on the second calculation. Then on the second calculation, the number of dropped frames can be greater than the parsed frame which will hit the assert. The number of total frames is a better measure since it counts the frames that appeared in the in VideoSink plus the total dropped frames.

Comment 15

[Intermittent Failures Robot]

12 failures in 4408 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1
• mozilla-central: 1
• autoland: 8
• mozilla-inbound: 2

Platform breakdown:

• android-em-7-0-x86_64: 10
• windows10-64-ccov: 1
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-09-02&endday=2019-09-08&tree=all

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/0d5c063c17b4
Use total frames instead of parsed frames to calculate benchmark. r=alwu

Comment 17

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/0d5c063c17b4

Comment 18

[Intermittent Failures Robot]

7 failures in 4637 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1
• autoland: 3
• mozilla-central: 2
• mozilla-inbound: 1

Platform breakdown:

• android-em-7-0-x86_64: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-09-09&endday=2019-09-15&tree=all

Comment 19

[Intermittent Failures Robot]

1 failures in 4350 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform breakdown:

• android-em-7-0-x86_64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-09-16&endday=2019-09-22&tree=all

Comment 20

[Intermittent Failures Robot]

1 failures in 4530 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform breakdown:

• android-em-7-0-x86_64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1571821&startday=2019-09-23&endday=2019-09-29&tree=all