Intermittent test_mediarecorder_principals.html | mediaRecorder.onerror must fire SecurityError

REOPENED
Assigned to

Status

()

Core
Audio/Video: Recording
P3
normal
Rank:
25
REOPENED
2 years ago
6 months ago

People

(Reporter: Tomcat, Assigned: jib)

Tracking

({intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

(URL)

MozReview Requests

()

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(1 attachment)

(Reporter)

Description

2 years ago
https://treeherder.mozilla.org/logviewer.html#?job_id=26277329&repo=mozilla-inbound

 06:20:22 INFO - 461 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_mediarecorder_principals.html | mediaRecorder.onerror must fire SecurityError

Comment 1

2 years ago
11 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 9
* mozilla-central: 1
* fx-team: 1

Platform breakdown:
* linux64: 11

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2016-04-18&endday=2016-04-24&tree=all
jib/mt: any idea why this is failing intermittently?
Rank: 25
Component: Audio/Video → Audio/Video: Recording
Flags: needinfo?(martin.thomson)
Flags: needinfo?(jib)
Priority: -- → P2
There are two tests in this file, both relying on partial http requests. The first one works fine, but the second one never redirects. The initial request from the second test [1] starts here (with v2_*):

> 06:20:17     INFO -  Received request for key = v2_11009232
> 06:20:17     INFO -  Response Content-Range = bytes 0-285309/285310
> 06:20:17     INFO -  Response Content-Length = 285310
> 06:20:20     INFO -  --DOCSHELL 0x7f34990eb800 == 3 [pid = 1883] [id = 75]
> 06:20:21     INFO -  TEST-INFO | started process screentopng
> 06:20:22     INFO -  TEST-INFO | screentopng: exit 0

Anyone know what "screentopng" is? If we see this again, I'd be curious to see if it's involved.

> 06:20:22     INFO -  455 INFO TEST-PASS | dom/media/test/test_mediarecorder_principals.html | A valid string reason is expected
> 06:20:22     INFO -  456 INFO TEST-PASS | dom/media/test/test_mediarecorder_principals.html | Reason cannot be empty
> 06:20:22     INFO -  457 INFO video.currentTime = 0.964463
> 06:20:22     INFO -  458 INFO video.currentTime = 1.977329

Gravity waves here, just looking at the times for the last two lines above. How is that possible, even accounting for rounding error? What's further odd is that these two lines seem to be from *from the first test*!

> 06:20:22     INFO -  459 INFO TEST-PASS | dom/media/test/test_mediarecorder_principals.html | mediaRecorder.start() must throw SecurityError
> 06:20:22     INFO -  460 INFO TEST-PASS | dom/media/test/test_mediarecorder_principals.html | mediaRecorder.start() should not throw here
> 06:20:22     INFO -  461 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_mediarecorder_principals.html | mediaRecorder.onerror must fire SecurityError

I thought I'd locked down the partial loader sufficiently in this test, but the seek.ogv file being operated on is only 4 seconds long after all, so I don't know if it's possible for things to be out of whack enough for this file to finish without any redirecting taking place. I suggest we keep an eye on it, and compare with future logs.

[1] http://mxr.mozilla.org/mozilla-central/source/dom/media/test/test_mediarecorder_principals.html?force=1#71
Flags: needinfo?(jib)
Sorry, just noticed the robot in comment 1.

Yeah the "screentopng" seems to be the culprit, whatever it is.

It shows up in the middle of this second test in every intermittent log. Linux x64 debug and asan only. Is there a way to move this thing away from this particular test, or just away in general?
(In reply to Jan-Ivar Bruaroey [:jib] from comment #4)
> Sorry, just noticed the robot in comment 1.
> 
> Yeah the "screentopng" seems to be the culprit, whatever it is.
> 
> It shows up in the middle of this second test in every intermittent log.
> Linux x64 debug and asan only. Is there a way to move this thing away from
> this particular test, or just away in general?

screentopng is a snapshot-the-screen thing run after a failure, that's not a cause, it's an effect.
Flags: needinfo?(jib)
Hmm that makes sense. Pity it throws off the logs so much, to the point of it looking like it happens a whole second before the failure is reported.
Flags: needinfo?(jib)
So the test is failing, because a SecurityError is not thrown within the 4 seconds of the file, because the rigged redirect from all subsequent partial requests isn't happening, because no partial requests apart from the initial one (v2_*) appear to be made by the HTMLMediaElement loader, which is odd, because the test directly ahead of it, loads the same file the same way, and it causes plenty of partial loads (v1_*), as can be seen in the log.

Is there some file caching specific to linux x64 going on, or other unique concurrency behaviors I should be aware of there? Timing wise, things seem to almost be overlapping here. Maybe breaking the two tests into different test files would help?
I'd be fine with disabling this test on linux x64 fwiw. Any takers?
Is the first request forcing a partial load?  That is, does the response include a short range no matter what?
Flags: needinfo?(martin.thomson)
Yes. Both tests work under the same media.cache_size of 192K. Using the log from comment 0 again:

> 06:20:15     INFO -  Received request for key = v1_11009232
> 06:20:15     INFO -  Response Content-Range = bytes 0-285309/285310
> 06:20:15     INFO -  Response Content-Length = 285310

Ironically, seek.ogv is so small (278K) that the initial request includes the entire file (we're probably below some minimum value), but with our tiny buffer, more requests are forthcoming:

> 06:20:15     INFO -  Received request for key = v1_11009232
> 06:20:15     INFO -  Redirecting to http://example.org/tests/dom/media/test/dynamic_redirect.sjs?nested&key=v1_11009232&res=seek.ogv

here's the second request and redirect,

> 06:20:15     INFO -  [Parent 1820] WARNING: NS_ENSURE_TRUE(mCacheEntry) failed: file /home/worker/workspace/build/src/netwerk/protocol/http/nsHttpChannel.cpp, line 4286
> 06:20:15     INFO -  Received request for key = v1_11009232
> 06:20:15     INFO -  Response Content-Range = bytes 32768-285309/285310
> 06:20:15     INFO -  Response Content-Length = 252542

and this is an actual partial request for a chunk of 246K (skipping the first 32K for some reason).

> 06:20:16     INFO -  Received request for key = v1_11009232
> 06:20:16     INFO -  Redirecting to http://example.org/tests/dom/media/test/dynamic_redirect.sjs?nested&key=v1_11009232&res=seek.ogv
> 06:20:16     INFO -  [Parent 1820] WARNING: NS_ENSURE_TRUE(mCacheEntry) failed: file /home/worker/workspace/build/src/netwerk/protocol/http/nsHttpChannel.cpp, line 4286
> 06:20:16     INFO -  Received request for key = v1_11009232
> 06:20:16     INFO -  Response Content-Range = bytes 285310-285310/285310
> 06:20:16     INFO -  Response Content-Length = 1
> 06:20:16     INFO -  [Child 1883] WARNING: NS_ENSURE_TRUE(aRangeStart < aRangeEnd) failed: file /home/worker/workspace/build/src/dom/media/MediaResource.cpp, line 352

And a bonus one where it's getting a byte past the end of the file, which looks like a fence-post error in HTMLMediaElement, but lets not chase that here.

> 06:20:17     INFO -  Received request for key = v2_11009232

And here's comes the second request.
There were no objections in the morning meeting to disabling this on linux x64 for now.

Comment 12

2 years ago
17 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 10
* fx-team: 3
* ash: 2
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 17

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2016-04-25&endday=2016-05-01&tree=all
Created attachment 8747943 [details]
MozReview Request: Bug 1266345 - disable test_mediarecorder_principals.html on linux 64

Review commit: https://reviewboard.mozilla.org/r/50081/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/50081/
Attachment #8747943 - Flags: review?(rjesup)
Assignee: nobody → jib
Comment on attachment 8747943 [details]
MozReview Request: Bug 1266345 - disable test_mediarecorder_principals.html on linux 64

https://reviewboard.mozilla.org/r/50081/#review46869
Attachment #8747943 - Flags: review?(rjesup) → review+
(Reporter)

Comment 16

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/e4711157125b
Status: NEW → RESOLVED
Last Resolved: 2 years ago
status-firefox49: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla49
Still happening.
Status: RESOLVED → REOPENED
status-firefox49: fixed → ---
Resolution: FIXED → ---
Target Milestone: mozilla49 → ---

Comment 18

2 years ago
5 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 3
* fx-team: 2

Platform breakdown:
* linux32: 4
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2016-05-23&endday=2016-05-29&tree=all
7 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 3
* mozilla-inbound: 2
* mozilla-central: 1
* fx-team: 1

Platform breakdown:
* osx-10-10: 6
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2016-10-03&endday=2016-10-09&tree=all
5 failures in 690 pushes (0.007 failures/push) were associated with this bug in the last 7 days.  

Repository breakdown:
* mozilla-central: 2
* mozilla-release: 1
* mozilla-inbound: 1
* mozilla-aurora: 1

Platform breakdown:
* linux32: 2
* windowsxp: 1
* windows7-32-vm: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-01-16&endday=2017-01-22&tree=all
6 failures in 749 pushes (0.008 failures/push) were associated with this bug in the last 7 days.  

Repository breakdown:
* mozilla-inbound: 5
* mozilla-central: 1

Platform breakdown:
* windows8-64: 3
* linux32: 2
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-01-23&endday=2017-01-29&tree=all
5 failures in 733 pushes (0.007 failures/push) were associated with this bug in the last 7 days.  

Repository breakdown:
* try: 2
* autoland: 2
* mozilla-inbound: 1

Platform breakdown:
* windows8-64: 2
* windows7-32-vm: 1
* osx-10-10: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-01-30&endday=2017-02-05&tree=all
15 failures in 836 pushes (0.018 failures/push) were associated with this bug in the last 7 days.  
Repository breakdown:
* autoland: 6
* mozilla-inbound: 5
* mozilla-central: 2
* mozilla-beta: 1
* graphics: 1

Platform breakdown:
* windows8-64: 9
* linux32: 5
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-02-06&endday=2017-02-12&tree=all
6 failures in 833 pushes (0.007 failures/push) were associated with this bug in the last 7 days.  
Repository breakdown:
* autoland: 3
* mozilla-inbound: 2
* graphics: 1

Platform breakdown:
* linux32: 3
* windows8-64: 1
* windows7-32: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-02-13&endday=2017-02-19&tree=all

Comment 25

11 months ago
5 failures in 845 pushes (0.006 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 3
* mozilla-inbound: 1
* mozilla-aurora: 1

Platform breakdown:
* windows7-32-vm: 3
* windows8-64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-03-27&endday=2017-04-02&tree=all

Comment 26

10 months ago
6 failures in 770 pushes (0.008 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 2
* autoland: 2
* try: 1
* mozilla-esr52: 1

Platform breakdown:
* windows7-32-vm: 3
* windows7-32: 2
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-05-01&endday=2017-05-07&tree=all

Comment 27

10 months ago
5 failures in 879 pushes (0.006 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 2
* oak: 1
* mozilla-beta: 1
* autoland: 1

Platform breakdown:
* windows7-32-vm: 3
* windows7-32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-05-08&endday=2017-05-14&tree=all

Comment 28

9 months ago
8 failures in 820 pushes (0.01 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 3
* autoland: 3
* try: 1
* mozilla-central: 1

Platform breakdown:
* windows8-64: 2
* windows7-32-vm: 2
* windows7-32: 2
* osx-10-10: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-05-29&endday=2017-06-04&tree=all

Comment 29

9 months ago
11 failures in 864 pushes (0.013 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 5
* mozilla-central: 3
* try: 2
* mozilla-inbound: 1

Platform breakdown:
* windows7-32-vm: 6
* windows8-64: 5

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-06-05&endday=2017-06-11&tree=all

Comment 30

8 months ago
8 failures in 814 pushes (0.01 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 5
* try: 3

Platform breakdown:
* windows7-32-vm: 4
* linux32: 2
* windows8-64: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-06-12&endday=2017-06-18&tree=all

Comment 31

8 months ago
4 failures in 892 pushes (0.004 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 3
* try: 1

Platform breakdown:
* linux32: 2
* windows7-32-vm: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-06-19&endday=2017-06-25&tree=all

Comment 32

8 months ago
1 failures in 718 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-06-26&endday=2017-07-02&tree=all

Comment 33

8 months ago
1 failures in 656 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-07-03&endday=2017-07-09&tree=all

Comment 34

7 months ago
3 failures in 720 pushes (0.004 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* oak: 1
* mozilla-esr52: 1
* autoland: 1

Platform breakdown:
* linux32: 2
* windows7-32-vm: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-07-10&endday=2017-07-16&tree=all

Comment 35

7 months ago
4 failures in 822 pushes (0.005 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-beta: 2
* autoland: 2

Platform breakdown:
* linux32: 2
* windows7-32-vm: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-07-17&endday=2017-07-23&tree=all

Comment 36

7 months ago
2 failures in 1008 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 1
* mozilla-esr52: 1

Platform breakdown:
* windows7-32-vm: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1266345&startday=2017-07-24&endday=2017-07-30&tree=all
Mass change P2->P3 to align with new Mozilla triage process.
Priority: P2 → P3
You need to log in before you can comment on or make changes to this bug.