Closed Bug 967758 Opened 6 years ago Closed 6 years ago

Intermittent test_add_put.html | application timed out after 330 seconds with no output | application crashed [@ nsIFrame::SchedulePaint(nsIFrame::PaintType)] (Assertion failure: pres->GetContainerWeak() (SchedulePaint in a detached pres context))

Categories

(Core :: Layout, defect, critical)

x86_64
macOS
defect
Not set
critical

Tracking

()

RESOLVED FIXED
mozilla30
Tracking Status
firefox28 --- unaffected
firefox29 --- unaffected
firefox30 --- fixed
firefox-esr24 --- unaffected

People

(Reporter: RyanVM, Assigned: tnikkel)

References

Details

(Keywords: assertion, crash, intermittent-failure)

Attachments

(1 file)

The merge this started on includes bug 946929 which seems like a good candidate.

https://tbpl.mozilla.org/php/getParsedLog.php?id=34078813&tree=Mozilla-Central

Rev5 MacOSX Mountain Lion 10.8 mozilla-central debug test mochitest-3 on 2014-02-04 11:59:07 PST for push 2e5880940469
slave: talos-mtnlion-r5-031

12:01:04     INFO -  0 INFO SimpleTest START
12:01:04     INFO -  1 INFO TEST-START | /tests/dom/indexedDB/test/test_add_put.html
12:01:04     INFO -  243 INFO TEST-PASS | /tests/dom/indexedDB/ipc/test_ipc.html | Got second iframe load event.
12:01:04     INFO -  ++DOMWINDOW == 9 (0x11622e158) [pid = 1186] [serial = 9] [outer = 0x105d7ce58]
12:01:04     INFO -  Assertion failure: pres->GetContainerWeak() (SchedulePaint in a detached pres context), at ../../../layout/generic/nsFrame.cpp:4899
12:01:06     INFO -  --DOMWINDOW == 30 (0x111e5df28) [pid = 1184] [serial = 128] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/WebStorage/tests/submissions/Ms2ger/test_storage_session_removeitem_js.html]
12:01:06     INFO -  --DOMWINDOW == 29 (0x1005d1e28) [pid = 1184] [serial = 129] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 28 (0x106cd6d68) [pid = 1184] [serial = 127] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 27 (0x123be92b8) [pid = 1184] [serial = 135] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 26 (0x108974c38) [pid = 1184] [serial = 126] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/WebStorage/tests/submissions/Ms2ger/test_storage_session_length_js.html]
12:01:06     INFO -  --DOMWINDOW == 25 (0x11d3581c8) [pid = 1184] [serial = 125] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 24 (0x112b68158) [pid = 1184] [serial = 133] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 23 (0x11d4763f8) [pid = 1184] [serial = 130] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/WebStorage/tests/submissions/Ms2ger/test_storage_session_setitem_js.html]
12:01:06     INFO -  --DOMWINDOW == 22 (0x1243ca4b8) [pid = 1184] [serial = 137] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 21 (0x112b04028) [pid = 1184] [serial = 131] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
12:01:06     INFO -  --DOMWINDOW == 20 (0x11d6e2fe8) [pid = 1184] [serial = 132] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/XMLHttpRequest/tests/submissions/Ms2ger/test_FormData-append.html]
12:01:06     INFO -  --DOMWINDOW == 19 (0x123ba9d58) [pid = 1184] [serial = 134] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/XMLHttpRequest/tests/submissions/Ms2ger/test_interfaces.html]
12:01:11     INFO -  --DOMWINDOW == 18 (0x11d41ba58) [pid = 1184] [serial = 124] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/WebStorage/tests/submissions/Ms2ger/test_storage_session_index_js.html]
12:01:11     INFO -  --DOMWINDOW == 17 (0x12219ada8) [pid = 1184] [serial = 122] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/WebStorage/tests/submissions/Ms2ger/test_storage_session_in_js.html]
12:01:13     INFO -  --DOMWINDOW == 16 (0x10dbed498) [pid = 1184] [serial = 136] [outer = 0x0] [url = http://mochi.test:8888/tests/dom/imptests/webapps/XMLHttpRequest/tests/submissions/Ms2ger/test_setrequestheader-invalid-arguments.htm]
12:01:21     INFO -  ###!!! [Parent][MessageChannel] Error: Channel error: cannot send/recv
12:01:21     INFO -  JavaScript error: chrome://browser/content/tabbrowser.xml, line 3202: browser.docShell is undefined
12:01:21     INFO -  [Parent 1184] WARNING: RemoveObserver() called for unregistered observer: file ../../hal/Hal.cpp, line 204
12:01:21     INFO -  [Parent 1184] WARNING: RemoveObserver() called for unregistered observer: file ../../hal/Hal.cpp, line 204
12:01:21     INFO -  [Parent 1184] WARNING: RemoveObserver() called for unregistered observer: file ../../hal/Hal.cpp, line 204
12:01:21     INFO -  [Parent 1184] WARNING: RemoveObserver() called for unregistered observer: file ../../hal/Hal.cpp, line 204
12:01:21     INFO -  [Parent 1184] WARNING: RemoveObserver() called for unregistered observer: file ../../hal/Hal.cpp, line 204
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x10db38840'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113917970'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113917970'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113917970'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113917970'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113bf6c00'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:01:37     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113917970'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:03:33     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x10db3e700'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:03:33     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x112b347b0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:03:33     INFO -  [Parent 1184] WARNING: 1 sort operation has occurred for the SQL statement '0x113b772e0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
12:09:03  WARNING -  TEST-UNEXPECTED-FAIL | /tests/dom/indexedDB/test/test_add_put.html | application timed out after 330 seconds with no output
12:09:04     INFO -  libpng warning: zero length keyword
12:09:04     INFO -  libpng warning: Empty language field in iTXt chunk
12:09:04  WARNING -  TEST-UNEXPECTED-FAIL | /tests/dom/indexedDB/test/test_add_put.html | application terminated with exit code 5
12:09:04     INFO -  INFO | runtests.py | Application ran for: 0:08:34.484082
12:09:04     INFO -  INFO | zombiecheck | Reading PID log: /var/folders/1c/kqj9vttd52ggtbc6jlj2t8fr00000w/T/tmpouYJ0gpidlog
12:09:18  WARNING -  PROCESS-CRASH | /tests/dom/indexedDB/test/test_add_put.html | application crashed [@ nsIFrame::SchedulePaint(nsIFrame::PaintType)]
12:09:18     INFO -  Crash dump filename: /var/folders/1c/kqj9vttd52ggtbc6jlj2t8fr00000w/T/tmpf1xN9P/minidumps/7E1F62D7-4F30-4A56-A86B-7607F8442F10.dmp
12:09:18     INFO -  Operating system: Mac OS X
12:09:18     INFO -                    10.8.0 12A269
12:09:18     INFO -  CPU: amd64
12:09:18     INFO -       family 6 model 42 stepping 7
12:09:18     INFO -       8 CPUs
12:09:18     INFO -  Crash reason:  EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
12:09:18     INFO -  Crash address: 0x0
12:09:18     INFO -  Thread 0 (crashed)
12:09:18     INFO -   0  XUL!nsIFrame::SchedulePaint(nsIFrame::PaintType) [nsFrame.cpp:2e5880940469 : 4899 + 0x0]
12:09:18     INFO -      rbx = 0x00007fff72f13c68   r12 = 0x0000000108aa8658
12:09:18     INFO -      r13 = 0x0000000108849400   r14 = 0x00000001090f4958
12:09:18     INFO -      r15 = 0x0000000000000000   rip = 0x0000000101c80b84
12:09:18     INFO -      rsp = 0x00007fff5fbfc150   rbp = 0x00007fff5fbfc180
12:09:18     INFO -      Found by: given as instruction pointer in context
12:09:18     INFO -   1  XUL!mozilla::LayerActivityTracker::NotifyExpired(mozilla::LayerActivity*) [ActiveLayerTracker.cpp:2e5880940469 : 118 + 0x9]
12:09:18     INFO -      rbx = 0x00000001059d2e20   r12 = 0x00000001059d0330
12:09:18     INFO -      r13 = 0x000000010a100e00   r14 = 0x00000001059d0358
12:09:18     INFO -      r15 = 0x00000001090f4958   rip = 0x0000000101b87806
12:09:18     INFO -      rsp = 0x00007fff5fbfc190   rbp = 0x00007fff5fbfc1b0
12:09:18     INFO -      Found by: call frame info
12:09:18     INFO -   2  XUL!nsExpirationTracker<mozilla::LayerActivity, 4u>::AgeOneGeneration() [nsExpirationTracker.h:2e5880940469 : 188 + 0xd]
12:09:18     INFO -      rbx = 0x0000000000000003   r12 = 0x00000001059d0330
12:09:18     INFO -      r13 = 0x000000010a100e00   r14 = 0x00000001059d0358
12:09:18     INFO -      r15 = 0x0000000000000003   rip = 0x0000000101bccd06
12:09:18     INFO -      rsp = 0x00007fff5fbfc1c0   rbp = 0x00007fff5fbfc1e0
12:09:18     INFO -      Found by: call frame info
12:09:18     INFO -   3  XUL!nsExpirationTracker<mozilla::LayerActivity, 4u>::TimerCallback(nsITimer*, void*) [nsExpirationTracker.h:2e5880940469 : 312 + 0x7]
12:09:18     INFO -      rbx = 0x0000000101bccfb0   r12 = 0x00000001059d2c80
12:09:18     INFO -      r13 = 0x000000010a100e00   r14 = 0x00000001059d0330
12:09:18     INFO -      r15 = 0x000000010a100e02   rip = 0x0000000101bccfc2
12:09:18     INFO -      rsp = 0x00007fff5fbfc1f0   rbp = 0x00007fff5fbfc200
12:09:18     INFO -      Found by: call frame info
12:09:18     INFO -   4  XUL!nsTimerImpl::Fire() [nsTimerImpl.cpp:2e5880940469 : 551 + 0x9]
12:09:18     INFO -      rbx = 0x0000000101bccfb0   r12 = 0x00000001059d2c80
12:09:18     INFO -      r13 = 0x000000010a100e00   r14 = 0x0000000000000002
12:09:18     INFO -      r15 = 0x000000010a100e02   rip = 0x00000001000b2019
12:09:18     INFO -      rsp = 0x00007fff5fbfc210   rbp = 0x00007fff5fbfc280
12:09:18     INFO -      Found by: call frame info
Group: core-security
Severity: normal → critical
Destroying the frame should destroy all its properties, and destroying the layer activity property should remove it from the expiration tracker. http://mxr.mozilla.org/mozilla-central/source/layout/base/ActiveLayerTracker.cpp#94 and following

So the frame should be alive here.
OK, good, so this is the same type of problem as bug 946929 then, i.e.
that the paint will run in a detached pres context.  So should we remove
this assertion and simply do an early return?  or should we check this
condition in NotifyExpired() instead and leave the assertion intact
(to find other offenders)?
Group: core-security
I think inbound is closed for this right now.
Indeed it is.
If it's that frequent maybe we should disable the assert for now and use try to investigate. I think the assert is just pointing out something that has been happening already for a while.
Attached patch disableassertSplinter Review
Mats is probably asleep, but we need to re-open inbound quickly.
Attachment #8370432 - Flags: review?(roc)
Looks to be about 10% frequent.
That should be enough to investigate on try. Up to the sheriffs if they want this patch to land or not (once it has review).
Comment on attachment 8370432 [details] [diff] [review]
disableassert

Review of attachment 8370432 [details] [diff] [review]:
-----------------------------------------------------------------

This is OK. It would be better to make it an NS_ASSERTION and annotate the failing tests to get the tree open.
Attachment #8370432 - Flags: review?(roc) → review+
I just did the straight disable right now because I can't commit to watching the tree to make sure all the proper annotations are in place right now.
https://hg.mozilla.org/integration/mozilla-inbound/rev/3e1c8c8f5d0f
Mats, are you planning to investigate this soon? If not we should make this into NS_ASSERTIONs and add annotations.
Flags: needinfo?(matspal)
https://hg.mozilla.org/mozilla-central/rev/3e1c8c8f5d0f
Assignee: nobody → tnikkel
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla30
AFAICT, all three incidents in this bug were for "SchedulePaint in a detached pres context".

Were there also any unreported incidents of "Invalidation in detached pres context"?
Flags: needinfo?(philringnalda)
(In reply to Timothy Nikkel (:tn) from comment #14)
> Mats, are you planning to investigate this soon? If not we should make this
> into NS_ASSERTIONs and add annotations.

I filed follow-up bug 968174 on that.
Depends on: 968174
Flags: needinfo?(matspal)
(In reply to Mats Palmgren (:mats) from comment #16)
> Were there also any unreported incidents of "Invalidation in detached pres
> context"?

Not that I'm aware of.
Flags: needinfo?(philringnalda)
Possibly related: bug 974905 is about a 100% reproducible failure of this assertion, just running reftest-sanity with IPC preferences turned on.
You need to log in before you can comment on or make changes to this bug.