Closed Bug 1706712 Opened 4 years ago Closed 4 years ago

Perma layout/tools/reftest/selftest/test_reftest_manifest_parser.py::test_parse_test_types TEST-UNEXPECTED-FAIL

Categories

(Testing :: Reftest, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1672455

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=337331457&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/deZyjohzRbixHDC1Q2q70g/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/deZyjohzRbixHDC1Q2q70g/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2021-04-21T17:20:22.705Z]  0:04.38 =========================== 1 passed in 0.18 seconds ===========================
[task 2021-04-21T17:26:24.441Z]  6:06.11 /builds/worker/checkouts/gecko/layout/tools/reftest/selftest/test_reftest_manifest_parser.py
[task 2021-04-21T17:26:24.442Z]  6:06.11 ============================= test session starts ==============================
[task 2021-04-21T17:26:24.442Z]  6:06.11 platform linux -- Python 3.6.9, pytest-3.6.2, py-1.5.4, pluggy-0.6.0 -- /builds/worker/checkouts/gecko/obj-x86_64-pc-linux-gnu/_virtualenvs/python-test/bin/python
[task 2021-04-21T17:26:24.442Z]  6:06.11 rootdir: /builds/worker/checkouts/gecko, inifile: /builds/worker/checkouts/gecko/config/mozunit/mozunit/pytest.ini
[task 2021-04-21T17:26:24.442Z]  6:06.11 collecting ... collected 3 items
[task 2021-04-21T17:26:24.442Z]  6:06.11 
[task 2021-04-21T17:26:24.442Z]  6:06.11 layout/tools/reftest/selftest/test_reftest_manifest_parser.py::test_parse_test_types TEST-UNEXPECTED-FAIL
[task 2021-04-21T17:26:24.442Z]  6:06.11 layout/tools/reftest/selftest/test_reftest_manifest_parser.py::test_parse_failure_type_interactions TEST-UNEXPECTED-FAIL
[task 2021-04-21T17:26:24.442Z]  6:06.11 layout/tools/reftest/selftest/test_reftest_manifest_parser.py::test_parse_invalid_manifests TEST-UNEXPECTED-FAIL
[task 2021-04-21T17:26:24.442Z]  6:06.11 
[task 2021-04-21T17:26:24.442Z]  6:06.11 =================================== FAILURES ===================================
[task 2021-04-21T17:26:24.442Z]  6:06.11 ____________________________ test_parse_test_types _____________________________
[task 2021-04-21T17:26:24.442Z]  6:06.11 
[task 2021-04-21T17:26:24.442Z]  6:06.11 parse = <function parse.<locals>.inner at 0x7fd24918d7b8>
[task 2021-04-21T17:26:24.442Z]  6:06.11 
[task 2021-04-21T17:26:24.442Z]  6:06.11     def test_parse_test_types(parse):
[task 2021-04-21T17:26:24.442Z]  6:06.11 >       tests = parse("types.list")
[task 2021-04-21T17:26:24.442Z]  6:06.11 
[task 2021-04-21T17:26:24.442Z]  6:06.11 layout/tools/reftest/selftest/test_reftest_manifest_parser.py:34:
[task 2021-04-21T17:26:24.442Z]  6:06.11 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2021-04-21T17:26:24.442Z]  6:06.11 layout/tools/reftest/selftest/test_reftest_manifest_parser.py:28: in inner
[task 2021-04-21T17:26:24.442Z]  6:06.11     return reftest.getActiveTests(manifests, options)
[task 2021-04-21T17:26:24.442Z]  6:06.11 ../../fetches/tests/reftest/runreftest.py:1027: in getActiveTests
[task 2021-04-21T17:26:24.442Z]  6:06.11     self.runApp(options, cmdargs=cmdargs, prefs=prefs)
[task 2021-04-21T17:26:24.442Z]  6:06.11 ../../fetches/tests/reftest/runreftest.py:1014: in runApp
[task 2021-04-21T17:26:24.442Z]  6:06.11     raise reraise(exc, value, tb)
[task 2021-04-21T17:26:24.442Z]  6:06.11 third_party/python/six/six.py:696: in reraise
[task 2021-04-21T17:26:24.442Z]  6:06.11     raise value
[task 2021-04-21T17:26:24.442Z]  6:06.11 ../../fetches/tests/reftest/runreftest.py:971: in runApp
[task 2021-04-21T17:26:24.442Z]  6:06.11     marionette.start_session()
[task 2021-04-21T17:26:24.443Z]  6:06.11 testing/marionette/client/marionette_driver/decorators.py:37: in _
[task 2021-04-21T17:26:24.443Z]  6:06.11     m._handle_socket_failure()
[task 2021-04-21T17:26:24.443Z]  6:06.11 testing/marionette/client/marionette_driver/marionette.py:683: in _handle_socket_failure
[task 2021-04-21T17:26:24.443Z]  6:06.11     reraise(exc_cls, exc, tb)
[task 2021-04-21T17:26:24.443Z]  6:06.11 third_party/python/six/six.py:696: in reraise
[task 2021-04-21T17:26:24.443Z]  6:06.11     raise value
[task 2021-04-21T17:26:24.443Z]  6:06.11 testing/marionette/client/marionette_driver/decorators.py:27: in _
[task 2021-04-21T17:26:24.443Z]  6:06.11     return func(*args, **kwargs)
[task 2021-04-21T17:26:24.443Z]  6:06.11 testing/marionette/client/marionette_driver/marionette.py:1180: in start_session
[task 2021-04-21T17:26:24.443Z]  6:06.11     self.raise_for_port(timeout=timeout)
[task 2021-04-21T17:26:24.443Z]  6:06.11 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2021-04-21T17:26:24.443Z]  6:06.11 
[task 2021-04-21T17:26:24.443Z]  6:06.11 self = <marionette_driver.marionette.Marionette object at 0x7fd248a95390>
[task 2021-04-21T17:26:24.443Z]  6:06.11 timeout = 120, check_process_status = True
[task 2021-04-21T17:26:24.443Z]  6:06.11 
[task 2021-04-21T17:26:24.443Z]  6:06.12     def raise_for_port(self, timeout=None, check_process_status=True):
[task 2021-04-21T17:26:24.443Z]  6:06.12         """Raise socket.timeout if no connection can be established.
[task 2021-04-21T17:26:24.443Z]  6:06.12 
[task 2021-04-21T17:26:24.443Z]  6:06.12             :param timeout: Optional timeout in seconds for the server to be ready.
[task 2021-04-21T17:26:24.443Z]  6:06.12             :param check_process_status: Optional, if `True` the process will be
[task 2021-04-21T17:26:24.443Z]  6:06.12                 continuously checked if it has exited, and the connection
[task 2021-04-21T17:26:24.443Z]  6:06.12                 attempt will be aborted.
[task 2021-04-21T17:26:24.443Z]  6:06.12             """
[task 2021-04-21T17:26:24.443Z]  6:06.12         if timeout is None:
[task 2021-04-21T17:26:24.443Z]  6:06.12             timeout = self.startup_timeout
[task 2021-04-21T17:26:24.443Z]  6:06.12 
[task 2021-04-21T17:26:24.443Z]  6:06.12         runner = None
[task 2021-04-21T17:26:24.443Z]  6:06.12         if self.instance is not None:
[task 2021-04-21T17:26:24.443Z]  6:06.12             runner = self.instance.runner
[task 2021-04-21T17:26:24.443Z]  6:06.12 
[task 2021-04-21T17:26:24.443Z]  6:06.12         poll_interval = 0.1
[task 2021-04-21T17:26:24.443Z]  6:06.12         starttime = datetime.datetime.now()
[task 2021-04-21T17:26:24.444Z]  6:06.12         timeout_time = starttime + datetime.timedelta(seconds=timeout)
[task 2021-04-21T17:26:24.444Z]  6:06.12 
[task 2021-04-21T17:26:24.444Z]  6:06.12         client = transport.TcpTransport(self.host, self.port, 0.5)
[task 2021-04-21T17:26:24.444Z]  6:06.12 
[task 2021-04-21T17:26:24.444Z]  6:06.12         connected = False
[task 2021-04-21T17:26:24.444Z]  6:06.12         while datetime.datetime.now() < timeout_time:
[task 2021-04-21T17:26:24.444Z]  6:06.12             # If the instance we want to connect to is not running return immediately
[task 2021-04-21T17:26:24.444Z]  6:06.12             if check_process_status and runner is not None and not runner.is_running():
[task 2021-04-21T17:26:24.444Z]  6:06.12                 break
[task 2021-04-21T17:26:24.444Z]  6:06.12 
[task 2021-04-21T17:26:24.444Z]  6:06.12             try:
[task 2021-04-21T17:26:24.444Z]  6:06.12                 client.connect()
[task 2021-04-21T17:26:24.444Z]  6:06.12                 return True
[task 2021-04-21T17:26:24.444Z]  6:06.12             except socket.error:
[task 2021-04-21T17:26:24.444Z]  6:06.12                 pass
[task 2021-04-21T17:26:24.445Z]  6:06.12             finally:
[task 2021-04-21T17:26:24.445Z]  6:06.12                 client.close()
[task 2021-04-21T17:26:24.445Z]  6:06.12 
[task 2021-04-21T17:26:24.445Z]  6:06.12             time.sleep(poll_interval)
[task 2021-04-21T17:26:24.445Z]  6:06.12 
[task 2021-04-21T17:26:24.445Z]  6:06.12         if not connected:
[task 2021-04-21T17:26:24.445Z]  6:06.12             # There might have been a startup crash of the application
[task 2021-04-21T17:26:24.445Z]  6:06.12             if runner is not None and self.check_for_crash() > 0:
[task 2021-04-21T17:26:24.445Z]  6:06.12                 raise IOError("Process crashed (Exit code: {})".format(runner.wait(0)))
[task 2021-04-21T17:26:24.446Z]  6:06.12 
[task 2021-04-21T17:26:24.446Z]  6:06.12             raise socket.timeout(
[task 2021-04-21T17:26:24.446Z]  6:06.12                 "Timed out waiting for connection on {0}:{1}!".format(
[task 2021-04-21T17:26:24.446Z]  6:06.12 >                   self.host, self.port
[task 2021-04-21T17:26:24.446Z]  6:06.12                 )
[task 2021-04-21T17:26:24.446Z]  6:06.12             )
[task 2021-04-21T17:26:24.446Z]  6:06.12 E           socket.timeout: Timed out waiting for connection on 127.0.0.1:2828!
[task 2021-04-21T17:26:24.446Z]  6:06.12 
[task 2021-04-21T17:26:24.446Z]  6:06.12 testing/marionette/client/marionette_driver/marionette.py:598: timeout
[task 2021-04-21T17:26:24.446Z]  6:06.12 ----------------------------- Captured stdout call -----------------------------
[task 2021-04-21T17:26:24.447Z]  6:06.12 REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/fetches/firefox/llvm-symbolizer
[task 2021-04-21T17:26:24.447Z]  6:06.12 REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration
[task 2021-04-21T17:26:24.447Z]  6:06.12 REFTEST INFO | UBSan enabled.
[task 2021-04-21T17:26:24.447Z]  6:06.12 REFTEST INFO | Running with e10s: True
[task 2021-04-21T17:26:24.447Z]  6:06.12 REFTEST INFO | Running with fission: False
[task 2021-04-21T17:26:24.447Z]  6:06.12 REFTEST INFO | Application command: /builds/worker/fetches/firefox/firefox -marionette -profile /tmp/tmpjhej1pyu.mozrunner
[task 2021-04-21T17:26:24.447Z]  6:06.12 1619025626412	Marionette	INFO	Marionette enabled
[task 2021-04-21T17:26:24.448Z]  6:06.12 1619025626675	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-04-21T17:26:24.448Z]  6:06.12 console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpjhej1pyu.mozrunner/search.json.mozlz4", (void 0)))
[task 2021-04-21T17:26:24.448Z]  6:06.12 AddressSanitizer:DEADLYSIGNAL
[task 2021-04-21T17:26:24.448Z]  6:06.12 =================================================================
[task 2021-04-21T17:26:24.448Z]  6:06.12 ==195==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000001 (pc 0x7fb24ebb2f63 bp 0x7ffcfea8cd50 sp 0x7ffcfea8cd50 T0)
[task 2021-04-21T17:26:24.448Z]  6:06.12 ==195==The signal is caused by a WRITE memory access.
[task 2021-04-21T17:26:24.448Z]  6:06.12 ==195==Hint: address points to the zero page.
[task 2021-04-21T17:26:24.448Z]  6:06.12     #0 0x7fb24ebb2f63 in MOZ_Crash /builds/worker/workspace/obj-build/dist/include/mozilla/Assertions.h:246:3
[task 2021-04-21T17:26:24.448Z]  6:06.12     #1 0x7fb24ebb2f63 in RustMozCrash /builds/worker/checkouts/gecko/mozglue/static/rust/wrappers.cpp:17:3
[task 2021-04-21T17:26:24.449Z]  6:06.12     #2 0x7fb24be86947 in mozglue_static::panic_hook::h709fa1789bb182be /builds/worker/checkouts/gecko/mozglue/static/rust/lib.rs:89:9
[task 2021-04-21T17:26:24.449Z]  6:06.12     #3 0x7fb24be86695 in core::ops::function::Fn::call::h22798fbb74f65dca /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/ops/function.rs:70:5
[task 2021-04-21T17:26:24.449Z]  6:06.12     #4 0x7fb24c73bf2b in std::panicking::rust_panic_with_hook::h55d23fef0ad751bc /rustc/74f7e32f43b5fb0f83896d124566d8242eb786b1/library/std/src/panicking.rs:597:17
[task 2021-04-21T17:26:24.449Z]  6:06.12     #5 0x7fb24c757922 in std::panicking::begin_panic_handler::_$u7b$$u7b$closure$u7d$$u7d$::h56ae74c6dea6e141 /rustc/74f7e32f43b5fb0f83896d124566d8242eb786b1/library/std/src/panicking.rs
[task 2021-04-21T17:26:24.449Z]  6:06.12     #6 0x7fb24c75789b in std::sys_common::backtrace::__rust_end_short_backtrace::h3c4721f56689fae4 /rustc/74f7e32f43b5fb0f83896d124566d8242eb786b1/library/std/src/sys_common/backtrace.rs:141:18
[task 2021-04-21T17:26:24.449Z]  6:06.12     #7 0x7fb24c75784c in rust_begin_unwind /rustc/74f7e32f43b5fb0f83896d124566d8242eb786b1/library/std/src/panicking.rs:495:5
[task 2021-04-21T17:26:24.449Z]  6:06.12     #8 0x7fb24b114a8f in core::panicking::panic_fmt::hb15d6f55e8472f62 /rustc/74f7e32f43b5fb0f83896d124566d8242eb786b1/library/core/src/panicking.rs:92:14
[task 2021-04-21T17:26:24.449Z]  6:06.12     #9 0x7fb24b11be11 in core::option::expect_failed::h6bc6a05976f4cb88 /rustc/74f7e32f43b5fb0f83896d124566d8242eb786b1/library/core/src/option.rs:1260:5
[task 2021-04-21T17:26:24.450Z]  6:06.12     #10 0x7fb24badbdc5 in core::option::Option$LT$T$GT$::expect::h3d3e02b29798d9a0 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/option.rs:349:21
[task 2021-04-21T17:26:24.450Z]  6:06.12     #11 0x7fb24badbdc5 in glean::with_glean_mut::h60f858a7959c91b4 /builds/worker/checkouts/gecko/third_party/rust/glean/src/lib.rs:149:17
[task 2021-04-21T17:26:24.450Z]  6:06.12     #12 0x7fb24badbdc5 in glean::set_source_tags::hf91f9a52de48a0e8 /builds/worker/checkouts/gecko/third_party/rust/glean/src/lib.rs:753:9
[task 2021-04-21T17:26:24.450Z]  6:06.12     #13 0x7fb24b46764c in fog_init /builds/worker/checkouts/gecko/toolkit/components/glean/src/lib.rs:156:9
[task 2021-04-21T17:26:24.450Z]  6:06.12     #14 0x7fb23ed8e581 in NS_InvokeByIndex /builds/worker/checkouts/gecko/xpcom/reflect/xptcall/md/unix/xptcinvoke_asm_x86_64_unix.S:101
[task 2021-04-21T17:26:24.450Z]  6:06.12     #15 0x7fb24074c05a in Invoke /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1623:10
[task 2021-04-21T17:26:24.450Z]  6:06.12     #16 0x7fb24074c05a in Call /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1176:19
[task 2021-04-21T17:26:24.451Z]  6:06.12     #17 0x7fb24074c05a in XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1142:23
[task 2021-04-21T17:26:24.451Z]  6:06.12     #18 0x7fb240751089 in XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:925:10
[task 2021-04-21T17:26:24.451Z]  6:06.12     #19 0x7fb249742904 in CallJSNative /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:437:13
[task 2021-04-21T17:26:24.451Z]  6:06.12     #20 0x7fb249742904 in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:522:12
[task 2021-04-21T17:26:24.451Z]  6:06.12     #21 0x7fb249744729 in InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:582:10
[task 2021-04-21T17:26:24.451Z]  6:06.12     #22 0x7fb24972e010 in CallFromStack /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:586:10
[task 2021-04-21T17:26:24.452Z]  6:06.12     #23 0x7fb24972e010 in Interpret(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:3248:16
[task 2021-04-21T17:26:24.452Z]  6:06.12     #24 0x7fb2497123de in js::RunScript(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:406:13
[task 2021-04-21T17:26:24.452Z]  6:06.12     #25 0x7fb249742a43 in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:554:13
[task 2021-04-21T17:26:24.452Z]  6:06.12     #26 0x7fb249744729 in InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:582:10
[task 2021-04-21T17:26:24.452Z]  6:06.12     #27 0x7fb2497449ab in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:599:8
[task 2021-04-21T17:26:24.452Z]  6:06.12     #28 0x7fb24a56270b in js::jit::InvokeFunction(JSContext*, JS::Handle<JSObject*>, bool, bool, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/jit/VMFunctions.cpp:760:10
[task 2021-04-21T17:26:24.452Z]  6:06.12     #29 0x7fb24a5631d2 in js::jit::InvokeFromInterpreterStub(JSContext*, js::jit::InterpreterStubExitFrameLayout*) /builds/worker/checkouts/gecko/js/src/jit/VMFunctions.cpp:784:8
[task 2021-04-21T17:26:24.453Z]  6:06.12     #30 0x7fb1a04ecdf3  (<unknown module>)
[task 2021-04-21T17:26:24.453Z]  6:06.12 AddressSanitizer can not provide additional info.
[task 2021-04-21T17:26:24.453Z]  6:06.12 SUMMARY: AddressSanitizer: SEGV /builds/worker/workspace/obj-build/dist/include/mozilla/Assertions.h:246:3 in MOZ_Crash```

Chris, could you have a look over this? Treeherder backfills.

Flags: needinfo?(chutten)

The stack sure looks like me.

Calling set_source_tags should be safe no matter when it's called, though. Jan-Erik: ideas?

Interesting that expect_failed didn't panic with the message we passed to expect: Global Glean object not initialized

Lemme see if I can reproduce this locally.

Flags: needinfo?(chutten) → needinfo?(jrediger)

I'll take the fix for this race condition to the original bug 1672455 since the patches were backed out. If that's not okay, please reopen.

Status: NEW → RESOLVED
Closed: 4 years ago
Flags: needinfo?(jrediger)
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.