1628399 - Intermittent browser/base/content/test/plugins/browser_pluginCrashCommentAndURL.js | The crash UI should be visible - false == true - got false, expected true (operator ==)

Status: RESOLVED FIXED

(Core Graveyard :: Plug-ins, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=296802494&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fmlPQD1jT3KG1w8HyX7maA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-04-08T13:43:27.756Z] 13:43:27 INFO - TEST-START | browser/base/content/test/plugins/browser_pluginCrashCommentAndURL.js
[task 2020-04-08T13:43:27.775Z] 13:43:27 INFO - GECKO(6716) | [Child 5064: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 00000137BFF2E000 == 3 [pid = 5064] [id = {56e3ade0-6967-4570-9206-d7c3d81015b5}]
[task 2020-04-08T13:43:27.775Z] 13:43:27 INFO - GECKO(6716) | [Child 5064: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 28 (00000137C5EE53C0) [pid = 5064] [serial = 104] [outer = 0000000000000000]
[task 2020-04-08T13:43:27.775Z] 13:43:27 INFO - GECKO(6716) | [Child 5064: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 29 (00000137BFFA3800) [pid = 5064] [serial = 105] [outer = 00000137C5EE53C0]
[task 2020-04-08T13:43:27.793Z] 13:43:27 INFO - GECKO(6716) | [Child 5064: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 30 (00000137C67A2400) [pid = 5064] [serial = 106] [outer = 00000137C5EE53C0]
[task 2020-04-08T13:43:27.884Z] 13:43:27 INFO - GECKO(6716) | hostRecordType: 0
[task 2020-04-08T13:43:27.910Z] 13:43:27 INFO - GECKO(6716) | [Child 5064: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 31 (00000137C67D4C00) [pid = 5064] [serial = 107] [outer = 00000137C5EE53C0]
[task 2020-04-08T13:43:27.932Z] 13:43:27 INFO - GECKO(6716) | [Parent 4040, Main Thread] WARNING: '!mName', file /builds/worker/checkouts/gecko/editor/libeditor/EditAggregateTransaction.cpp, line 92
[task 2020-04-08T13:43:27.933Z] 13:43:27 INFO - GECKO(6716) | [Parent 4040, Main Thread] WARNING: EditAggregationTransaction::GetName() failed: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/editor/libeditor/PlaceholderTransaction.cpp, line 217
[task 2020-04-08T13:43:27.933Z] 13:43:27 INFO - GECKO(6716) | [Parent 4040, Main Thread] WARNING: nsIAbsorbingTransaction::GetTxnName() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/PlaceholderTransaction.cpp, line 188
[task 2020-04-08T13:43:27.933Z] 13:43:27 INFO - GECKO(6716) | For application/x-test found plugin nptest.dll
[task 2020-04-08T13:43:27.943Z] 13:43:27 INFO - GECKO(6716) | XPCOM_MEM_BLOAT_LOG: c:\users\task_1586352835\appdata\local\temp\tmpjigbk5.mozrunner\runtests_leaks.log
[task 2020-04-08T13:43:27.943Z] 13:43:27 INFO - GECKO(6716) | Writing to log: c:\users\task_1586352835\appdata\local\temp\tmpjigbk5.mozrunner\runtests_leaks_plugin_pid6176.log
[task 2020-04-08T13:43:28.176Z] 13:43:28 INFO - GECKO(6716) | ###!!! [Parent][MessageChannel::Call] Error: Channel error: cannot send/recv
[task 2020-04-08T13:43:28.176Z] 13:43:28 INFO - GECKO(6716) | [Child 5064, Main Thread] WARNING: Failed to send message!: file /builds/worker/checkouts/gecko/dom/plugins/ipc/PluginScriptableObjectParent.cpp, line 248
[task 2020-04-08T13:43:28.176Z] 13:43:28 INFO - GECKO(6716) | [Parent 4040, Main Thread] WARNING: [PluginModuleParent::ActorDestroy] abnormal shutdown without minidump!: file /builds/worker/checkouts/gecko/dom/plugins/ipc/PluginModuleParent.cpp, line 1336
[task 2020-04-08T13:43:28.176Z] 13:43:28 INFO - GECKO(6716) | [Parent 4040, Main Thread] WARNING: '!aObserver', file /builds/worker/checkouts/gecko/xpcom/ds/nsObserverService.cpp, line 237
[task 2020-04-08T13:43:28.176Z] 13:43:28 INFO - GECKO(6716) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x6F001E,name=PPluginInstance::Msg_AsyncSetWindow) Channel error: cannot send/recv
[task 2020-04-08T13:43:28.200Z] 13:43:28 INFO - GECKO(6716) | [Child 5064, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp, line 3758
[task 2020-04-08T13:43:28.232Z] 13:43:28 INFO - TEST-INFO | started process screenshot
[task 2020-04-08T13:43:28.331Z] 13:43:28 INFO - TEST-INFO | screenshot: exit 0
[task 2020-04-08T13:43:28.331Z] 13:43:28 INFO - Buffered messages logged at 13:43:27
[task 2020-04-08T13:43:28.331Z] 13:43:28 INFO - Entering test bound
[task 2020-04-08T13:43:28.331Z] 13:43:28 INFO - Leaving test bound
[task 2020-04-08T13:43:28.331Z] 13:43:28 INFO - Entering test bound
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - Wait tab event: load
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - Tab event received: load
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - Buffered messages finished
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/plugins/browser_pluginCrashCommentAndURL.js | The crash UI should be visible - false == true - got false, expected true (operator ==)
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - Stack trace:
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - @chrome://mochitests/content/browser/browser/base/content/test/plugins/browser_pluginCrashCommentAndURL.js:88:12
[task 2020-04-08T13:43:28.332Z] 13:43:28 INFO - execute@resource://specialpowers/SpecialPowersSandbox.jsm:140:12
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.jsm:1729:15
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.jsm:281:21
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - JSWindowActor queryreceiveMessage@resource://specialpowers/SpecialPowersParent.jsm:1063:12
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - JSWindowActor queryspawn@resource://specialpowers/SpecialPowersChild.jsm:1684:17
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - @chrome://mochitests/content/browser/browser/base/content/test/plugins/browser_pluginCrashCommentAndURL.js:74:23
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - AsyncTester_execTest/<@chrome://mochikit/content/browser-test.js:1062:34
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - asyncTester_execTest@chrome://mochikit/content/browser-test.js:1097:11
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:925:14
[task 2020-04-08T13:43:28.333Z] 13:43:28 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:918:23
[task 2020-04-08T13:43:29.033Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0000014B752F0800) [pid = 9544] [serial = 35] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:29.033Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0000014B752ED400) [pid = 9544] [serial = 27] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:29.033Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0000014B752E7800) [pid = 9544] [serial = 32] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:29.051Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0000014B752E8000 == 4 [pid = 9544] [id = {e1ef51ab-9b71-4aee-8188-15183972696a}] [url = about:blank]
[task 2020-04-08T13:43:29.051Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0000014B752E7400 == 3 [pid = 9544] [id = {8b9bae72-d74b-49d8-9449-1cb1770d138a}] [url = http://example.com/]
[task 2020-04-08T13:43:29.051Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0000014B6EC4E400 == 2 [pid = 9544] [id = {8205954b-fdaa-4b45-a494-263e451295a2}] [url = about:blank]
[task 2020-04-08T13:43:29.051Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0000014B7764D800 == 1 [pid = 9544] [id = {17f6f57d-42fd-462a-8aae-191a1aac9214}] [url = http://example.com/]
[task 2020-04-08T13:43:29.093Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0000014B74EE1AC0) [pid = 9544] [serial = 31] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:29.093Z] 13:43:29 INFO - GECKO(6716) | [Child 9544: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0000014B76B57740) [pid = 9544] [serial = 28] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:29.559Z] 13:43:29 INFO - GECKO(6716) | [Parent 4040: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0000029031A84C00) [pid = 4040] [serial = 15] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:29.559Z] 13:43:29 INFO - GECKO(6716) | [Parent 4040: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (000002902B7BA000) [pid = 4040] [serial = 19] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (000001E643CFB400) [pid = 8184] [serial = 37] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (000001E6438B5C00) [pid = 8184] [serial = 34] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (000001E643CFB000) [pid = 8184] [serial = 45] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (000001E643CEF400) [pid = 8184] [serial = 41] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (000001E648167400) [pid = 8184] [serial = 49] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (000001E648170C00) [pid = 8184] [serial = 46] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.268Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (000001E643DAEC00) [pid = 8184] [serial = 42] [outer = 0000000000000000] [url = about:blank]
[task 2020-04-08T13:43:30.269Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 000001E643DB4400 == 1 [pid = 8184] [id = {95a56f6d-05f9-4ded-b741-a134148d8b5b}] [url = about:blank]
[task 2020-04-08T13:43:30.269Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 000001E6438B6000 == 0 [pid = 8184] [id = {92104892-bff3-4dd4-bb21-259d07151251}] [url = about:blank]
[task 2020-04-08T13:43:30.308Z] 13:43:30 INFO - GECKO(6716) | [Child 8184: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (000001E6438E43C0) [pid = 8184] [serial = 38] [outer = 0000000000000000] [url = about:blank]

Comment 1

[Noemi Erli[:noemi_erli]]

R/B range: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=0b4ef9402dd4b9a9d619e8d3b96d7696465f4aaa&tochange=4ad323ff378b0a5bc83f56129ecaf3a7d8b5b4d8&fromchange=75b820a68aa67577d62150335619555f29a86208&selectedJob=297194072

Gabriele, could this fail be triggered from the changes in Bug 1614933?

Comment 2

[Intermittent Failures Robot]

22 failures in 4823 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 17
• mozilla-central: 5

Platform breakdown:

• windows7-32: 6
• windows10-64-qr: 11
• windows7-32-shippable: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-04-06&endday=2020-04-12&tree=all

Comment 3

[Gabriele Svelto [:gsvelto]]

Yes, it could be. I'll try to have a look tomorrow. Leaving the NI? for now.

Comment 4

[Intermittent Failures Robot]

57 failures in 4528 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #16 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 8
• autoland: 47
• try: 2

Platform breakdown:

• windows7-32: 41
• windows7-32-shippable: 8
• windows10-64-qr: 7
• windows7-32-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-04-13&endday=2020-04-19&tree=all

Comment 5

[Intermittent Failures Robot]

16 failures in 955 pushes (0.017 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 15
• mozilla-central: 1

Platform breakdown:

• windows7-32: 11
• windows7-32-shippable: 3
• windows10-64-qr: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-04-20&endday=2020-04-20&tree=all

Comment 6

[Cristina Coroiu [:ccoroiu]]

This bug has 71 failures in the last 7 days on windows10-64-qr, windows7-32, windows7-32-shippable platforms, opt and debug build type.

Recent failure log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=298850227&repo=autoland&lineNumber=4339

Jim, can you please take a look at this?

Comment 7

[Gabriele Svelto [:gsvelto]]

I have to fix this and I don't think it's a terribly hard fix, but I'm struggling to find the time to do it.

Comment 8

[Intermittent Failures Robot]

48 failures in 5582 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #42 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 39
• mozilla-central: 7
• try: 2

Platform breakdown:

• windows7-32: 26
• windows7-32-shippable: 13
• windows10-64-qr: 8
• windows7-32-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-04-20&endday=2020-04-26&tree=all

Comment 9

[Stefan Hindli [:stefan_hindli]]

Over the last 7 days there are 41 failures present on this bug. These happen on windows10-64-qr, windows7-32 and windows7-32-shippable.
Here is the latest failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=300204861&repo=autoland&lineNumber=5765

Comment 10

[Gabriele Svelto [:gsvelto]]

This should be fixed by the patch I landed yesterday night in bug 1498706. Let's see if the volume declines, if it does not I'll have another look.

Comment 11

[Gabriele Svelto [:gsvelto]]

This is still happening so it's a different issue. Taking this.

Comment 12

[Intermittent Failures Robot]

54 failures in 5423 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #30 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 44
• try: 3
• mozilla-central: 7

Platform breakdown:

• windows7-32: 25
• windows7-32-shippable: 26
• windows10-64-qr: 1
• windows7-32-devedition: 1
• windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-04-27&endday=2020-05-03&tree=all

Comment 13

[Gabriele Svelto [:gsvelto]]

From the looks of it we're failing to write out the minidump for the plugin process. Given the timing and that it seems to be happening only on Windows then bug 1614933 is most definitely what regressed this. There was some more fallout from that bug and none of the other issues I fixed were causing the minidump not to be written. It's possibly that this is a race in the exception handler so I'll try following that lead while investigating this.

Comment 14

[Gabriele Svelto [:gsvelto]]

I managed to reproduce the race by manually injecting a delay in the exception handler. This looks like it's caused by bug 1624467 which I thought was Linux only but it's not.

Comment 15

[Gabriele Svelto [:gsvelto]]

Attachment: Bug 1628399 - Make sure that the main process can't access a crash report before it's fully populated

Comment 16

[Gabriele Svelto [:gsvelto]]

It seems that my patch fixes the problem: https://treeherder.mozilla.org/#/jobs?repo=try&revision=2157f186deab1a61116b647044cdb4c65bc01484

However I have to adapt it for Linux and macOS too before asking for review.

Comment 17

[Intermittent Failures Robot]

57 failures in 5276 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

This is the #22 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 46
• mozilla-beta: 5
• mozilla-central: 6

Platform breakdown:

• windows7-32-shippable: 19
• windows7-32: 31
• windows10-64-qr: 3
• windows7-32-devedition: 1
• windows10-64: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-05-04&endday=2020-05-10&tree=all

Comment 18

[Firefox Bug Husbandry Bot]

Because this bug's Severity has not been changed from the default since it was filed, and it's Priority is P3 (Backlog,) indicating it has been triaged, the bug's Severity is being updated to S3 (normal.)

Comment 19

[Intermittent Failures Robot]

40 failures in 5488 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

This is the #37 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• mozilla-central: 7
• try: 3
• autoland: 28
• mozilla-beta: 2

Platform breakdown:

• windows7-32: 9
• windows7-32-shippable: 25
• windows10-64: 2
• windows10-64-shippable-qr: 1
• windows10-64-qr: 2
• windows7-32-devedition: 1

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

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e5dc95633722
Make sure that the main process can't access a crash report before it's fully populated r=KrisWright

Comment 21

[Narcis Beleuzu [:NarcisB]]

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

Comment 23

[Gabriele Svelto [:gsvelto]]

Failure rate dropped to 0 on the 19th, this looks fixed for good.

Comment 24

[Intermittent Failures Robot]

9 failures in 4727 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 7
• mozilla-central: 2

Platform breakdown:

• windows10-64-qr: 1
• windows7-32-shippable: 4
• windows7-32: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1628399&startday=2020-05-18&endday=2020-05-24&tree=all