1769544 - Perma py3 ref layout/tools/reftest/selftest/test_reftest_output.py::test_output_crash TEST-UNEXPECTED-FAIL

Status: RESOLVED FIXED

(Testing :: Reftest, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=378204962&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f03AykANQRybH_tIyPJoHA/runs/1/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/f03AykANQRybH_tIyPJoHA/runs/1/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2022-05-16T12:45:15.574Z] layout/tools/reftest/selftest/test_reftest_manifest_parser.py::test_parse_invalid_manifests PASSED
[task 2022-05-16T12:45:15.574Z] 
[task 2022-05-16T12:45:15.574Z] =============================== warnings summary ===============================
[task 2022-05-16T12:45:15.574Z] testing/mozbase/mozinstall/mozinstall/mozinstall.py:233
[task 2022-05-16T12:45:15.574Z]   /builds/worker/checkouts/gecko/testing/mozbase/mozinstall/mozinstall/mozinstall.py:233: DeprecationWarning: invalid escape sequence \h
[task 2022-05-16T12:45:15.574Z]     cmdArgs = ["%s\\uninstall\helper.exe" % install_folder, "/S"]
[task 2022-05-16T12:45:15.574Z] 
[task 2022-05-16T12:45:15.574Z] layout/tools/reftest/selftest/test_reftest_manifest_parser.py::test_parse_test_types
[task 2022-05-16T12:45:15.574Z]   /builds/worker/fetches/tests/bin/fix_stacks.py:20: DeprecationWarning: invalid escape sequence \d
[task 2022-05-16T12:45:15.574Z]     line_re = re.compile("#\d+: .+\[.+ \+0x[0-9A-Fa-f]+\]")
[task 2022-05-16T12:45:15.574Z] 
[task 2022-05-16T12:45:15.574Z] -- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
[task 2022-05-16T12:45:15.575Z] =================== 3 passed, 2 warnings in 83.58s (0:01:23) ===================
[task 2022-05-16T12:45:15.575Z] 
[task 2022-05-16T12:45:15.575Z] 
[task 2022-05-16T12:47:15.280Z] Tests Completed:  67%|██████▋   | 2/3 [01:25<00:50, 50.02s/Test]
[task 2022-05-16T12:47:15.280Z]                                                                 
[task 2022-05-16T12:47:15.281Z] Setting retcode to 1 from /builds/worker/checkouts/gecko/layout/tools/reftest/selftest/test_reftest_output.py
[task 2022-05-16T12:47:15.281Z] 
[task 2022-05-16T12:47:15.281Z] Tests Completed: 100%|██████████| 3/3 [03:25<00:00, 81.84s/Test]
[task 2022-05-16T12:47:15.281Z]                                                                 
[task 2022-05-16T12:47:15.281Z] /builds/worker/checkouts/gecko/layout/tools/reftest/selftest/test_reftest_output.py
[task 2022-05-16T12:47:15.281Z] ============================= test session starts ==============================
[task 2022-05-16T12:47:15.281Z] platform linux -- Python 3.6.9, pytest-7.0.1, pluggy-1.0.0 -- /builds/worker/checkouts/gecko/obj-x86_64-pc-linux-gnu/_virtualenvs/python-test/bin/python
[task 2022-05-16T12:47:15.281Z] rootdir: /builds/worker/checkouts/gecko, configfile: config/mozunit/mozunit/pytest.ini
[task 2022-05-16T12:47:15.281Z] collecting ... collected 6 items
[task 2022-05-16T12:47:15.281Z] 
[task 2022-05-16T12:47:15.281Z] layout/tools/reftest/selftest/test_reftest_output.py::test_output_pass PASSED
[task 2022-05-16T12:47:15.281Z] layout/tools/reftest/selftest/test_reftest_output.py::test_output_fail PASSED
[task 2022-05-16T12:47:15.281Z] layout/tools/reftest/selftest/test_reftest_output.py::test_output_crash TEST-UNEXPECTED-FAIL
[task 2022-05-16T12:47:15.281Z] layout/tools/reftest/selftest/test_reftest_output.py::test_output_asan SKIPPED
[task 2022-05-16T12:47:15.282Z] layout/tools/reftest/selftest/test_reftest_output.py::test_output_assertion PASSED
[task 2022-05-16T12:47:15.282Z] layout/tools/reftest/selftest/test_reftest_output.py::test_output_leak PASSED
[task 2022-05-16T12:47:15.282Z] 
[task 2022-05-16T12:47:15.282Z] =================================== FAILURES ===================================
[task 2022-05-16T12:47:15.282Z] ______________________________ test_output_crash _______________________________
[task 2022-05-16T12:47:15.282Z] layout/tools/reftest/selftest/test_reftest_output.py:79: in test_output_crash
[task 2022-05-16T12:47:15.282Z]     assert status == 1
[task 2022-05-16T12:47:15.282Z] E   assert 245 == 1
[task 2022-05-16T12:47:15.282Z] E     +245
[task 2022-05-16T12:47:15.283Z] E     -1
[task 2022-05-16T12:47:15.283Z] ----------------------------- Captured stdout call -----------------------------
[task 2022-05-16T12:47:15.283Z] REFTEST INFO | Running with e10s: True
[task 2022-05-16T12:47:15.283Z] REFTEST INFO | Running with fission: True
[task 2022-05-16T12:47:15.283Z] REFTEST INFO | Application command: /builds/worker/fetches/firefox/firefox -marionette -profile /tmp/tmpsm7_zv87.mozrunner
[task 2022-05-16T12:47:15.283Z] ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpsm7_zv87.mozrunner/runreftest_leaks.log
[task 2022-05-16T12:47:15.283Z] [2800, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-05-16T12:47:15.283Z] [2022-05-16T12:46:05Z WARN  rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
[task 2022-05-16T12:47:15.283Z] ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpsm7_zv87.mozrunner/runreftest_leaks_socket_pid2838.log
[task 2022-05-16T12:47:15.283Z] [2838, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-05-16T12:47:15.283Z] [Socket 2838, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpHandler.cpp:339
[task 2022-05-16T12:47:15.283Z] [Socket 2838, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002 (NS_NOINTERFACE): file /builds/worker/checkouts/gecko/toolkit/components/resistfingerprinting/nsRFPService.cpp:560
[task 2022-05-16T12:47:15.283Z] [Parent 2800, Main Thread] WARNING: GLX_swap_control unsupported, ASAP mode may still block on buffer swaps.: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderGLX.cpp:214
[task 2022-05-16T12:47:15.283Z] 1652705166137	Marionette	INFO	Marionette enabled
[task 2022-05-16T12:47:15.283Z] 1652705166141	Marionette	TRACE	Received observer notification final-ui-startup
[task 2022-05-16T12:47:15.283Z] 1652705166145	Marionette	INFO	Listening on port 2828
[task 2022-05-16T12:47:15.284Z] 1652705166145	Marionette	DEBUG	Marionette is listening
[task 2022-05-16T12:47:15.284Z] [Parent 2800, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/layout/style/Loader.cpp:2039
[task 2022-05-16T12:47:15.284Z] 1652705166404	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:39282
[task 2022-05-16T12:47:15.284Z] 1652705166535	Marionette	DEBUG	Closed connection 0
[task 2022-05-16T12:47:15.284Z] 1652705166536	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:39284
[task 2022-05-16T12:47:15.284Z] 1652705167005	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-05-16T12:47:15.284Z] 1652705167014	Marionette	DEBUG	Waiting for initial application window
[task 2022-05-16T12:47:15.284Z] [Parent 2800, GMPThread] WARNING: Failed to delete GMP storage directory: file /builds/worker/checkouts/gecko/dom/media/gmp/GMPServiceParent.cpp:1754
[task 2022-05-16T12:47:15.284Z] ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpsm7_zv87.mozrunner/runreftest_leaks_tab_pid2884.log
[task 2022-05-16T12:47:15.284Z] [2884, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-05-16T12:47:15.284Z] [Child 2884, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:693
[task 2022-05-16T12:47:15.286Z] [Child 2884, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/layout/style/Loader.cpp:2039
[task 2022-05-16T12:47:15.286Z] [Child 2884, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2807
[task 2022-05-16T12:47:15.286Z] [Child 2884, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2807
[task 2022-05-16T12:47:15.286Z] [Child 2884, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2807
[task 2022-05-16T12:47:15.286Z] [Child 2884, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2807
[task 2022-05-16T12:47:15.286Z] [Child 2884, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2807
[task 2022-05-16T12:47:15.286Z] [GLX] window 20002c has VisualID 0x41
[task 2022-05-16T12:47:15.286Z] GL_VENDOR: VMware, Inc.
[task 2022-05-16T12:47:15.286Z] mVendor: VMware, Inc.
[task 2022-05-16T12:47:15.286Z] GL_RENDERER: llvmpipe (LLVM 10.0.0, 128 bits)
[task 2022-05-16T12:47:15.286Z] mRenderer: Unknown
[task 2022-05-16T12:47:15.286Z] mIsMesa: 1
[task 2022-05-16T12:47:15.286Z] [Parent 2800, Renderer] WARNING: robust_buffer_access_behavior marked as unsupported: file /builds/worker/checkouts/gecko/gfx/gl/GLContextFeatures.cpp:632

Comment 1

[Norisz Fay [:noriszfay]]

Hello Joel, could you take a look at this failure? It started appearing on this push and it might be caused by Bug 1762991 as the last test-run was 10th of May. Thank you!

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1762991

Comment 3

[Iulian Moraru]

Backfill range - just the push where it failed and the push where the job passed.

Hi Henrik! This is also related to the changes from Bug 1370520 . Can you please take a look at this too?
Thank you!

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

the error code is coming from :whimboo's change, I did fiddle with timeoutAsPass variable, which I thought affected this, but looking into the test it is a crash scenario and locally I wasn't able to reproduce the failure- I am ok with just changing the testcase to have the assert status == 245 now.

Comment 5

[Intermittent Failures Robot]

17 failures in 575 pushes (0.03 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 15
• mozilla-central: 2

Platform and build breakdown:

• linux1804-64: 16
  • debug: 14
  • opt: 2
• linux1804-64-asan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1769544&startday=2022-05-16&endday=2022-05-16&tree=all

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+1]]

(In reply to Joel Maher ( :jmaher ) (UTC -0800) from comment #4)

the error code is coming from :whimboo's change, I did fiddle with timeoutAsPass variable, which I thought affected this, but looking into the test it is a crash scenario and locally I wasn't able to reproduce the failure- I am ok with just changing the testcase to have the assert status == 245 now.

The problem is the following... Formerly such a crash caused a forced shutdown with an exit code of 0. It means the browser normally shutdown. But then the harness detected the minidump files and as such noticed a crash, which most likely caused it to change the status to 1. But now using an exit code that is not 0 it will just be passed-through. So changing the status to 245 should be the right fix, yes.

Sorry that this was missed. mach try auto didn't do well here and missed this specific test job.

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Attachment: Bug 1769544 - Fix layout/tools/reftest/selftest/test_reftest_output.py for the new exit code of a forced shutdown as caused by MOZ_CRASHREPORTER_SHUTDOWN.

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/39ded09a9c01
Fix layout/tools/reftest/selftest/test_reftest_output.py for the new exit code of a forced shutdown as caused by MOZ_CRASHREPORTER_SHUTDOWN. r=jmaher

Comment 9

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/39ded09a9c01

Comment 10

[Intermittent Failures Robot]

17 failures in 2694 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 15
• mozilla-central: 2

Platform and build breakdown:

• linux1804-64: 16
  • debug: 14
  • opt: 2
• linux1804-64-asan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1769544&startday=2022-05-16&endday=2022-05-22&tree=all