Closed Bug 1377471 Opened 8 years ago Closed 8 years ago

Intermittent TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::net::HttpChannelChild::ConnectParent, mozilla::net::HttpChannelChild::Redirect1Begin, mozilla::net::Redirect1Event::Run

Categories

(Core :: Networking, defect)

Product:
Core
Component:
Networking
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla56
Tracking Flags:
Tracking Status
firefox56 --- fixed

People

(Reporter: aryx, Assigned: schien)

References

Details

(Keywords: intermittent-failure, Whiteboard: [necko-active][PBg-HTTP-M3] [stockwell fixed:product])

Attachments

(1 file, 2 obsolete files)

Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown.
59 bytes, text/x-review-board-request
mayhemer
: review+
Details
https://treeherder.mozilla.org/logviewer.html#?job_id=111052964&repo=autoland [task 2017-06-30T07:43:02.810415Z] 07:43:02 INFO - TEST-OK | dom/workers/test/test_workersDisabled.html | took 601ms [task 2017-06-30T07:43:02.990713Z] 07:43:02 INFO - TEST-START | Shutdown [task 2017-06-30T07:43:02.994314Z] 07:43:02 INFO - Passed: 1967 [task 2017-06-30T07:43:02.994614Z] 07:43:02 INFO - Failed: 0 [task 2017-06-30T07:43:02.996652Z] 07:43:02 INFO - Todo: 9 [task 2017-06-30T07:43:02.998471Z] 07:43:02 INFO - Mode: e10s [task 2017-06-30T07:43:03.021878Z] 07:43:03 INFO - Slowest: 13339ms - /tests/dom/workers/test/test_subworkers_suspended.html [task 2017-06-30T07:43:03.025558Z] 07:43:03 INFO - SimpleTest FINISHED [task 2017-06-30T07:43:03.032984Z] 07:43:03 INFO - TEST-INFO | Ran 1 Loops [task 2017-06-30T07:43:03.034752Z] 07:43:03 INFO - SimpleTest FINISHED [task 2017-06-30T07:43:03.196141Z] 07:43:03 INFO - GECKO(2877) | 1498808583150 addons.xpi WARN Exception running bootstrap method shutdown on special-powers@mozilla.org: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]" nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)" location: "JS frame :: resource://gre/modules/RemoteAddonsParent.jsm :: ObserverInterposition.methods.removeObserver :: line 403" data: no] Stack trace: ObserverInterposition.methods.removeObserver()@resource://gre/modules/RemoteAddonsParent.jsm:403 < interposeProperty/desc.value()@jar:file:///builds/worker/workspace/build/application/firefox/omni.ja!/components/multiprocessShims.js:157 < SpecialPowersObserver.prototype.uninit/<()@SpecialPowersObserver.jsm:134 < SpecialPowersObserver.prototype.uninit()@SpecialPowersObserver.jsm:133 < shutdown()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///tmp/tmptyG5lF.mozrunner/extensions/special-powers@mozilla.org.xpi!/bootstrap.js:35 < callBootstrapMethod()@resource://gre/modules/addons/XPIProvider.jsm:4418 < observe()@resource://gre/modules/addons/XPIProvider.jsm:2307 < SpecialPowersObserver.prototype.receiveMessage()@SpecialPowersObserver.jsm:241 [task 2017-06-30T07:43:10.309056Z] 07:43:10 INFO - GECKO(2877) | ----------------------------------------------------- [task 2017-06-30T07:43:10.311754Z] 07:43:10 INFO - GECKO(2877) | Suppressions used: [task 2017-06-30T07:43:10.313181Z] 07:43:10 INFO - GECKO(2877) | count bytes template [task 2017-06-30T07:43:10.315572Z] 07:43:10 INFO - GECKO(2877) | 694 22152 nsComponentManagerImpl [task 2017-06-30T07:43:10.317792Z] 07:43:10 INFO - GECKO(2877) | 2 288 mozJSComponentLoader::LoadModule [task 2017-06-30T07:43:10.321272Z] 07:43:10 INFO - GECKO(2877) | 2 288 libfontconfig.so [task 2017-06-30T07:43:10.323558Z] 07:43:10 INFO - GECKO(2877) | 4 2068 libglib-2.0.so [task 2017-06-30T07:43:10.325576Z] 07:43:10 INFO - GECKO(2877) | ----------------------------------------------------- [task 2017-06-30T07:43:11.425595Z] 07:43:11 INFO - GECKO(2877) | ================================================================= [task 2017-06-30T07:43:11.431760Z] 07:43:11 INFO - GECKO(2877) | ==2918==ERROR: LeakSanitizer: detected memory leaks [task 2017-06-30T07:43:11.433364Z] 07:43:11 INFO - GECKO(2877) | Indirect leak of 72 byte(s) in 1 object(s) allocated from: [task 2017-06-30T07:43:11.435168Z] 07:43:11 INFO - GECKO(2877) | #0 0x4bb9ec in malloc /builds/slave/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:64:3 [task 2017-06-30T07:43:11.440137Z] 07:43:11 INFO - GECKO(2877) | #1 0x4ecf0d in moz_xmalloc /builds/worker/workspace/build/src/memory/mozalloc/mozalloc.cpp:83:17 [task 2017-06-30T07:43:11.442414Z] 07:43:11 INFO - GECKO(2877) | #2 0x7fd595833956 in operator new /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/mozalloc.h:194:12 [task 2017-06-30T07:43:11.448035Z] 07:43:11 INFO - GECKO(2877) | #3 0x7fd595833956 in mozilla::net::HttpChannelChild::ConnectParent(unsigned int) /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp:1933 [task 2017-06-30T07:43:11.454122Z] 07:43:11 INFO - GECKO(2877) | #4 0x7fd59582f0fb in mozilla::net::HttpChannelChild::Redirect1Begin(unsigned int const&, mozilla::ipc::URIParams const&, unsigned int const&, mozilla::net::nsHttpResponseHead const&, nsACString const&, unsigned long const&) /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp:1630:30 [task 2017-06-30T07:43:11.464571Z] 07:43:11 INFO - GECKO(2877) | #5 0x7fd5958fae7f in mozilla::net::Redirect1Event::Run() /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp:1501:13 [task 2017-06-30T07:43:11.469231Z] 07:43:11 INFO - GECKO(2877) | Indirect leak of 48 byte(s) in 1 object(s) allocated from: [task 2017-06-30T07:43:11.477764Z] 07:43:11 INFO - GECKO(2877) | #0 0x4bb9ec in malloc /builds/slave/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:64:3 [task 2017-06-30T07:43:11.480369Z] 07:43:11 INFO - GECKO(2877) | #1 0x4ecf0d in moz_xmalloc /builds/worker/workspace/build/src/memory/mozalloc/mozalloc.cpp:83:17 [task 2017-06-30T07:43:11.491504Z] 07:43:11 INFO - GECKO(2877) | #2 0x7fd5957d5dd6 in operator new /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/mozalloc.h:194:12 [task 2017-06-30T07:43:11.495062Z] 07:43:11 INFO - GECKO(2877) | #3 0x7fd5957d5dd6 in NS_NewRunnableFunction<(lambda at /builds/worker/workspace/build/src/netwerk/protocol/http/HttpBackgroundChannelChild.cpp:446:63)> /builds/worker/workspace/build/src/obj-firefox/dist/include/nsThreadUtils.h:630 [task 2017-06-30T07:43:11.499066Z] 07:43:11 INFO - GECKO(2877) | #4 0x7fd5957d5dd6 in mozilla::net::HttpBackgroundChannelChild::ActorDestroy(mozilla::ipc::IProtocol::ActorDestroyReason) /builds/worker/workspace/build/src/netwerk/protocol/http/HttpBackgroundChannelChild.cpp:445 [task 2017-06-30T07:43:11.519776Z] 07:43:11 INFO - GECKO(2877) | #5 0x7fd595d19bdd in mozilla::ipc::PBackgroundChild::DestroySubtree(mozilla::ipc::IProtocol::ActorDestroyReason) /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PBackgroundChild.cpp:2205:24 [task 2017-06-30T07:43:11.523658Z] 07:43:11 INFO - GECKO(2877) | #6 0x7fd595d17f12 in mozilla::ipc::PBackgroundChild::OnChannelClose() /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PBackgroundChild.cpp:2030:5 [task 2017-06-30T07:43:11.525657Z] 07:43:11 INFO - GECKO(2877) | Indirect leak of 16 byte(s) in 1 object(s) allocated from: [task 2017-06-30T07:43:11.530150Z] 07:43:11 INFO - GECKO(2877) | #0 0x4bb9ec in malloc /builds/slave/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:64:3 [task 2017-06-30T07:43:11.533418Z] 07:43:11 INFO - GECKO(2877) | #1 0x4ecf0d in moz_xmalloc /builds/worker/workspace/build/src/memory/mozalloc/mozalloc.cpp:83:17 [task 2017-06-30T07:43:11.536949Z] 07:43:11 INFO - GECKO(2877) | #2 0x7fd594c508e4 in Malloc /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray.h:209:46 [task 2017-06-30T07:43:11.542275Z] 07:43:11 INFO - GECKO(2877) | #3 0x7fd594c508e4 in nsTArrayInfallibleAllocator::ResultTypeProxy nsTArray_base<nsTArrayInfallibleAllocator, nsTArray_CopyWithMemutils>::EnsureCapacity<nsTArrayInfallibleAllocator>(unsigned long, unsigned long) /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray-inl.h:136 [task 2017-06-30T07:43:11.549352Z] 07:43:11 INFO - GECKO(2877) | #4 0x7fd5957d5f5b in AppendElement<already_AddRefed<mozilla::Runnable>, nsTArrayInfallibleAllocator> /builds/worker/workspace/build/src/obj-firefox/dist/include/nsTArray.h:2198:47 [task 2017-06-30T07:43:11.551763Z] 07:43:11 INFO - GECKO(2877) | #5 0x7fd5957d5f5b in mozilla::net::HttpBackgroundChannelChild::ActorDestroy(mozilla::ipc::IProtocol::ActorDestroyReason) /builds/worker/workspace/build/src/netwerk/protocol/http/HttpBackgroundChannelChild.cpp:445 [task 2017-06-30T07:43:11.557219Z] 07:43:11 INFO - GECKO(2877) | #6 0x7fd595d19bdd in mozilla::ipc::PBackgroundChild::DestroySubtree(mozilla::ipc::IProtocol::ActorDestroyReason) /builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/PBackgroundChild.cpp:2205:24 [task 2017-06-30T07:43:11.559456Z] 07:43:11 INFO - GECKO(2877) | ----------------------------------------------------- [task 2017-06-30T07:43:11.561388Z] 07:43:11 INFO - GECKO(2877) | Suppressions used: [task 2017-06-30T07:43:11.563381Z] 07:43:11 INFO - GECKO(2877) | count bytes template [task 2017-06-30T07:43:11.569586Z] 07:43:11 INFO - GECKO(2877) | 715 22768 nsComponentManagerImpl [task 2017-06-30T07:43:11.573221Z] 07:43:11 INFO - GECKO(2877) | 7 1008 mozJSComponentLoader::LoadModule [task 2017-06-30T07:43:11.575304Z] 07:43:11 INFO - GECKO(2877) | 611 17713 libfontconfig.so [task 2017-06-30T07:43:11.579660Z] 07:43:11 INFO - GECKO(2877) | 1 72 nss_ClearErrorStack [task 2017-06-30T07:43:11.584874Z] 07:43:11 INFO - GECKO(2877) | 16 2316 libglib-2.0.so [task 2017-06-30T07:43:11.586997Z] 07:43:11 INFO - GECKO(2877) | ----------------------------------------------------- [task 2017-06-30T07:43:11.590236Z] 07:43:11 INFO - GECKO(2877) | SUMMARY: AddressSanitizer: 136 byte(s) leaked in 3 allocation(s). [task 2017-06-30T07:43:14.386706Z] 07:43:14 INFO - GECKO(2877) | ----------------------------------------------------- [task 2017-06-30T07:43:14.388778Z] 07:43:14 INFO - GECKO(2877) | Suppressions used: [task 2017-06-30T07:43:14.390162Z] 07:43:14 INFO - GECKO(2877) | count bytes template [task 2017-06-30T07:43:14.391566Z] 07:43:14 INFO - GECKO(2877) | 716 22816 nsComponentManagerImpl [task 2017-06-30T07:43:14.392944Z] 07:43:14 INFO - GECKO(2877) | 50 7200 mozJSComponentLoader::LoadModule [task 2017-06-30T07:43:14.394333Z] 07:43:14 INFO - GECKO(2877) | 1 384 pixman_implementation_lookup_composite [task 2017-06-30T07:43:14.395711Z] 07:43:14 INFO - GECKO(2877) | 611 17509 libfontconfig.so [task 2017-06-30T07:43:14.396846Z] 07:43:14 INFO - GECKO(2877) | 1 32 libdl.so [task 2017-06-30T07:43:14.398354Z] 07:43:14 INFO - GECKO(2877) | 17 4348 libglib-2.0.so [task 2017-06-30T07:43:14.401347Z] 07:43:14 INFO - GECKO(2877) | 1 28 libresolv.so [task 2017-06-30T07:43:14.403456Z] 07:43:14 INFO - GECKO(2877) | ----------------------------------------------------- [task 2017-06-30T07:43:14.709286Z] 07:43:14 INFO - TEST-INFO | Main app process: exit 0 [task 2017-06-30T07:43:14.711831Z] 07:43:14 INFO - TEST-INFO | LeakSanitizer | To show the addresses of leaked objects add report_objects=1 to LSAN_OPTIONS [task 2017-06-30T07:43:14.715310Z] 07:43:14 INFO - TEST-INFO | LeakSanitizer | This can be done in testing/mozbase/mozrunner/mozrunner/utils.py [task 2017-06-30T07:43:14.717663Z] 07:43:14 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at mozilla::net::HttpChannelChild::ConnectParent, mozilla::net::HttpChannelChild::Redirect1Begin, mozilla::net::Redirect1Event::Run [task 2017-06-30T07:43:14.720288Z] 07:43:14 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at NS_NewRunnableFunction, mozilla::net::HttpBackgroundChannelChild::ActorDestroy, mozilla::ipc::PBackgroundChild::DestroySubtree, mozilla::ipc::PBackgroundChild::OnChannelClose [task 2017-06-30T07:43:14.726119Z] 07:43:14 ERROR - TEST-UNEXPECTED-FAIL | LeakSanitizer | leak at Malloc, nsTArray_base, AppendElement, mozilla::net::HttpBackgroundChannelChild::ActorDestroy
maybe related to bug 1338493.
Assignee: nobody → schien
Whiteboard: [necko-active][PBg-HTTP-M3]
confirmed that it is caused by my patch on bug 1338493. I got my uncompleted revision uploaded.
Comment on attachment 8882659 [details] Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. https://reviewboard.mozilla.org/r/153724/#review158910 This needs a good description of what the cause of the bug exactly is and how the patches fixes it and why.
Attachment #8882659 - Flags: review?(honzab.moz) → review-
Comment on attachment 8882659 [details] Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. https://reviewboard.mozilla.org/r/153724/#review158910 It is really my bad that I landed a uncomplete patch so the previous code doesn't make any sense at all. The new code is the correct one to address your previous review comment on ensuring mChannelChild is touched on STS thread (see bug 1338493 comment #14).
Comment on attachment 8882659 [details] Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. https://reviewboard.mozilla.org/r/153724/#review159122 ::: netwerk/protocol/http/HttpBackgroundChannelChild.cpp:443 (Diff revision 2) > > if (!OnSocketThread()) { > // PBackgroundChild might be destroyed during shutdown and > // ActorDestroy will be called on main thread directly. > - // Simply disconnect with HttpChannelChild to release memory. > - mChannelChild = nullptr; > + // Try disconnect mChannelChild on STS thread. > + MOZ_RELEASE_ASSERT(gSocketTransportService); IMPO, this is too restrictive. if there is no sts thread, can you release on the main or just let it leak (the latter preferred)? ::: netwerk/protocol/http/HttpBackgroundChannelChild.cpp:455 (Diff revision 2) > - self->mChannelChild = nullptr; > + self->mChannelChild = nullptr; > - })); > + }), NS_DISPATCH_NORMAL); > + > + // If failed to do this on STS thread, disconnect mChannelChild immediately. > + if (NS_WARN_IF(NS_FAILED(rv))) { > + mChannelChild = nullptr; not sure what is the real cause of bug 1377471, apparently you were releasing the channel so why there is a leak and not a crash which I would expect more likely?
Attachment #8882659 - Flags: review?(honzab.moz) → review+
Can this land now? (I'm eager for a fix since this is failing very frequently.)
Flags: needinfo?(schien)
Whiteboard: [necko-active][PBg-HTTP-M3] → [necko-active][PBg-HTTP-M3] [stockwell needswork]
Comment on attachment 8882659 [details] Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. https://reviewboard.mozilla.org/r/153724/#review159122 > IMPO, this is too restrictive. if there is no sts thread, can you release on the main or just let it leak (the latter preferred)? sure, I can change to `if (!gSocketTransportService) { return; }` to let it leak. > not sure what is the real cause of bug 1377471, apparently you were releasing the channel so why there is a leak and not a crash which I would expect more likely? The leakage is on HttpBackgroundChannelChild object but not HttpChannelChild. The HttpBackgroundChannelChild object is self referenced by the mQueuedRunnables array.
(In reply to Geoff Brown [:gbrown] from comment #11) > Can this land now? (I'm eager for a fix since this is failing very > frequently.) Sorry for the delay. I am out off office few days ago. Plan to land this patch today with some more tests.
Flags: needinfo?(schien)
Pushed by schien@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/21d595faf0db disconnect HttpChannelChild and its background channel on STS thread. r=mayhemer
sorry, backed out for failures like https://treeherder.mozilla.org/logviewer.html#?job_id=112186320&repo=autoland
Flags: needinfo?(schien)
Backout by cbook@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/a38e794472d8 Backed out changeset 21d595faf0db for Assertion failure: NS_IsMainThread(), at /home/worker/workspace/build/src/netwerk/protocol/http/HttpBackgroundChannelChild.cpp:443
@mayhemer, my previous analysis is not wrong and HttpBackgroundChannelChild::ActorDestroy is still called on STS thread. However OnSocketThread() will return false if it is called during shutdown phase. I request another run of review since there is a major logic change in my patch.
Flags: needinfo?(schien)
Attachment #8882659 - Flags: review+ → review?(honzab.moz)
Attachment #8882659 - Attachment is obsolete: true
Attachment #8882659 - Flags: review?(honzab.moz)
Attachment #8884493 - Attachment is obsolete: true
Attachment #8884493 - Flags: review?(honzab.moz)
Comment on attachment 8884496 [details] Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. https://reviewboard.mozilla.org/r/155396/#review161390 ::: commit-message-0b560:5 (Diff revision 1) > +Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. r?mayhemer > + > +HttpBackgroundChannelChild::ActorDestroy is always called on STS thread. However OnSocketThread will return wrong > +result during shutdown phase. In this case we need to use gSocketTransportService->IsOnCurrentThreadInfallible() > +if the can be execute during shutdown phase. In addition, we should disconnect mChannelChild immediately while "if the can be execute during shutdown phase" looks misspelled ::: netwerk/protocol/http/HttpBackgroundChannelChild.cpp (Diff revision 1) > + // might return false even on STS thread. Use IsOnCurrentThreadInfallible() > + // to get correct information. > + MOZ_ASSERT(gSocketTransportService); > + MOZ_ASSERT(gSocketTransportService->IsOnCurrentThreadInfallible()); > > - if (!OnSocketThread()) { So, this is posted to the socket thread after [1] (main thread is at/after [2]). During the xpcom shutdown we leave the sts thread live (something I was not aware of). Makes sense. [1] https://dxr.mozilla.org/mozilla-central/rev/b07db5d650b7056c78ba0dbc409d060ec4e922cd/netwerk/base/nsSocketTransportService2.cpp#1039 [2] https://dxr.mozilla.org/mozilla-central/rev/b07db5d650b7056c78ba0dbc409d060ec4e922cd/netwerk/base/nsIOService.cpp#1153
Attachment #8884496 - Flags: review?(honzab.moz) → review+
Comment on attachment 8884496 [details] Bug 1377471 - disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. https://reviewboard.mozilla.org/r/155396/#review161390 > "if the can be execute during shutdown phase" > > looks misspelled fixed. > So, this is posted to the socket thread after [1] (main thread is at/after [2]). During the xpcom shutdown we leave the sts thread live (something I was not aware of). > > Makes sense. > > [1] https://dxr.mozilla.org/mozilla-central/rev/b07db5d650b7056c78ba0dbc409d060ec4e922cd/netwerk/base/nsSocketTransportService2.cpp#1039 > > [2] https://dxr.mozilla.org/mozilla-central/rev/b07db5d650b7056c78ba0dbc409d060ec4e922cd/netwerk/base/nsIOService.cpp#1153 Yes exactly. sts thread is killed until 'xpcom-shutdown-threa', which happens after 'xpcom-shutdown'. https://searchfox.org/mozilla-central/rev/31311070d9860b24fe4a7a36976c14b328c16208/xpcom/build/XPCOMInit.cpp#807
Pushed by schien@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/46fb242c49d8 disconnect mChannelChild directly if ActorDestroy is triggered by shutdown. r=mayhemer
https://hg.mozilla.org/mozilla-central/rev/46fb242c49d8
Status: NEW → RESOLVED
Closed: 8 years ago
status-firefox56: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla56
Whiteboard: [necko-active][PBg-HTTP-M3] [stockwell needswork] → [necko-active][PBg-HTTP-M3] [stockwell fixed:product]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: