Intermittent test_encryptedMediaExtensions.html | Failed to initialise MediaKeySession (with "Sandbox: seccomp sandbox violation, … syscall 141")

RESOLVED FIXED in Firefox 34

Status

()

defect
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: RyanVM, Assigned: jld)

Tracking

(Blocks 1 bug, {intermittent-failure})

Trunk
mozilla36
x86_64
Linux
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox33 wontfix, firefox34 fixed, firefox35 fixed, firefox36 fixed, firefox-esr31 unaffected)

Details

Attachments

(1 attachment)

https://treeherder.mozilla.org/ui/logviewer.html#?job_id=2857362&repo=mozilla-inbound

builder 	Ubuntu ASAN VM 12.04 x64 mozilla-inbound opt test mochitest-1
buildid 	20141008095906
builduid 	617796d675db477aa26ddf275941b0d3
results 	warnings (1)
revision 	0097b4ffaf33
slave 		tst-linux64-spot-318
starttime 	Wed Oct 08 2014 13:42:47 GMT-0400 (Eastern Standard Time)

11:03:09 INFO - 1781 INFO TEST-START | /tests/content/media/test/test_encryptedMediaExtensions.html
11:03:09 INFO - I/SampleTable( 2183): There are reordered frames present.
11:03:10 INFO - Sandbox: seccomp sandbox violation: pid 2993, syscall 141, args 0 2995 1 140443920623904 983040 9447184. Killing process.
11:03:10 INFO - 1782 INFO Started Wed Oct 08 2014 11:03:09 GMT-0700 (PDT) (1412791389.329s)
11:03:10 INFO - 1783 INFO TEST-PASS | /tests/content/media/test/test_encryptedMediaExtensions.html | [started short-cenc.mp4-0] Length of array should match number of running tests
11:03:10 INFO - 1784 INFO got encrypted event
11:03:10 INFO - 1785 INFO TEST-PASS | /tests/content/media/test/test_encryptedMediaExtensions.html | MediaKeys should support this keysystem
11:03:10 INFO - 1786 INFO created MediaKeys object ok
11:03:10 INFO - 1787 INFO set MediaKeys on <video> element ok
11:03:10 INFO - 1788 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_encryptedMediaExtensions.html | Failed to initialise MediaKeySession - expected PASS
11:03:10 INFO - 1789 INFO TEST-OK | /tests/content/media/test/test_encryptedMediaExtensions.html | took 1248ms 


The sandbox error looks possibly-relevant?
I filed bug 1080077 about getting a call stack for these crashes (normally we would, via the crash reporter, but ASAN disables it), so that I can find out what is calling setpriority() after we're sandboxed rather than just guessing.

My guess, for what it's worth, is that the NSPR thread creation stuff that does getpriority followed by setpriority (and skips the latter if the former fails) is racing with the sandbox startup.  I don't know why that would start happening now.

(I also don't like that it's even possible to have that kind of race condition, but there are larger windmills to tilt at.)
See Also: → 1080803
Comment #5 is a timeout that seems to be unrelated; there's no sandbox failure.  (Bug 1082112: mozharness doesn't highlight the relevant log lines, even though it's seriously bad if they ever appear, so their presence/absence isn't obvious.)

Comment #4 *is* a repro, with a stack trace thanks to bug 1080077:

15:33:48 INFO - Sandbox: seccomp sandbox violation: pid 2689, syscall 141, args 0 2691 1 139757464054048 983040 9447184. Killing process.
15:33:48 INFO - Sandbox: crash reporter is disabled (or failed); trying stack trace:
15:33:48 INFO - Sandbox: frame #01: setpriority[/lib/x86_64-linux-gnu/libc.so.6 +0xec407]
15:33:48 INFO - Sandbox: frame #02: ???[/builds/slave/test/build/application/firefox/libnspr4.so +0x681c5]
15:33:48 INFO - Sandbox: frame #03: ???[/lib/x86_64-linux-gnu/libpthread.so.0 +0x7e9a]
15:33:48 INFO - Sandbox: frame #04: clone[/lib/x86_64-linux-gnu/libc.so.6 +0xf3dbd]
15:33:48 INFO - Sandbox: end of stack.

So, 0x681c5.  Clear the Thumb bit, subtract 1, and ask addr2line:

_pt_root
/builds/slave/m-in-l64-asan-0000000000000000/build/nsprpub/pr/src/pthreads/ptthread.c:142

Which is this:

    137     rv = getpriority(PRIO_PROCESS, 0);
    138
    139     /* If we cannot read the main thread's nice value don't try to change the
    140      * new thread's nice value. */
    141     if (errno == 0) {
 => 142         setpriority(PRIO_PROCESS, tid,
    143                     pt_RelativePriority(rv, thred->priority));
    144     }

So my guess in comment #2 was right, and this isn't actually ASAN-specific.
Assignee: nobody → jld
Blocks: 1021232
Summary: Intermittent test_encryptedMediaExtensions.html | Failed to initialise MediaKeySession → Intermittent test_encryptedMediaExtensions.html | Failed to initialise MediaKeySession (with "Sandbox: seccomp sandbox violation, … syscall 141")
I filed bug 1083924 for comment 5 (and others like it).
(In reply to Jed Davis [:jld] from comment #6)
> So, 0x681c5.  Clear the Thumb bit, subtract 1, and ask addr2line:

…and we can see here that it was too early in the morning when I wrote that, because this is amd64, not ARM.  But it's still valid: 0x681c3 is inside the 5-byte call instruction at 0x681c0, so the debug info thusly indexed is correct.

The important part, really, is that the caller doesn't care if the setpriority fails.
The try run in comment #9 is green.
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/11f1649bd31a
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla36
Please request Aurora and Beta approval on this when you get a chance.
Comment on attachment 8506350 [details] [diff] [review]
bug1080165-setpriority-hg0.diff

Approval Request Comment
[Feature/regressing bug #]: Bug 1012951
[User impact if declined]: Intermittent failure to start a media plugin.  We've only seen this on automated ASAN runs, and not very often (see above), but in theory it could occur on regular builds.
[Describe test coverage new/current, TBPL]: There are mochitests that run media plugins, including the one named in this bug's summary.
[Risks and why]: Very little; this changes setpriority() from crashing to simply failing, for media plugins (OpenH264, EME) on Linux.  The set of allowed system calls is unaffected.
[String/UUID change made/needed]: None.

Aurora try: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=168163563792
Beta try: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=fbaf4f1d5e75
Flags: needinfo?(jld)
Attachment #8506350 - Flags: approval-mozilla-beta?
Attachment #8506350 - Flags: approval-mozilla-aurora?
Comment on attachment 8506350 [details] [diff] [review]
bug1080165-setpriority-hg0.diff

Beta+
Aurora+
Attachment #8506350 - Flags: approval-mozilla-beta?
Attachment #8506350 - Flags: approval-mozilla-beta+
Attachment #8506350 - Flags: approval-mozilla-aurora?
Attachment #8506350 - Flags: approval-mozilla-aurora+
You need to log in before you can comment on or make changes to this bug.