Found while fuzzing with m-c 20210318-a96c49a026f6 (--enable-debug)

Hit MOZ_CRASH(called Option::unwrap() on a None value) at /builds/worker/checkouts/gecko/third_party/rust/euclid/src/size.rs:285 (e5aa1b7f:347b34b9)

#0 0x7fd20e03aca5 in MOZ_Crash /builds/worker/workspace/obj-build/dist/include/mozilla/Assertions.h:254:3
#1 0x7fd20e03aca5 in RustMozCrash src/mozglue/static/rust/wrappers.cpp:17:3
#2 0x7fd20e03ac54 in mozglue_static::panic_hook::h52aa0e5c41eb49de src/mozglue/static/rust/lib.rs:89:9
#3 0x7fd20e03a62b in core::ops::function::Fn::call::h45fce903fef90bf4 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/ops/function.rs:70:5
#4 0x7fd20f053085 in std::panicking::rust_panic_with_hook::hb27ea14285131c61 /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:595:17
#5 0x7fd20f052b76 in std::panicking::begin_panic_handler::_$u7b$$u7b$closure$u7d$$u7d$::hc552fcee62aad17f /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:495:13
#6 0x7fd20f04efcb in std::sys_common::backtrace::__rust_end_short_backtrace::hb9f0aa9a78e885a0 /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys_common/backtrace.rs:141:18
#7 0x7fd20f052b08 in rust_begin_unwind /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/panicking.rs:493:5
#8 0x7fd20f0bc2d0 in core::panicking::panic_fmt::h12ac4570ea43d06f /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/panicking.rs:92:14
#9 0x7fd20f0bc21c in core::panicking::panic::h72bd72f6f4a70105 /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/core/src/panicking.rs:50:5
#10 0x7fd20d7fd755 in webrender::picture::PicturePrimitive::take_context::h1bff7ab7dd44e572 src/gfx/wr/webrender/src/picture.rs
#11 0x7fd20d80b1c5 in webrender::prepare::prepare_prim_for_render::hcef705fef2e19b0d src/gfx/wr/webrender/src/prepare.rs:173:15
#12 0x7fd20d80b1c5 in webrender::prepare::prepare_primitives::h30480fd0f11d2ed9 src/gfx/wr/webrender/src/prepare.rs:119:16
#13 0x7fd20d7ad994 in webrender::frame_builder::FrameBuilder::build_layer_screen_rects_and_cull_layers::hbd196e0a355fa892 src/gfx/wr/webrender/src/frame_builder.rs:480:17
#14 0x7fd20d7ad994 in webrender::frame_builder::FrameBuilder::build::hbbf24da9aab9928a src/gfx/wr/webrender/src/frame_builder.rs:572:9
#15 0x7fd20d83451e in webrender::render_backend::Document::build_frame::h35cee1820359000b src/gfx/wr/webrender/src/render_backend.rs:622:25
#16 0x7fd20d84546b in webrender::render_backend::RenderBackend::update_document::hb327ca0df4994300 src/gfx/wr/webrender/src/render_backend.rs:1508:41
#17 0x7fd20d83b806 in webrender::render_backend::RenderBackend::prepare_transactions::h3253b83741782ded src/gfx/wr/webrender/src/render_backend.rs:1362:28
#18 0x7fd20d83b806 in webrender::render_backend::RenderBackend::process_api_msg::h669825647dd68f81 src/gfx/wr/webrender/src/render_backend.rs:1218:17
#19 0x7fd20d62845d in webrender::render_backend::RenderBackend::run::h9d404f4f82ce9be5 src/gfx/wr/webrender/src/render_backend.rs:894:21
#20 0x7fd20d62845d in webrender::renderer::Renderer::new::_$u7b$$u7b$closure$u7d$$u7d$::h0287ea296518ff7c src/gfx/wr/webrender/src/renderer/mod.rs:1281:13
#21 0x7fd20d62845d in std::sys_common::backtrace::__rust_begin_short_backtrace::h1e021cc148337dd0 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:125:18
#22 0x7fd20d64a559 in std::thread::Builder::spawn_unchecked::_$u7b$$u7b$closure$u7d$$u7d$::_$u7b$$u7b$closure$u7d$$u7d$::h692c75054f207650 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:474:17
#23 0x7fd20d64a559 in _$LT$std..panic..AssertUnwindSafe$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$$LP$$RP$$GT$$GT$::call_once::h6eeba4835c596917 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panic.rs:322:9
#24 0x7fd20d64a559 in std::panicking::try::do_call::hfbc785d5d54f4d36 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panicking.rs:379:40
#25 0x7fd20d64a559 in std::panicking::try::h79a89e99f34dc379 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panicking.rs:343:19
#26 0x7fd20d64a559 in std::panic::catch_unwind::hd62f3d38488be536 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panic.rs:396:14
#27 0x7fd20d64a559 in std::thread::Builder::spawn_unchecked::_$u7b$$u7b$closure$u7d$$u7d$::h586ce072699f6516 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:473:30
#28 0x7fd20d64a559 in core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::hf4220e17974a62de /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/ops/function.rs:227:5
#29 0x7fd20f063499 in _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::h9ed215ba67984d70 /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/alloc/src/boxed.rs:1328:9
#30 0x7fd20f063499 in _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::hcece06e1fe04906f /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/alloc/src/boxed.rs:1328:9
#31 0x7fd20f063499 in std::sys::unix::thread::Thread::new::thread_start::h6e82a4b7be15319a /rustc/cb75ad5db02783e8b0222fee363c5f63f7e2cf5b/library/std/src/sys/unix/thread.rs:71:17
#32 0x7fd21cd9b608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477:8
#33 0x7fd21c964292 in clone /build/glibc-eX1tMB/glibc-2.31/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bugmon Analysis:
Verified bug as reproducible on mozilla-central 20210319215733-e8ee87ef82c3.
Failed to bisect testcase (Unable to launch the start build!):

Start: bbb78f71a5de9849f6697da61a062f59ec960f97 (20200321035946)
End: a96c49a026f646c041c781789de2b781b27cfe7c (20210318213531)
BuildFlags: BuildFlags(asan=False, tsan=False, debug=True, fuzzing=False, coverage=False, valgrind=False)

A Pernosco session is available here: https://pernos.co/debug/PxyLIUGmsLpFr5-GyG31Zg/index.html

This is easily reproduced by visiting the test case:

https://crash-stats.mozilla.org/report/index/f8ec9847-0423-48fd-869d-fe4770210325

Part of bug 1684781 perhaps?

Doesn't seem to repro on my local setup, and the pernosco session is unfortunately not helpful here as the code in question is all inlined and so the callstack doesn't identify the caller.

Glenn, I am able to repro on my local setup (Ubuntu 20.04) with Grizzly replay using a debug build (m-c 20210325-2da6d806f457).

To install Grizzly:

python3 -m pip install grizzly-framework

To repro with the attached test case and prefs.js files:

python3 -m grizzly.replay <build_path>/firefox testcase.html --repeat 10 --relaunch 1 --xvfb -p prefs.js

Note: --xvfb isn't required for me but it does make the execution a bit more consistent.

Does that help?

This is the output I get when I run that command:

[2021-03-29 07:44:51] Starting Grizzly Replay
[2021-03-29 07:44:51] Ignoring: timeout, log-limit
[2021-03-29 07:44:51] Running with Xvfb
[2021-03-29 07:44:51] Using time limit: 30s, timeout: 45s
[2021-03-29 07:44:51] Repeat: 10, Minimum crashes: 1, Relaunch 1
[2021-03-29 07:44:51] Using specified prefs.js
[2021-03-29 07:45:15] Running test (1/10)...
[2021-03-29 07:46:01] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:46:01] Result: Ignored (1)
[2021-03-29 07:46:23] Running test (2/10)...
[2021-03-29 07:47:09] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:47:09] Result: Ignored (2)
[2021-03-29 07:47:30] Running test (3/10)...
[2021-03-29 07:48:16] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:48:16] Result: Ignored (3)
[2021-03-29 07:48:37] Running test (4/10)...
[2021-03-29 07:49:24] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:49:24] Result: Ignored (4)
[2021-03-29 07:49:46] Running test (5/10)...
[2021-03-29 07:50:32] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:50:32] Result: Ignored (5)
[2021-03-29 07:50:53] Running test (6/10)...
[2021-03-29 07:51:39] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:51:39] Result: Ignored (6)
[2021-03-29 07:52:01] Running test (7/10)...
[2021-03-29 07:52:47] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:52:47] Result: Ignored (7)
[2021-03-29 07:53:09] Running test (8/10)...
[2021-03-29 07:53:55] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:53:55] Result: Ignored (8)
[2021-03-29 07:54:16] Running test (9/10)...
[2021-03-29 07:55:02] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:55:02] Result: Ignored (9)
[2021-03-29 07:55:23] Running test (10/10)...
[2021-03-29 07:56:09] symbols_path not found: '/home/code/work/gecko4/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2021-03-29 07:56:09] Result: Ignored (10)
[2021-03-29 07:56:09] Failed to reproduce results
[2021-03-29 07:56:09] Shutting down...
[2021-03-29 07:56:09] Done.

I ran it many times both with and without the --xvfb option. It's definitely a full debug build, I'm not sure if the log related to symbols not being found might be relevant. Are there are only options I could try to repro locally?

Hmm that's interesting, let me side track a little bit here...

The symbols_path not found msg means a minidump was found but the Result: Ignored and time diff indicate a timeout occurred.

So we should see one or the other, not both. This pointed out a bug in our tools and I fixed it this morning. OTOH it should still not have hung, so I'm not sure what's up with that but hopefully this fixes it.

Would you mind trying again with the latest FFuppet (0.7.7)? pip install ffpuppet --upgrade should do what you need. Adding --log-level DEBUG to the grizzly.replay command would also be helpful in case there are more bugs in our tools.

Now back to the bug we are trying to catch.

I tested again this morning with the latest fuzzing debug build and triggered it first try. I was also able to reproduce on an 18.04 machine. I even triggered it with a m-c opt build.

If you have a patch I'd be happy to run it or I can get an updated Pernosco session. I am building with -O0 to avoid in-lining, any ideas why that would be happening?

Output from doing the update and adding debug logging, still doesn't seem to repro for me, which is very odd. I tried with an opt / debug / debug no-inlining build. Is there anything else obvious I might be missing? Could it be related to screen resolution or device-pixel scaling ratio perhaps?

gw@amd:~/code/work/gecko3$ python3 -m grizzly.replay obj-x86_64-pc-linux-gnu/dist/bin/firefox ~/Downloads/testcase.html --repeat 10 --relaunch 1 --log-level DEBUG --xvfb -p ~/Downloads/prefs.js
2021-03-31 08:44:12,051 I grizzly.replay.replay | Starting Grizzly Replay
2021-03-31 08:44:12,051 I grizzly.replay.replay | Ignoring: log-limit, timeout
2021-03-31 08:44:12,051 I grizzly.replay.replay | Running with Xvfb
2021-03-31 08:44:12,051 D grizzly.replay.replay | loading the TestCases
2021-03-31 08:44:12,051 I grizzly.replay.replay | Using time limit: 30s, timeout: 45s
2021-03-31 08:44:12,051 I grizzly.replay.replay | Repeat: 10, Minimum crashes: 1, Relaunch 1
2021-03-31 08:44:12,051 D grizzly.replay.replay | initializing the Target
2021-03-31 08:44:12,154 I grizzly.replay.replay | Using specified prefs.js
2021-03-31 08:44:12,154 D grizzly.replay.replay | starting sapphire server
2021-03-31 08:44:12,155 D sapphire.server_map | mapping dynamic response 'grz_harness' -> <function ReplayManager.run.<locals>.<lambda> at 0x7f976da134c0> ('text/html')
2021-03-31 08:44:12,155 D grizzly.replay.replay | unpacking testcases (1)...
2021-03-31 08:44:12,155 D sapphire.core | clearing socket backlog
2021-03-31 08:44:12,155 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:44:12,155 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:44:12,156 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:44:12,156 D ffpuppet.core | using profile '/tmp/ffprof_1yqss1s2'
2021-03-31 08:44:12,156 D ffpuppet.core | launch timeout: 300
2021-03-31 08:44:12,156 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_1yqss1s2 http://127.0.0.1:57262'
2021-03-31 08:44:12,158 D ffpuppet.core | launched process 1667421
2021-03-31 08:44:12,158 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:44:13,747 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:44:13,825 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:44:13,826 D ffpuppet.bootstrapper | bootstrap complete (1.67s)
2021-03-31 08:44:13,826 I grizzly.replay.replay | Running test (1/10)...
2021-03-31 08:44:13,826 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976da13550> ('application/octet-stream')
2021-03-31 08:44:13,826 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:44:13,827 D sapphire.job | required: 'testcase.html'
2021-03-31 08:44:13,827 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:44:13,827 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:44:13,827 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976da13550>
2021-03-31 08:44:13,827 D sapphire.job | 3 files required to serve
2021-03-31 08:44:13,827 D sapphire.connection_manager | starting listener
2021-03-31 08:44:13,991 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:44:13,992 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:44:14,331 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:44:14,331 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:44:14,346 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:44:14,348 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:44:14,348 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:44:14,348 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:44:44,657 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:44:44,657 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:44:44,659 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:44:44,660 D sapphire.worker | expecting to finish
2021-03-31 08:44:44,660 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:44:44,709 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:44:44,710 D sapphire.core | status: 0, timeout: False
2021-03-31 08:44:44,710 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:44:45,712 D ffpuppet.core | is_running() returned False
2021-03-31 08:44:45,712 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:44:45,712 D ffpuppet.core | browser pid: 1667421, 0 proc(s)
2021-03-31 08:44:45,712 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:44:45,712 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_1yqss1s2/minidumps' did not contain '.dmp' files
2021-03-31 08:44:45,718 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:44:45,718 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:44:45,718 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:44:45,718 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:44:45,718 D sapphire.core | clearing socket backlog
2021-03-31 08:44:45,718 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:44:45,719 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:44:45,719 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:44:45,719 D ffpuppet.core | using profile '/tmp/ffprof_p5cl6e2h'
2021-03-31 08:44:45,719 D ffpuppet.core | launch timeout: 300
2021-03-31 08:44:45,720 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_p5cl6e2h http://127.0.0.1:54396'
2021-03-31 08:44:45,722 D ffpuppet.core | launched process 1667889
2021-03-31 08:44:45,722 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:44:47,290 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:44:47,364 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:44:47,364 D ffpuppet.bootstrapper | bootstrap complete (1.64s)
2021-03-31 08:44:47,364 I grizzly.replay.replay | Running test (2/10)...
2021-03-31 08:44:47,365 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:44:47,365 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:44:47,365 D sapphire.job | required: 'testcase.html'
2021-03-31 08:44:47,365 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:44:47,365 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:44:47,365 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:44:47,366 D sapphire.job | 3 files required to serve
2021-03-31 08:44:47,366 D sapphire.connection_manager | starting listener
2021-03-31 08:44:47,523 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:44:47,523 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:44:47,854 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:44:47,854 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:44:47,871 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:44:47,871 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:44:47,872 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:44:47,872 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:45:18,194 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:45:18,194 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:45:18,197 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:45:18,197 D sapphire.worker | expecting to finish
2021-03-31 08:45:18,197 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:45:18,247 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:45:18,247 D sapphire.core | status: 0, timeout: False
2021-03-31 08:45:18,247 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:45:19,249 D ffpuppet.core | is_running() returned False
2021-03-31 08:45:19,249 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:45:19,249 D ffpuppet.core | browser pid: 1667889, 0 proc(s)
2021-03-31 08:45:19,249 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:45:19,250 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_p5cl6e2h/minidumps' did not contain '.dmp' files
2021-03-31 08:45:19,255 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:45:19,256 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:45:19,256 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:45:19,256 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:45:19,256 D sapphire.core | clearing socket backlog
2021-03-31 08:45:19,256 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:45:19,256 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:45:19,256 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:45:19,256 D ffpuppet.core | using profile '/tmp/ffprof_a80q2ng4'
2021-03-31 08:45:19,256 D ffpuppet.core | launch timeout: 300
2021-03-31 08:45:19,257 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_a80q2ng4 http://127.0.0.1:8915'
2021-03-31 08:45:19,259 D ffpuppet.core | launched process 1668349
2021-03-31 08:45:19,260 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:45:20,821 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:45:20,893 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:45:20,893 D ffpuppet.bootstrapper | bootstrap complete (1.63s)
2021-03-31 08:45:20,893 I grizzly.replay.replay | Running test (3/10)...
2021-03-31 08:45:20,893 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:45:20,893 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:45:20,894 D sapphire.job | required: 'testcase.html'
2021-03-31 08:45:20,894 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:45:20,894 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:45:20,894 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:45:20,894 D sapphire.job | 3 files required to serve
2021-03-31 08:45:20,894 D sapphire.connection_manager | starting listener
2021-03-31 08:45:21,045 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:45:21,045 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:45:21,425 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:45:21,425 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:45:21,439 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:45:21,439 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:45:21,440 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:45:21,440 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:45:51,759 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:45:51,760 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:45:51,762 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:45:51,762 D sapphire.worker | expecting to finish
2021-03-31 08:45:51,762 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:45:51,812 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:45:51,813 D sapphire.core | status: 0, timeout: False
2021-03-31 08:45:51,813 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:45:52,815 D ffpuppet.core | is_running() returned False
2021-03-31 08:45:52,815 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:45:52,815 D ffpuppet.core | browser pid: 1668349, 0 proc(s)
2021-03-31 08:45:52,815 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:45:52,815 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_a80q2ng4/minidumps' did not contain '.dmp' files
2021-03-31 08:45:52,821 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:45:52,821 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:45:52,821 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:45:52,821 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:45:52,821 D sapphire.core | clearing socket backlog
2021-03-31 08:45:52,821 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:45:52,821 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:45:52,822 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:45:52,822 D ffpuppet.core | using profile '/tmp/ffprof_135j8i5c'
2021-03-31 08:45:52,822 D ffpuppet.core | launch timeout: 300
2021-03-31 08:45:52,822 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_135j8i5c http://127.0.0.1:54859'
2021-03-31 08:45:52,825 D ffpuppet.core | launched process 1668838
2021-03-31 08:45:52,825 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:45:54,496 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:45:54,560 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:45:54,561 D ffpuppet.bootstrapper | bootstrap complete (1.74s)
2021-03-31 08:45:54,561 I grizzly.replay.replay | Running test (4/10)...
2021-03-31 08:45:54,561 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:45:54,561 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:45:54,561 D sapphire.job | required: 'testcase.html'
2021-03-31 08:45:54,561 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:45:54,562 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:45:54,562 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:45:54,562 D sapphire.job | 3 files required to serve
2021-03-31 08:45:54,562 D sapphire.connection_manager | starting listener
2021-03-31 08:45:54,705 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:45:54,706 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:45:55,052 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:45:55,052 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:45:55,074 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:45:55,074 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:45:55,074 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:45:55,074 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:46:25,384 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:46:25,384 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:46:25,386 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:46:25,386 D sapphire.worker | expecting to finish
2021-03-31 08:46:25,386 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:46:25,436 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:46:25,437 D sapphire.core | status: 0, timeout: False
2021-03-31 08:46:25,437 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:46:26,438 D ffpuppet.core | is_running() returned False
2021-03-31 08:46:26,439 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:46:26,439 D ffpuppet.core | browser pid: 1668838, 0 proc(s)
2021-03-31 08:46:26,439 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:46:26,439 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_135j8i5c/minidumps' did not contain '.dmp' files
2021-03-31 08:46:26,445 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:46:26,445 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:46:26,445 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:46:26,445 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:46:26,445 D sapphire.core | clearing socket backlog
2021-03-31 08:46:26,446 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:46:26,446 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:46:26,446 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:46:26,446 D ffpuppet.core | using profile '/tmp/ffprof_27ccqkmd'
2021-03-31 08:46:26,446 D ffpuppet.core | launch timeout: 300
2021-03-31 08:46:26,447 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_27ccqkmd http://127.0.0.1:36819'
2021-03-31 08:46:26,450 D ffpuppet.core | launched process 1669292
2021-03-31 08:46:26,450 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:46:28,029 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:46:28,087 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:46:28,088 D ffpuppet.bootstrapper | bootstrap complete (1.64s)
2021-03-31 08:46:28,088 I grizzly.replay.replay | Running test (5/10)...
2021-03-31 08:46:28,088 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:46:28,088 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:46:28,088 D sapphire.job | required: 'testcase.html'
2021-03-31 08:46:28,088 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:46:28,088 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:46:28,088 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:46:28,088 D sapphire.job | 3 files required to serve
2021-03-31 08:46:28,089 D sapphire.connection_manager | starting listener
2021-03-31 08:46:28,235 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:46:28,235 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:46:28,647 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:46:28,647 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:46:28,659 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:46:28,659 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:46:28,660 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:46:28,660 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:46:58,930 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:46:58,930 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:46:58,933 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:46:58,933 D sapphire.worker | expecting to finish
2021-03-31 08:46:58,933 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:46:58,983 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:46:58,983 D sapphire.core | status: 0, timeout: False
2021-03-31 08:46:58,983 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:46:59,985 D ffpuppet.core | is_running() returned False
2021-03-31 08:46:59,985 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:46:59,985 D ffpuppet.core | browser pid: 1669292, 0 proc(s)
2021-03-31 08:46:59,985 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:46:59,986 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_27ccqkmd/minidumps' did not contain '.dmp' files
2021-03-31 08:46:59,991 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:46:59,992 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:46:59,992 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:46:59,992 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:46:59,992 D sapphire.core | clearing socket backlog
2021-03-31 08:46:59,992 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:46:59,992 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:46:59,992 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:46:59,992 D ffpuppet.core | using profile '/tmp/ffprof_k9osdkro'
2021-03-31 08:46:59,992 D ffpuppet.core | launch timeout: 300
2021-03-31 08:46:59,993 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_k9osdkro http://127.0.0.1:40803'
2021-03-31 08:46:59,995 D ffpuppet.core | launched process 1669753
2021-03-31 08:46:59,996 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:47:01,570 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:47:01,646 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:47:01,646 D ffpuppet.bootstrapper | bootstrap complete (1.65s)
2021-03-31 08:47:01,647 I grizzly.replay.replay | Running test (6/10)...
2021-03-31 08:47:01,647 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:47:01,647 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:47:01,647 D sapphire.job | required: 'testcase.html'
2021-03-31 08:47:01,647 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:47:01,647 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:47:01,647 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:47:01,648 D sapphire.job | 3 files required to serve
2021-03-31 08:47:01,648 D sapphire.connection_manager | starting listener
2021-03-31 08:47:01,797 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:47:01,798 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:47:02,198 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:47:02,199 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:47:02,203 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:47:02,203 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:47:02,203 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:47:02,203 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:47:32,471 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:47:32,471 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:47:32,474 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:47:32,474 D sapphire.worker | expecting to finish
2021-03-31 08:47:32,474 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:47:32,524 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:47:32,524 D sapphire.core | status: 0, timeout: False
2021-03-31 08:47:32,525 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:47:33,526 D ffpuppet.core | is_running() returned False
2021-03-31 08:47:33,526 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:47:33,527 D ffpuppet.core | browser pid: 1669753, 0 proc(s)
2021-03-31 08:47:33,527 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:47:33,527 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_k9osdkro/minidumps' did not contain '.dmp' files
2021-03-31 08:47:33,533 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:47:33,533 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:47:33,533 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:47:33,533 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:47:33,533 D sapphire.core | clearing socket backlog
2021-03-31 08:47:33,533 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:47:33,533 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:47:33,533 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:47:33,534 D ffpuppet.core | using profile '/tmp/ffprof_d64ruqek'
2021-03-31 08:47:33,534 D ffpuppet.core | launch timeout: 300
2021-03-31 08:47:33,534 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_d64ruqek http://127.0.0.1:46373'
2021-03-31 08:47:33,537 D ffpuppet.core | launched process 1670242
2021-03-31 08:47:33,537 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:47:35,160 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:47:35,229 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:47:35,229 D ffpuppet.bootstrapper | bootstrap complete (1.69s)
2021-03-31 08:47:35,229 I grizzly.replay.replay | Running test (7/10)...
2021-03-31 08:47:35,229 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:47:35,230 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:47:35,230 D sapphire.job | required: 'testcase.html'
2021-03-31 08:47:35,230 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:47:35,230 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:47:35,230 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:47:35,230 D sapphire.job | 3 files required to serve
2021-03-31 08:47:35,230 D sapphire.connection_manager | starting listener
2021-03-31 08:47:35,365 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:47:35,365 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:47:35,766 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:47:35,766 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:47:35,775 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:47:35,775 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:47:35,776 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:47:35,776 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:48:06,060 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:48:06,060 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:48:06,063 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:48:06,063 D sapphire.worker | expecting to finish
2021-03-31 08:48:06,063 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:48:06,113 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:48:06,113 D sapphire.core | status: 0, timeout: False
2021-03-31 08:48:06,113 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:48:07,115 D ffpuppet.core | is_running() returned False
2021-03-31 08:48:07,115 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:48:07,115 D ffpuppet.core | browser pid: 1670242, 0 proc(s)
2021-03-31 08:48:07,115 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:48:07,115 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_d64ruqek/minidumps' did not contain '.dmp' files
2021-03-31 08:48:07,121 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:48:07,121 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:48:07,121 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:48:07,121 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:48:07,121 D sapphire.core | clearing socket backlog
2021-03-31 08:48:07,121 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:48:07,121 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:48:07,121 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:48:07,122 D ffpuppet.core | using profile '/tmp/ffprof_ovvbvze4'
2021-03-31 08:48:07,122 D ffpuppet.core | launch timeout: 300
2021-03-31 08:48:07,122 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_ovvbvze4 http://127.0.0.1:60123'
2021-03-31 08:48:07,125 D ffpuppet.core | launched process 1670742
2021-03-31 08:48:07,125 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:48:08,721 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:48:08,797 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:48:08,798 D ffpuppet.bootstrapper | bootstrap complete (1.67s)
2021-03-31 08:48:08,798 I grizzly.replay.replay | Running test (8/10)...
2021-03-31 08:48:08,798 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:48:08,798 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:48:08,798 D sapphire.job | required: 'testcase.html'
2021-03-31 08:48:08,798 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:48:08,798 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:48:08,798 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:48:08,798 D sapphire.job | 3 files required to serve
2021-03-31 08:48:08,799 D sapphire.connection_manager | starting listener
2021-03-31 08:48:08,949 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:48:08,949 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:48:09,286 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:48:09,287 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:48:09,301 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:48:09,301 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:48:09,301 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:48:09,301 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:48:39,624 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:48:39,624 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:48:39,626 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:48:39,626 D sapphire.worker | expecting to finish
2021-03-31 08:48:39,627 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:48:39,676 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:48:39,677 D sapphire.core | status: 0, timeout: False
2021-03-31 08:48:39,677 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:48:40,678 D ffpuppet.core | is_running() returned False
2021-03-31 08:48:40,679 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:48:40,679 D ffpuppet.core | browser pid: 1670742, 0 proc(s)
2021-03-31 08:48:40,679 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:48:40,679 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_ovvbvze4/minidumps' did not contain '.dmp' files
2021-03-31 08:48:40,685 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:48:40,685 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:48:40,685 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:48:40,685 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:48:40,685 D sapphire.core | clearing socket backlog
2021-03-31 08:48:40,685 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:48:40,685 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:48:40,686 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:48:40,686 D ffpuppet.core | using profile '/tmp/ffprof_5iev5zko'
2021-03-31 08:48:40,686 D ffpuppet.core | launch timeout: 300
2021-03-31 08:48:40,687 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_5iev5zko http://127.0.0.1:63758'
2021-03-31 08:48:40,689 D ffpuppet.core | launched process 1671264
2021-03-31 08:48:40,689 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:48:42,425 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:48:42,489 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:48:42,489 D ffpuppet.bootstrapper | bootstrap complete (1.80s)
2021-03-31 08:48:42,489 I grizzly.replay.replay | Running test (9/10)...
2021-03-31 08:48:42,489 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:48:42,489 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:48:42,490 D sapphire.job | required: 'testcase.html'
2021-03-31 08:48:42,490 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:48:42,490 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:48:42,490 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:48:42,490 D sapphire.job | 3 files required to serve
2021-03-31 08:48:42,490 D sapphire.connection_manager | starting listener
2021-03-31 08:48:42,617 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:48:42,617 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:48:43,010 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:48:43,011 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:48:43,035 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:48:43,035 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:48:43,035 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:48:43,036 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:49:13,339 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:49:13,340 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:49:13,343 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:49:13,343 D sapphire.worker | expecting to finish
2021-03-31 08:49:13,343 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:49:13,393 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:49:13,393 D sapphire.core | status: 0, timeout: False
2021-03-31 08:49:13,393 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:49:14,395 D ffpuppet.core | is_running() returned False
2021-03-31 08:49:14,395 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:49:14,395 D ffpuppet.core | browser pid: 1671264, 0 proc(s)
2021-03-31 08:49:14,395 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:49:14,395 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_5iev5zko/minidumps' did not contain '.dmp' files
2021-03-31 08:49:14,401 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:49:14,401 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:49:14,401 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:49:14,401 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:49:14,402 D sapphire.core | clearing socket backlog
2021-03-31 08:49:14,402 D grizzly.common.runner | launching target (timeout 300s)
2021-03-31 08:49:14,402 D ffpuppet.core | requested location: 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000'
2021-03-31 08:49:14,402 D ffpuppet.helpers | using prefs.js: '/home/Downloads/prefs.js'
2021-03-31 08:49:14,402 D ffpuppet.core | using profile '/tmp/ffprof_5fnvboae'
2021-03-31 08:49:14,402 D ffpuppet.core | launch timeout: 300
2021-03-31 08:49:14,403 D ffpuppet.core | launch command: '/home/code/work/gecko3/obj-x86_64-pc-linux-gnu/dist/bin/firefox -no-remote -profile /tmp/ffprof_5fnvboae http://127.0.0.1:11778'
2021-03-31 08:49:14,405 D ffpuppet.core | launched process 1671784
2021-03-31 08:49:14,405 D ffpuppet.bootstrapper | waiting for browser connection...
2021-03-31 08:49:16,061 D ffpuppet.bootstrapper | waiting to receive browser request...
2021-03-31 08:49:16,127 D ffpuppet.bootstrapper | sending response (redirect 'http://127.0.0.1:49732/grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:49:16,127 D ffpuppet.bootstrapper | bootstrap complete (1.72s)
2021-03-31 08:49:16,127 I grizzly.replay.replay | Running test (10/10)...
2021-03-31 08:49:16,128 D sapphire.server_map | mapping dynamic response 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0> ('application/octet-stream')
2021-03-31 08:49:16,128 D sapphire.core | serving '/tmp/grizzly/serve/tc_o5q0mkbt' (forever=False)
2021-03-31 08:49:16,128 D sapphire.job | required: 'testcase.html'
2021-03-31 08:49:16,128 D sapphire.job | required: 'grz_next_test' -> 'grz_empty'
2021-03-31 08:49:16,128 D sapphire.job | optional: 'grz_current_test' -> 'testcase.html'
2021-03-31 08:49:16,128 D sapphire.job | required: 'grz_empty' -> <function Runner.run.<locals>.<lambda> at 0x7f976dbd01f0>
2021-03-31 08:49:16,129 D sapphire.job | 3 files required to serve
2021-03-31 08:49:16,129 D sapphire.connection_manager | starting listener
2021-03-31 08:49:16,268 D sapphire.worker | check_request('grz_harness?close_after=1&time_limit=30000')
2021-03-31 08:49:16,269 D sapphire.worker | 200 'grz_harness?close_after=1&time_limit=30000' - dynamic request (3 to go)
2021-03-31 08:49:16,646 D sapphire.worker | check_request('grz_current_test')
2021-03-31 08:49:16,646 D sapphire.worker | 307 'grz_current_test' -> 'testcase.html' (3 to go)
2021-03-31 08:49:16,675 D sapphire.worker | check_request('testcase.html')
2021-03-31 08:49:16,676 D sapphire.worker | target '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html'
2021-03-31 08:49:16,676 D sapphire.worker | sending: 369 bytes, mime: 'text/html'
2021-03-31 08:49:16,676 D sapphire.worker | 200 '/tmp/grizzly/serve/tc_o5q0mkbt/testcase.html' (2 to go)
2021-03-31 08:49:46,974 D sapphire.worker | check_request('grz_next_test')
2021-03-31 08:49:46,974 D sapphire.worker | 307 'grz_next_test' -> 'grz_empty' (1 to go)
2021-03-31 08:49:46,976 D sapphire.worker | check_request('grz_empty')
2021-03-31 08:49:46,976 D sapphire.worker | expecting to finish
2021-03-31 08:49:46,977 D sapphire.worker | 200 'grz_empty' - dynamic request (0 to go)
2021-03-31 08:49:47,026 D sapphire.connection_manager | listener cleaning up workers
2021-03-31 08:49:47,027 D sapphire.core | status: 0, timeout: False
2021-03-31 08:49:47,027 D grizzly.common.runner | relaunch/shutdown limit hit
2021-03-31 08:49:48,029 D ffpuppet.core | is_running() returned False
2021-03-31 08:49:48,029 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:49:48,029 D ffpuppet.core | browser pid: 1671784, 0 proc(s)
2021-03-31 08:49:48,029 D ffpuppet.core | reviewing 0 check(s)
2021-03-31 08:49:48,029 D ffpuppet.minidump_parser | scan_path '/tmp/ffprof_5fnvboae/minidumps' did not contain '.dmp' files
2021-03-31 08:49:48,035 D ffpuppet.core | exit reason code 'EXITED'
2021-03-31 08:49:48,035 D ffpuppet.core | reason is set to 'EXITED'
2021-03-31 08:49:48,035 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:49:48,035 D grizzly.target.puppet_target | target closed itself
2021-03-31 08:49:48,035 D grizzly.replay.replay | results (0) < minimum (1), after 10 attempts
2021-03-31 08:49:48,036 D ffpuppet.core | close(force_close=False) called
2021-03-31 08:49:48,036 I grizzly.replay.replay | Failed to reproduce results
2021-03-31 08:49:48,036 I grizzly.replay.replay | Shutting down...
2021-03-31 08:49:48,036 D ffpuppet.core | clean_up() called
2021-03-31 08:49:48,036 D ffpuppet.core | close(force_close=True) called
2021-03-31 08:49:48,043 I grizzly.replay.replay | Done.

(In reply to Glenn Watson [:gw] from comment #10)

Thank you for the logs! It looks like it is working as expected now.

Output from doing the update and adding debug logging, still doesn't seem to repro for me, which is very odd. Is there anything else obvious I might be missing?

I really have no idea what it could be. When I was trying on other systems I was hoping I'd catch the problem. Side note, it looks like this was last reported by fuzzers with m-c 20210322-7bff3dc37b07. I don't know if it was easier to trigger before that or what.

Could it be related to screen resolution or device-pixel scaling ratio perhaps?

Usually Xvfb is how we deal with that but it doesn't look like it mattered in this case. I tested on my laptop (Ubuntu 20.04, X1 Carbon) but could not reproduce it there.

This is the about:support from the VM that I can consistently reproduce the issue on.

Application Basics
------------------

Name: Firefox
Version: 89.0a1
Build ID: 20210330215136
Distribution ID:
Update Channel: default
User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0
OS: Linux 5.8.0-44-generic #50~20.04.1-Ubuntu SMP Wed Feb 10 21:07:30 UTC 2021
Multiprocess Windows: 1/1
Fission Windows: 1/1 Enabled by user
Remote Processes: 7
Enterprise Policies: Inactive
Google Location Service Key: Missing
Google Safebrowsing Key: Missing
Mozilla Location Service Key: Missing
Safe Mode: false

Nightly Features
----------------

Name: DoH Roll-Out
Version: 2.0.0
ID: doh-rollout@mozilla.org

Name: Firefox Screenshots
Version: 39.0.0
ID: screenshots@mozilla.org

Name: Form Autofill
Version: 1.0
ID: formautofill@mozilla.org

Name: Picture-In-Picture
Version: 1.0.0
ID: pictureinpicture@mozilla.org

Name: Web Compatibility Interventions
Version: 21.0.0
ID: webcompat@mozilla.org

Name: WebCompat Reporter
Version: 1.4.0
ID: webcompat-reporter@mozilla.org

Remote Features
---------------

Remote Processes
----------------

Type: Local File
Count: 1

Type: Extension
Count: 1

Type: Privileged About
Count: 1

Type: Preallocated
Count: 3

Type: Socket
Count: 1

Add-ons
-------

Name: Amazon.com
Type: extension
Version: 1.3
Enabled: true
ID: amazondotcom@search.mozilla.org

Name: Bing
Type: extension
Version: 1.3
Enabled: true
ID: bing@search.mozilla.org

Name: DuckDuckGo
Type: extension
Version: 1.1
Enabled: true
ID: ddg@search.mozilla.org

Name: eBay
Type: extension
Version: 1.3
Enabled: true
ID: ebay@search.mozilla.org

Name: Google
Type: extension
Version: 1.1
Enabled: true
ID: google@search.mozilla.org

Name: Wikipedia (en)
Type: extension
Version: 1.1
Enabled: true
ID: wikipedia@search.mozilla.org

Graphics
--------

Features
Compositing: WebRender
Asynchronous Pan/Zoom: wheel input enabled; scrollbar drag enabled; keyboard enabled; autoscroll enabled; smooth pinch-zoom enabled
WebGL 1 Driver WSI Info: GLX 1.4 GLX_VENDOR(client): Mesa Project and SGI GLX_VENDOR(server): SGI Extensions: GLX_ARB_create_context GLX_ARB_create_context_no_error GLX_ARB_create_context_profile GLX_ARB_fbconfig_float GLX_ARB_framebuffer_sRGB GLX_ARB_get_proc_address GLX_ARB_multisample GLX_EXT_buffer_age GLX_EXT_create_context_es2_profile GLX_EXT_create_context_es_profile GLX_EXT_fbconfig_packed_float GLX_EXT_framebuffer_sRGB GLX_EXT_import_context GLX_EXT_texture_from_pixmap GLX_EXT_visual_info GLX_EXT_visual_rating GLX_MESA_copy_sub_buffer GLX_MESA_query_renderer GLX_MESA_swap_control GLX_OML_swap_method GLX_OML_sync_control GLX_SGIS_multisample GLX_SGIX_fbconfig GLX_SGIX_pbuffer GLX_SGIX_visual_select_group GLX_SGI_make_current_read GLX_SGI_video_sync IsWebglOutOfProcessEnabled: 0
WebGL 1 Driver Renderer: VMware, Inc. -- SVGA3D; build: RELEASE; LLVM;
WebGL 1 Driver Version: 3.3 (Compatibility Profile) Mesa 20.2.6
WebGL 1 Driver Extensions: GL_ARB_multisample GL_EXT_abgr GL_EXT_bgra GL_EXT_blend_color GL_EXT_blend_minmax GL_EXT_blend_subtract GL_EXT_copy_texture GL_EXT_subtexture GL_EXT_texture_object GL_EXT_vertex_array GL_EXT_compiled_vertex_array GL_EXT_texture GL_EXT_texture3D GL_IBM_rasterpos_clip GL_ARB_point_parameters GL_EXT_draw_range_elements GL_EXT_packed_pixels GL_EXT_point_parameters GL_EXT_rescale_normal GL_EXT_separate_specular_color GL_EXT_texture_edge_clamp GL_SGIS_generate_mipmap GL_SGIS_texture_border_clamp GL_SGIS_texture_edge_clamp GL_SGIS_texture_lod GL_ARB_framebuffer_sRGB GL_ARB_multitexture GL_EXT_framebuffer_sRGB GL_IBM_multimode_draw_arrays GL_IBM_texture_mirrored_repeat GL_ARB_texture_cube_map GL_ARB_texture_env_add GL_ARB_transpose_matrix GL_EXT_blend_func_separate GL_EXT_fog_coord GL_EXT_multi_draw_arrays GL_EXT_secondary_color GL_EXT_texture_env_add GL_EXT_texture_filter_anisotropic GL_EXT_texture_lod_bias GL_INGR_blend_func_separate GL_NV_blend_square GL_NV_light_max_exponent GL_NV_texgen_reflection GL_NV_texture_env_combine4 GL_S3_s3tc GL_SUN_multi_draw_arrays GL_ARB_texture_border_clamp GL_ARB_texture_compression GL_EXT_framebuffer_object GL_EXT_texture_compression_s3tc GL_EXT_texture_env_combine GL_EXT_texture_env_dot3 GL_MESA_window_pos GL_NV_packed_depth_stencil GL_NV_texture_rectangle GL_ARB_depth_texture GL_ARB_occlusion_query GL_ARB_shadow GL_ARB_texture_env_combine GL_ARB_texture_env_crossbar GL_ARB_texture_env_dot3 GL_ARB_texture_mirrored_repeat GL_ARB_window_pos GL_ATI_fragment_shader GL_EXT_stencil_two_side GL_EXT_texture_cube_map GL_NV_depth_clamp GL_NV_fog_distance GL_APPLE_packed_pixels GL_ARB_draw_buffers GL_ARB_fragment_program GL_ARB_fragment_shader GL_ARB_shader_objects GL_ARB_vertex_program GL_ARB_vertex_shader GL_ATI_draw_buffers GL_ATI_texture_env_combine3 GL_ATI_texture_float GL_EXT_shadow_funcs GL_EXT_stencil_wrap GL_MESA_pack_invert GL_NV_primitive_restart GL_ARB_depth_clamp GL_ARB_fragment_program_shadow GL_ARB_half_float_pixel GL_ARB_occlusion_query2 GL_ARB_point_sprite GL_ARB_shading_language_100 GL_ARB_sync GL_ARB_texture_non_power_of_two GL_ARB_vertex_buffer_object GL_ATI_blend_equation_separate GL_EXT_blend_equation_separate GL_OES_read_format GL_ARB_color_buffer_float GL_ARB_pixel_buffer_object GL_ARB_texture_compression_rgtc GL_ARB_texture_float GL_ARB_texture_rectangle GL_EXT_packed_float GL_EXT_pixel_buffer_object GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_rgtc GL_EXT_texture_rectangle GL_EXT_texture_sRGB GL_EXT_texture_shared_exponent GL_ARB_framebuffer_object GL_EXT_framebuffer_blit GL_EXT_framebuffer_multisample GL_EXT_packed_depth_stencil GL_ARB_vertex_array_object GL_ATI_separate_stencil GL_EXT_draw_buffers2 GL_EXT_draw_instanced GL_EXT_gpu_program_parameters GL_EXT_gpu_shader4 GL_EXT_texture_array GL_EXT_texture_integer GL_EXT_texture_sRGB_decode GL_EXT_timer_query GL_OES_EGL_image GL_EXT_texture_buffer_object GL_AMD_texture_texture4 GL_ARB_copy_buffer GL_ARB_depth_buffer_float GL_ARB_draw_instanced GL_ARB_half_float_vertex GL_ARB_instanced_arrays GL_ARB_map_buffer_range GL_ARB_texture_buffer_object GL_ARB_texture_rg GL_ARB_texture_swizzle GL_ARB_vertex_array_bgra GL_EXT_texture_swizzle GL_EXT_vertex_array_bgra GL_NV_conditional_render GL_AMD_conservative_depth GL_AMD_draw_buffers_blend GL_ARB_ES2_compatibility GL_ARB_blend_func_extended GL_ARB_compatibility GL_ARB_debug_output GL_ARB_draw_buffers_blend GL_ARB_draw_elements_base_vertex GL_ARB_explicit_attrib_location GL_ARB_fragment_coord_conventions GL_ARB_provoking_vertex GL_ARB_sample_shading GL_ARB_sampler_objects GL_ARB_seamless_cube_map GL_ARB_shader_texture_lod GL_ARB_texture_buffer_object_rgb32 GL_ARB_texture_cube_map_array GL_ARB_texture_gather GL_ARB_texture_multisample GL_ARB_texture_query_lod GL_ARB_texture_rgb10_a2ui GL_ARB_uniform_buffer_object GL_ARB_vertex_type_2_10_10_10_rev GL_EXT_provoking_vertex GL_EXT_texture_snorm GL_MESA_texture_signed_rgba GL_NV_copy_image GL_ARB_get_program_binary GL_ARB_robustness GL_ARB_separate_shader_objects GL_ARB_shader_bit_encoding GL_ARB_shader_subroutine GL_ARB_timer_query GL_ARB_viewport_array GL_EXT_direct_state_access GL_ANGLE_texture_compression_dxt3 GL_ANGLE_texture_compression_dxt5 GL_ARB_compressed_texture_pixel_storage GL_ARB_conservative_depth GL_ARB_internalformat_query GL_ARB_map_buffer_alignment GL_ARB_shading_language_420pack GL_ARB_shading_language_packing GL_ARB_texture_storage GL_EXT_framebuffer_multisample_blit_scaled GL_EXT_transform_feedback GL_AMD_shader_trinary_minmax GL_ARB_ES3_compatibility GL_ARB_arrays_of_arrays GL_ARB_clear_buffer_object GL_ARB_copy_image GL_ARB_explicit_uniform_location GL_ARB_fragment_layer_viewport GL_ARB_invalidate_subdata GL_ARB_program_interface_query GL_ARB_texture_buffer_range GL_ARB_texture_query_levels GL_ARB_texture_storage_multisample GL_ARB_vertex_attrib_binding GL_KHR_debug GL_KHR_texture_compression_astc_ldr GL_ARB_buffer_storage GL_ARB_clear_texture GL_ARB_internalformat_query2 GL_ARB_multi_bind GL_ARB_shading_language_include GL_EXT_shader_integer_mix GL_ARB_direct_state_access GL_ARB_get_texture_sub_image GL_KHR_context_flush_control GL_ARB_parallel_shader_compile GL_KHR_no_error GL_KHR_texture_compression_astc_sliced_3d GL_MESA_shader_integer_functions GL_ARB_texture_filter_anisotropic GL_KHR_parallel_shader_compile GL_EXT_EGL_image_storage GL_EXT_EGL_sync
WebGL 1 Extensions: ANGLE_instanced_arrays EXT_blend_minmax EXT_color_buffer_half_float EXT_disjoint_timer_query EXT_float_blend EXT_frag_depth EXT_shader_texture_lod EXT_sRGB EXT_texture_compression_rgtc EXT_texture_filter_anisotropic MOZ_debug OES_element_index_uint OES_fbo_render_mipmap OES_standard_derivatives OES_texture_float OES_texture_float_linear OES_texture_half_float OES_texture_half_float_linear OES_vertex_array_object WEBGL_color_buffer_float WEBGL_compressed_texture_astc WEBGL_compressed_texture_etc WEBGL_compressed_texture_s3tc WEBGL_compressed_texture_s3tc_srgb WEBGL_debug_renderer_info WEBGL_debug_shaders WEBGL_depth_texture WEBGL_draw_buffers WEBGL_explicit_present WEBGL_lose_context
WebGL 2 Driver WSI Info: -
WebGL 2 Driver Renderer: WebGL creation failed: * WebGL 2 requires support for the following features: transform_feedback2 (FEATURE_FAILURE_WEBGL2_OCCL)
WebGL 2 Driver Version: -
WebGL 2 Driver Extensions: -
WebGL 2 Extensions: -
Window Protocol: x11
Desktop Environment: gnome
Target Frame Rate: 60
GPU #1
Active: Yes
Description: SVGA3D; build: RELEASE; LLVM;
Vendor ID: 0x15ad
Device ID: 0x0405
Driver Vendor: mesa/vmwgfx
Driver Version: 20.2.6.0
RAM: 0

Diagnostics
AzureCanvasBackend: skia
AzureContentBackend: skia
AzureFallbackCanvasBackend: none
CairoUseXRender: 0
CMSOutputProfile: Empty profile data
Display0: 3840x2160 default
DisplayCount: 1
Device Reset: Trigger Device Reset
Decision Log
HW_COMPOSITING:
available by default
force_enabled by user: Force-enabled by pref
OPENGL_COMPOSITING:
available by default
force_enabled by user: Force-enabled by pref
WEBRENDER:
available by default
force_enabled by user: Force enabled by pref
disabled by env: Not qualified
WEBRENDER_QUALIFIED:
available by default
denied by env: Not on allowlist
WEBRENDER_COMPOSITOR:
disabled by default: Disabled by default
WEBRENDER_PARTIAL:
available by default
WEBRENDER_OPTIMIZED_SHADERS:
available by default
WEBRENDER_ANGLE:
available by default
unavailable by env: OS not supported
WEBRENDER_DCOMP_PRESENT:
available by default
disabled by user: User disabled via pref
unavailable by env: Requires Windows 10 or later
unavailable by runtime: Requires ANGLE
WEBRENDER_SOFTWARE:
available by default
OMTP:
disabled by default: Disabled by default
WEBGPU:
disabled by default: Disabled by default
available by user: Enabled via dom.webgpu.enabled
X11_EGL:
available by default
blocklisted by env: Blocklisted by gfxInfo
DMABUF:
available by default
unavailable by runtime: Requires EGL




Media
-----

Audio Backend: pulse-rust
Max Channels: 2
Preferred Sample Rate: 44100
Roundtrip latency (standard deviation): 212.04ms (15.52)
Output Devices
Name: Group
ES1371/ES1373 / Creative Labs CT2518 (Audio PCI 64V/128/5200 / Creative CT4810/CT5803/CT5806 [Sound Blaster PCI]) Analog Stereo: /devices/pci0000:00/0000:00:11.0/0000:02:02.0/sound/card0
Input Devices
Name: Group
Monitor of ES1371/ES1373 / Creative Labs CT2518 (Audio PCI 64V/128/5200 / Creative CT4810/CT5803/CT5806 [Sound Blaster PCI]) Analog Stereo: /devices/pci0000:00/0000:00:11.0/0000:02:02.0/sound/card0
ES1371/ES1373 / Creative Labs CT2518 (Audio PCI 64V/128/5200 / Creative CT4810/CT5803/CT5806 [Sound Blaster PCI]) Analog Stereo: /devices/pci0000:00/0000:00:11.0/0000:02:02.0/sound/card0
Media Capabilities
Enumerate database

Environment Variables
---------------------

DISPLAY: :0
MOZ_AUTOMATION: 1
MOZ_CC_RUN_DURING_SHUTDOWN: 1
MOZ_CRASHREPORTER: 1
MOZ_CRASHREPORTER_NO_DELETE_DUMP: 1
MOZ_CRASHREPORTER_NO_REPORT: 1
MOZ_DISABLE_CONTENT_SANDBOX: 1
MOZ_DISABLE_GMP_SANDBOX: 1
MOZ_DISABLE_GPU_SANDBOX: 1
MOZ_DISABLE_NPAPI_SANDBOX: 1
MOZ_DISABLE_PDFIUM_SANDBOX: 1
MOZ_DISABLE_RDD_SANDBOX: 1
MOZ_DISABLE_SOCKET_PROCESS_SANDBOX: 1
MOZ_DISABLE_VR_SANDBOX: 1
MOZ_GDB_SLEEP: 0
MOZ_SKIA_DISABLE_ASSERTS: 1
XRE_NO_WINDOWS_CRASH_DIALOG: 1
MOZ_ASSUME_USER_NS: 1
MOZ_LAUNCHED_CHILD:
MOZ_NO_REMOTE: 1
XRE_PROFILE_PATH:
XRE_PROFILE_LOCAL_PATH:
XRE_START_OFFLINE:
XRE_BINARY_PATH:
XRE_RESTARTED_BY_PROFILE_MANAGER:

Experimental Features
---------------------

about:home startup cache (browser.startup.homepage.abouthome_cache.enabled): true
Cookies: SameSite=Lax by default (network.cookie.sameSite.laxByDefault): true
Cookies: SameSite=None requires secure attribute (network.cookie.sameSite.noneRequiresSecure): true
Cookies: Schemeful SameSite (network.cookie.sameSite.schemeful): true
CSS: Constructable Stylesheets (layout.css.constructable-stylesheets.enabled): true
CSS: Masonry Layout (layout.css.grid-template-masonry-value.enabled): true
Developer Tools: Color Scheme Simulation (devtools.inspector.color-scheme-simulation.enabled): true
Developer Tools: Compatibility Panel (devtools.inspector.compatibility.enabled): true
Developer Tools: Execution Context Selector (devtools.webconsole.input.context): true
Developer Tools: Service Worker debugging (devtools.debugger.features.windowless-service-workers): false
Fission (Site Isolation) (fission.autostart): true
HTTP/3 protocol (network.http.http3.enabled): true
Multiple Picture-in-Picture Support (media.videocontrols.picture-in-picture.allow-multiple): true
Address Bar: show results during IME composition (browser.urlbar.keepPanelOpenDuringImeComposition): false
Web API: inputmode (dom.forms.inputmode): true
Web API: WebGPU (dom.webgpu.enabled): true
WebRTC Global Mute Toggles (privacy.webrtc.globalMuteToggles): false

Remote Experiments
------------------

Important Modified Preferences
------------------------------

apz.nonwr.activate_all_scroll_frames: true
browser.cache.disk_cache_ssl: false
browser.cache.disk.enable: false
browser.cache.memory.enable: false
browser.cache.offline.enable: false
browser.contentblocking.category: standard
browser.search.region: US
browser.search.suggest.enabled: false
browser.search.update: false
browser.sessionstore.resume_from_crash: false
browser.startup.homepage: about:blank
browser.startup.homepage_override.mstone: ignore
browser.startup.page: 0
browser.tabs.warnOnClose: false
browser.tabs.warnOnCloseOtherTabs: false
browser.urlbar.placeholderName: Google
doh-rollout.balrog-migration-done: true
doh-rollout.doneFirstRun: true
dom.allow_scripts_to_close_windows: true
dom.always_stop_slow_scripts: true
dom.audioworklet.enabled: true
dom.css_pseudo_element.enabled: true
dom.dialog_element.enabled: true
dom.disable_open_during_load: false
dom.disable_window_flip: false
dom.fetchObserver.enabled: true
dom.forms.autocomplete.formautofill: true
dom.gamepad.extensions.lightindicator: false
dom.gamepad.extensions.multitouch: false
dom.gamepad.test.enabled: false
dom.image-lazy-loading.enabled: false
dom.indexedDB.experimental: true
dom.input_events.beforeinput.enabled: true
dom.input.dirpicker: true
dom.ipc.plugins.flash.disable-protected-mode: true
dom.max_chrome_script_run_time: 0
dom.max_script_run_time: 0
dom.min_background_timeout_value: 4
dom.payments.request.enabled: true
dom.presentation.controller.enabled: true
dom.presentation.enabled: true
dom.presentation.receiver.enabled: true
dom.push.testing.ignorePermission: true
dom.security.featurePolicy.webidl.enabled: true
dom.security.sanitizer.enabled: true
dom.send_after_paint_to_content: true
dom.serviceWorkers.testing.enabled: true
dom.successive_dialog_time_limit: 0
dom.textMetrics.baselines.enabled: true
dom.textMetrics.emHeight.enabled: true
dom.textMetrics.fontBoundingBox.enabled: true
dom.visualviewport.enabled: true
dom.vr.enabled: false
dom.vr.external.notdetected.timeout: 0
dom.vr.external.quit.timeout: 0
dom.vr.poseprediction.enabled: false
dom.vr.puppet.enabled: false
dom.vr.require-gesture: false
dom.vr.webxr.enabled: false
dom.webgpu.enabled: true
dom.window_print.fuzzing.block_while_printing: true
dom.worklet.enabled: true
extensions.lastAppVersion: 89.0a1
fission.autostart: true
general.useragent.updates.enabled: false
gfx.color_management.enablev4: true
gfx.color_management.mode: 1
gfx.downloadable_fonts.disable_cache: true
gfx.downloadable_fonts.otl_validation: false
gfx.downloadable_fonts.sanitize_omt: false
gfx.downloadable_fonts.validate_variation_tables: false
gfx.e10s.font-list.shared: true
gfx.offscreencanvas.enabled: false
gfx.webrender.all: true
gfx.webrender.software: false
image.animated.decode-on-demand.batch-size: 1
image.animated.decode-on-demand.threshold-kb: 0
image.avif.enabled: true
image.cache.size: 0
image.multithreaded_decoding.limit: 1
layers.acceleration.force-enabled: true
media.autoplay.default: 0
media.autoplay.enabled.user-gestures-needed: false
media.eme.enabled: true
media.eme.hdcp-policy-check.enabled: true
media.gmp-manager.url.override: http://127.0.0.1:6/dummy-gmp-manager.xml
media.gmp.storage.version.observed: 1
media.mediasource.webm.enabled: true
media.navigator.permission.disabled: true
media.navigator.video.red_ulpfec_enabled: true
media.peerconnection.default_iceservers: [{"url": "stun:23.21.150.121"}]
media.setsinkid.enabled: true
media.useAudioChannelAPI: true
network.http.response.timeout: 1
network.http.spdy.enabled: false
network.manage-offline-status: false
network.prefetch-next: false
network.protocol-handler.external.mailto: false
network.trr.blocklist_cleanup_done: true
network.websocket.allowInsecureFromHTTPS: true
network.websocket.delay-failed-reconnects: false
plugin.disable: true
privacy.partition.network_state: false
privacy.sanitize.pending: [{"id":"newtab-container","itemsToClear":[],"options":{}}]
security.data_uri.unique_opaque_origin: false
security.default_personal_cert: Select Automatically
security.fileuri.strict_origin_policy: false
security.OCSP.enabled: 0
security.sandbox.plugin.tempDirSuffix: 6fb8a950-da01-428f-b621-7b06ce05e3e8
security.webauth.webauthn_enable_softtoken: true
security.webauth.webauthn_enable_usbtoken: false
services.sync.engine.addresses.available: true
webgl.enable-draft-extensions: true
webgl.enable-privileged-extensions: true
webgl.prefer-native-gl: false

Important Locked Preferences
----------------------------

fission.autostart.session: true

Places Database
---------------

Accessibility
-------------

Activated: false
Prevent Accessibility: 0

Library Versions
----------------

NSPR
Expected minimum version: 4.30
Version in use: 4.30

NSS
Expected minimum version: 3.63
Version in use: 3.63

NSSSMIME
Expected minimum version: 3.63
Version in use: 3.63

NSSSSL
Expected minimum version: 3.63
Version in use: 3.63

NSSUTIL
Expected minimum version: 3.63
Version in use: 3.63

Sandbox
-------

Seccomp-BPF (System Call Filtering): true
Seccomp Thread Synchronization: true
User Namespaces: true
Content Process Sandbox Level: 4
Effective Content Process Sandbox Level: 0

Rejected System Calls
---------------------

Startup Cache
-------------

Disk Cache Path: /tmp/ffprof_ubd386d7/startupCache/startupCache.8.little
Ignore Disk Cache: false
Found Disk Cache on Init: false
Wrote to Disk Cache: false

Internationalization & Localization
-----------------------------------

Application Settings
Requested Locales: ["en-US"]
Available Locales: ["en-US"]
App Locales: ["en-US"]
Regional Preferences: ["en-CA"]
Default Locale: "en-US"
Operating System
System Locales: ["en-CA"]
Regional Preferences: ["en-CA"]

Remote Debugging (Chromium Protocol)
------------------------------------

Accepting Connections: false
URL:

Printing
--------

Modified print settings
-----------------------

print.always_print_silent: true
print.print_to_file: true
print.show_print_progress: true

After only one crash earlier this week, this signature gets crash reports submitted again starting with 89.0a1 20210331092207 (crashes from 19 installs). Could this be related to the rust upgrade in bug 1700562? Because the webrender changelog doesn't contain any suspicious for that build.

(In reply to Sebastian Hengst [:aryx] (needinfo on intermittent or backout) from comment #12)

After only one crash earlier this week, this signature gets crash reports submitted again starting with 89.0a1 20210331092207 (crashes from 19 installs). Could this be related to the rust upgrade in bug 1700562? Because the webrender changelog doesn't contain any suspicious for that build.

I have been experiencing stable crashes on webrender::picture::PicturePrimitive::take_context since some nightly on March 31. It can be reproduced stably on my profile with a certain userscript [1] on ViolentMonkey on a certain website [2], but not fresh profiles.

Mozregression indicates the bisect pushlog as follows: https://hg.mozilla.org/integration/autoland/rev/be0f7947d378a4764a10bd3e676e859146efa445

Feel free to NI if there's anything I can help with.

1. https://github.com/the1812/Bilibili-Evolved/blob/4dc90004ffe49cf5b41727d1b5a56fd2edbc74f1/bilibili-evolved.user.js
2. I used https://www.bilibili.com/video/av203387849 for tests, but typically any video link on this website is affected.

FWIW, here's the set of changes introduced into that build: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=eed530931ca05b277c29539784ac24dea224f368&tochange=142544e13e2942ddd3035a3d9db5d739e0a7d392

I do see bug 1700539 in that range.

Needinfo'ing gw based on possible regressor from the last two comments.

[Tracking Requested - why for this release]: Apparent crash regression that is showing up on Nightly stability and has a test case. I'm also marking 88 for tracking because the apparent regressor bug 1700539 was backported to 88.

Hmm I guess the initial bug was filed a bit earlier, so maybe we need a new bug for the crash on Nightly?

For the crash I experienced, here is a STR:

1. Open a new profile on Nightly older than Mar 31
2. Install Violentmonkey
3. Import the attachment in "Settings" > "Data Import" > "Import from zip" to install the forementioned userscript (and its cache on my profile, which is essential to trigger the crash)
4. Open an affected page (e.g. https://www.bilibili.com/video/av203387849)

It's far from MRE but hopefully it helps.

tracking+ for now, but it sounds like this might overlap with bug 1702662

Changing the priority to p1 as the bug is tracked by a release manager for the current beta.
See What Do You Triage for more information

I'm going to see if I can reproduce and investigate this today with the steps in c18, thanks!

Thanks for the additional repro in comment 13. I can confirm I was able to repro that locally, and there is a patch in bug #1702662 which fixes this for me. Please see https://bugzilla.mozilla.org/show_bug.cgi?id=1702662#c12 for more context.

The patch from bug 1702662 definitely resolved the crash spike attributed to this bug, but I'm a bit worried that the original fuzz bug was filed prior to the regressing bug 1700539 landing. Is there still a testcase which reproduces this, Tyson? Regardless, we can drop the tracking status here as its immediate impact appears to have been mitigated.

The original test case still reproduces the originally logged issue as of m-c 20210406-b85e871f6a8d.

A updated Pernosco session can be found here: https://pernos.co/debug/J0BqJvtp3LFuB_LZJ1MheQ/index.html

I see some of the rust code is being removed. I will investigate further in bug 1703330.

An updated Pernosco session is available here: https://pernos.co/debug/aOylcvIaD2zhRiOsQBdaRA/index.html

The rust optimization issues should be fixed.

Bugmon Analysis
The bug appears to have been fixed in the following build range:

Start: 30ff85170f4f637ac4fd9e9fa14e039898753446 (20210614204928)
End: 48c3a00b8af3d266e0c45f9f0b96b19effebe62c (20210614214434)
Pushlog: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=30ff85170f4f637ac4fd9e9fa14e039898753446&tochange=48c3a00b8af3d266e0c45f9f0b96b19effebe62c
Removing bugmon keyword as no further action possible. Please review the bug and re-add the keyword for further analysis.

:gw, is it possible that bug 1715935 fixed this issue?

It sounds plausible, yes.

Ok, I'll go ahead and close for now. If our fuzzers start seeing it again, I'll file a new issue.