1674823 - Intermittent layout/generic/crashtests/370174-4.html | application crashed [@ mozalloc_handle_oom(unsigned int)] | After application terminated with exit code 1

Status: RESOLVED FIXED

(Core :: Layout, defect)

Description

[Treeherder Bug Filer]

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

---

[task 2020-11-02T16:09:36.130Z] 16:09:36     INFO - REFTEST TEST-START | layout/generic/crashtests/370174-4.html
[task 2020-11-02T16:09:36.130Z] 16:09:36     INFO - REFTEST TEST-LOAD | file:///Z:/task_1604332128/build/tests/reftest/tests/layout/generic/crashtests/370174-4.html | 2145 / 3863 (55%)
[task 2020-11-02T16:11:03.711Z] 16:11:03     INFO - out of memory: 0x0000000000001000 bytes requested
[task 2020-11-02T16:11:03.711Z] 16:11:03     INFO - Hit MOZ_CRASH() at /builds/worker/checkouts/gecko/memory/mozalloc/mozalloc_abort.cpp:33
[task 2020-11-02T16:11:03.730Z] 16:11:03     INFO - Exiting due to channel error.
[task 2020-11-02T16:11:03.757Z] 16:11:03    ERROR - TEST-UNEXPECTED-FAIL | layout/generic/crashtests/370174-4.html | application terminated with exit code 1
[task 2020-11-02T16:11:03.757Z] 16:11:03     INFO - REFTEST INFO | Copy/paste: Z:/task_1604332128/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1604332128\appdata\local\temp\tmpyzrunc.mozrunner\minidumps\a92bfa8c-2de0-4f06-96fa-362d827792d7.dmp Z:\task_1604332128\build\symbols
[task 2020-11-02T16:11:12.280Z] 16:11:12     INFO - REFTEST INFO | Saved minidump as Z:\task_1604332128\build\blobber_upload_dir\a92bfa8c-2de0-4f06-96fa-362d827792d7.dmp
[task 2020-11-02T16:11:12.283Z] 16:11:12     INFO - REFTEST INFO | Saved app info as Z:\task_1604332128\build\blobber_upload_dir\a92bfa8c-2de0-4f06-96fa-362d827792d7.extra
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO - REFTEST PROCESS-CRASH | layout/generic/crashtests/370174-4.html | application crashed [@ mozalloc_handle_oom(unsigned int)]
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO - Mozilla crash reason: MOZ_CRASH()
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO - Crash dump filename: c:\users\task_1604332128\appdata\local\temp\tmpyzrunc.mozrunner\minidumps\a92bfa8c-2de0-4f06-96fa-362d827792d7.dmp
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO - Operating system: Windows NT
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO -                   6.1.7601 Service Pack 1
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO - CPU: x86
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO -      GenuineIntel family 6 model 63 stepping 2
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO -      8 CPUs
[task 2020-11-02T16:11:12.381Z] 16:11:12     INFO - 
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - GPU: UNKNOWN
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - 
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - Crash reason:  EXCEPTION_BREAKPOINT
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - Crash address: 0x6b53f5b1
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - Process uptime: 728 seconds
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - 
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO - Thread 4 (crashed)
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -  0  mozglue.dll!mozalloc_abort(char const* const) [mozalloc_abort.cpp:82b844f552726949fe21ef223842f2ee10cee3f5 : 33 + 0x0]
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     eip = 0x6b53f5b1   esp = 0x024af934   ebp = 0x024af93c   ebx = 0x00001000
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     esi = 0x024af94a   edi = 0x6b42f9b0   eax = 0x00000000   ecx = 0x00000000
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     edx = 0x6b50e340   efl = 0x00000206
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     Found by: given as instruction pointer in context
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -  1  mozglue.dll!mozalloc_handle_oom(unsigned int) [mozalloc_oom.cpp:82b844f552726949fe21ef223842f2ee10cee3f5 : 51 + 0x6]
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     eip = 0x6b53f74e   esp = 0x024af944   ebp = 0x024af984   esi = 0x024af94a
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     edi = 0x00000000
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     Found by: call frame info
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -  2  mozglue.dll!moz_xmalloc(unsigned int) [mozalloc.cpp:82b844f552726949fe21ef223842f2ee10cee3f5 : 54 + 0x6]
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     eip = 0x6b53f6ee   esp = 0x024af98c   ebp = 0x024af994   esi = 0x00001000
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     edi = 0x00000000
[task 2020-11-02T16:11:12.382Z] 16:11:12     INFO -     Found by: call frame info
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  3  xul.dll + 0x919a05
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53eb9a05   esp = 0x024af99c   ebp = 0x024af9bc   esi = 0x1d4ee178
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: call frame info
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  4  xul.dll + 0x91a965
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53eba965   esp = 0x024af9c4   ebp = 0x024af9dc
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  5  xul.dll + 0x911287
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53eb1287   esp = 0x024af9e4   ebp = 0x024afa00
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  6  xul.dll + 0x9008d3
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53ea08d3   esp = 0x024afa08   ebp = 0x024afabc
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  7  xul.dll + 0x901046
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53ea1046   esp = 0x024afac4   ebp = 0x024afafc
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  8  xul.dll + 0x8facdb
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53e9acdb   esp = 0x024afb04   ebp = 0x024afb74
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -  9  xul.dll + 0x8faa5c
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     eip = 0x53e9aa5c   esp = 0x024afb7c   ebp = 0x024afb98
[task 2020-11-02T16:11:12.383Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO - 10  xul.dll + 0x8fb002
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     eip = 0x53e9b002   esp = 0x024afba0   ebp = 0x024afbd8
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO - 11  xul.dll + 0x90c3bf
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     eip = 0x53eac3bf   esp = 0x024afbe0   ebp = 0x024afc04
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO - 12  xul.dll + 0x90c2c3
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     eip = 0x53eac2c3   esp = 0x024afc0c   ebp = 0x024afc38
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO - 13  xul.dll + 0x915715
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     eip = 0x53eb5715   esp = 0x024afc40   ebp = 0x024afd74
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO - 14  xul.dll + 0x8fb939
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     eip = 0x53e9b939   esp = 0x024afd7c   ebp = 0x024afd84
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO - 15  kernel32.dll! ?? ?? ::FNODOBFM::`string' + 0x46
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     eip = 0x7624ef3c   esp = 0x024afd8c   ebp = 0x024afd90
[task 2020-11-02T16:11:12.384Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.385Z] 16:11:12     INFO - 16  ntdll.dll!__RtlUserThreadStart + 0x27
[task 2020-11-02T16:11:12.385Z] 16:11:12     INFO -     eip = 0x77603618   esp = 0x024afd98   ebp = 0x024afdd0
[task 2020-11-02T16:11:12.385Z] 16:11:12     INFO -     Found by: previous frame's frame pointer
[task 2020-11-02T16:11:12.385Z] 16:11:12     INFO - 17  ntdll.dll!_RtlUserThreadStart + 0x1b
[task 2020-11-02T16:11:12.385Z] 16:11:12     INFO -     eip = 0x776035eb   esp = 0x024afdd8   ebp = 0x024afde8
[task 2020-11-02T16:11:12.385Z] 16:11:12     INFO -     Found by: call frame info```

Comment 1

[Andrew McCreight (out of office until 8/21) [:mccr8]]

OOMs during layout tests are more of a layout issue.

Comment 2

[Intermittent Failures Robot]

1 failures in 4128 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1674823&startday=2020-11-02&endday=2020-11-08&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 4060 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2020-12-07&endday=2020-12-13&tree=all

Comment 4

[Intermittent Failures Robot]

1 failures in 3488 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-01-18&endday=2021-01-24&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 3891 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-01-25&endday=2021-01-31&tree=all

Comment 6

[Intermittent Failures Robot]

3 failures in 3966 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform and build breakdown:

• windows7-32: 3
  • debug: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-02-01&endday=2021-02-07&tree=all

Comment 7

[Intermittent Failures Robot]

1 failures in 4322 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-02-08&endday=2021-02-14&tree=all

Comment 8

[Intermittent Failures Robot]

1 failures in 3737 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-02-15&endday=2021-02-21&tree=all

Comment 9

[Intermittent Failures Robot]

2 failures in 4327 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• windows7-32: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-02-22&endday=2021-02-28&tree=all

Comment 10

[Intermittent Failures Robot]

3 failures in 4622 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2
• mozilla-central: 1

Platform and build breakdown:

• windows7-32: 2
  • debug: 2
• windows10-64: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-03-08&endday=2021-03-14&tree=all

Comment 11

[Alexandru Michis [:malexandru]]

Daniel, there have been instances of this failure appearing alongside a massive log, caused by lines like:
"INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in about:blank"
(See: https://firefox-ci-tc.services.mozilla.com/tasks/SpnDArpFTaOEOfAlDUqWVg
https://firefox-ci-tc.services.mozilla.com/tasks/XE3UXF6VQQGVr2tRb9jD7A)

Should a new bug be filled for this issue? Or is this caused by the crash itself?

Comment 12

[Daniel Holbert [:dholbert]]

That's a version of the same bug, I think. It looks like we just never call that crashtest "finished", because it keeps changing its rendering, and so we always have a pending paint that we need to flush before we call it done. I think the massive amounts of logging here are associated with the unending string of paints that we've observed, I think.

The testcase is making us run out of memory because it keeps appending to the src attribute of an iframe (on a recurring 1-second setInterval), forever. So if we let it keep going indefinitely, then eventually we'll run out of memory.

The most direct fix here is probably to just limit the number of times that we let the setInterval run.

Comment 13

[Daniel Holbert [:dholbert]]

Attachment: Bug 1674823: Adjust crashtest 370174-4.html to have an upper-bound on how many times its setInterval can fire. r?#layout-reviewers

This test doesn't use "reftest-wait", so really, we should be able to load it
and move on without even caring about its setInterval. But occasionally we get
unlucky and see a still-pending paint (caused by the setInterval) every time we
make a decision about whether the test is done or not. Let's avoid this issue
by just setting an upper-bound of 10 iterations on the number of times we'll
let the setInterval fire.

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a87453821464
Adjust crashtest 370174-4.html to have an upper-bound on how many times its setInterval can fire. r=emilio

Comment 15

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/a87453821464

Comment 16

[Cosmin Sabou [:CosminS]]

Still failing after the merge to central: https://treeherder.mozilla.org/logviewer?job_id=333861442&repo=mozilla-central&lineNumber=46705
Daniel, could you have a look over this? Thank you.

Comment 17

[Daniel Holbert [:dholbert]]

I'm not sure what's happening there; my only other theory is that the randomly-positioned synthesized mouse event is hitting a location that's causing trouble somehow, which then causes this test to lose focus or continue painting for some reason.

I'm tempted to just remove this test, given that:
(1) it's only one of four tests that landed for the bug in question (so it's not removing test coverage for that bug)
(2) it's unlikely that it actually effectively tests what it's trying to test, given that it's using timeouts without reftest-wait
(3) in the scenarios where we do actually honor the timeouts (because we see that there are pending paints that we're also waiting for), the test is pretty wasteful with our test-harnesses' time. Timeouts themselves, especially full-second timeouts, and especially recurring ones, are an anti-pattern in automated tests.
(4) it uses display:-moz-inline-box in its iframe, which doesn't do anything in content processes (so it won't do anything in a crashtest)

Put another way: if we were fixing bug 370174 today and landing crashtests for it, I don't think we would include a crashtest with a 1-second setInterval, especially given that there are other crashtests for the same bug. So I can't really justify trying to maintain this test.

Comment 18

[Daniel Holbert [:dholbert]]

Attachment: Bug 1674823 part 2: Remove problematic and probably-ineffective crashtest 370174-4.html. r?emilio

This crashtest is timing out and OOM'ing on windows, probably in part because
it tries to append text to an iframe's URL forever.

Rather than spend time investigating those OOMs and diagnosing/polishing this
test, I think we should just remove this crashtest, because:

• It's unlikely that it ever served as an especially-effective regression test
  (given its use of timeouts without reftest-wait, which makes it prone to
  either completing immediately before having done anything, or having a
  fragile dependency on the presence of pending paints to determine when it
  completes).

• It's wasteful with our test-runners' time, when its timeouts are honored (we
  don't want individual tests to use up multiple seconds of CPU-time --
  particularly via timeouts where they're not doing anything -- unless
  absolutely necessary).

• There are three other crashtests that exist for the bug that it intends to be
  testing (so, to the extent that it tests something useful [which is unclear],
  we're still probably not losing coverage by removing it).

Comment 19

[Daniel Holbert [:dholbert]]

For reference, here's the relevant snippet of the log from comment 16 -- the test is loading and then we sit for several minutes and then OOM:

[task 2021-03-20T10:01:48.147Z] 10:01:48     INFO - REFTEST TEST-START | layout/generic/crashtests/370174-4.html
[task 2021-03-20T10:01:48.147Z] 10:01:48     INFO - REFTEST TEST-LOAD | file:///Z:/task_1616233166/build/tests/reftest/tests/layout/generic/crashtests/370174-4.html | 2179 / 3905 (55%)
[task 2021-03-20T10:05:22.287Z] 10:05:22     INFO - [Parent 3912, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1149
[task 2021-03-20T10:05:30.565Z] 10:05:30     INFO - out of memory: 0x0000000000000098 bytes requested
[task 2021-03-20T10:05:30.565Z] 10:05:30     INFO - Hit MOZ_CRASH() at /builds/worker/checkouts/gecko/memory/mozalloc/mozalloc_abort.cpp:33
[task 2021-03-20T10:05:30.568Z] 10:05:30    ERROR - TEST-UNEXPECTED-FAIL | layout/generic/crashtests/370174-4.html | application terminated with exit code 1

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/fe5192965fde
part 2: Remove problematic and probably-ineffective crashtest 370174-4.html. r=emilio

Comment 21

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/fe5192965fde

Comment 22

[Intermittent Failures Robot]

4 failures in 4257 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3
• mozilla-central: 1

Platform and build breakdown:

• windows7-32: 3
  • debug: 3
• windows10-64: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1674823&startday=2021-03-15&endday=2021-03-21&tree=all