Closed Bug 1062472 Opened 10 years ago Closed 3 years ago

PHttpChannelParent sends OnStartRequest/OnStopRequest after PBrowserChild is destroyed


(Core :: Networking, defect, P5)






(Reporter: mccr8, Unassigned)



(Whiteboard: [necko-backlog])


(1 file)

This happens, I think, in dom/browser-element/mochitest/priority/test_BackgroundLRU.html

This in turn causes us to not get leak logs for this process.  Here's some info from the log, with the NS_WARNING turned into an NS_ASSERTION in the content child abort code, but there's not a lot to go on.

329 INFO [Child 6178] WARNING: NS_ENSURE_TRUE(inBrowser) failed: file /home/amccreight/mc/embedding/browser/nsDocShellTreeOwner.cpp, line 82
331 INFO ###!!! [Child][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
332 INFO [Child 6178] ###!!! ASSERTION: content process _exit()ing: 'false', file /home/amccreight/mc/dom/ipc/ContentChild.cpp, line 1500
333 INFO mozilla::dom::ContentChild::QuickExit() (/home/amccreight/mc/dom/ipc/ContentChild.cpp:1500)
334 INFO mozilla::dom::ContentChild::ProcessingError(mozilla::ipc::HasResultCodes::Result) (/home/amccreight/mc/dom/ipc/ContentChild.cpp:1477)
335 INFO mozilla::dom::PContentChild::OnProcessingError(mozilla::ipc::HasResultCodes::Result) (/tmp/./PContentChild.cpp:5329)
336 INFO mozilla::ipc::MessageChannel::ReportConnectionError(char const*) const (/home/amccreight/mc/ipc/glue/MessageChannel.cpp:1558)
337 INFO mozilla::ipc::MessageChannel::DequeueOne(IPC::Message*) (/home/amccreight/mc/ipc/glue/MessageChannel.cpp:1045)
338 INFO mozilla::ipc::MessageChannel::OnMaybeDequeueOne() (/home/amccreight/mc/ipc/glue/MessageChannel.cpp:1080)
339 INFO void DispatchToMethod<mozilla::ipc::MessageChannel, bool (mozilla::ipc::MessageChannel::*)()>(mozilla::ipc::MessageChannel*, bool (mozilla::ipc::MessageChannel::*)(), Tuple0 const&) (/home/amccreight/mc/ipc/chromium/src/base/tuple.h:384)
340 INFO RunnableMethod<mozilla::ipc::MessageChannel, bool (mozilla::ipc::MessageChannel::*)(), Tuple0>::Run() (/home/amccreight/mc/ipc/chromium/src/base/task.h:308)
341 INFO mozilla::ipc::MessageChannel::RefCountedTask::Run() (/home/amccreight/mc/obj-dbg/ipc/glue/../../dist/include/mozilla/ipc/MessageChannel.h:411)
342 INFO mozilla::ipc::MessageChannel::DequeueTask::Run() (/home/amccreight/mc/obj-dbg/ipc/glue/../../dist/include/mozilla/ipc/MessageChannel.h:428)
343 INFO MessageLoop::RunTask(Task*) (/home/amccreight/mc/ipc/chromium/src/base/
344 INFO MessageLoop::DeferOrRunPendingTask(MessageLoop::PendingTask const&) (/home/amccreight/mc/ipc/chromium/src/base/
345 INFO MessageLoop::DoWork() (/home/amccreight/mc/ipc/chromium/src/base/
346 INFO mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) (/home/amccreight/mc/ipc/glue/MessagePump.cpp:297)
347 INFO MessageLoop::RunInternal() (/home/amccreight/mc/ipc/chromium/src/base/
348 INFO MessageLoop::RunHandler() (/home/amccreight/mc/ipc/chromium/src/base/
349 INFO MessageLoop::Run() (/home/amccreight/mc/ipc/chromium/src/base/
350 INFO nsBaseAppShell::Run() (/home/amccreight/mc/widget/xpwidgets/nsBaseAppShell.cpp:164)
351 INFO XRE_RunAppShell (/home/amccreight/mc/toolkit/xre/nsEmbedFunctions.cpp:702)
352 INFO mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) (/home/amccreight/mc/ipc/glue/MessagePump.cpp:272)
353 INFO MessageLoop::RunInternal() (/home/amccreight/mc/ipc/chromium/src/base/
354 INFO MessageLoop::RunHandler() (/home/amccreight/mc/ipc/chromium/src/base/
355 INFO MessageLoop::Run() (/home/amccreight/mc/ipc/chromium/src/base/
356 INFO XRE_InitChildProcess (/home/amccreight/mc/toolkit/xre/nsEmbedFunctions.cpp:539)
357 INFO content_process_main(int, char**) (/home/amccreight/mc/ipc/app/../contentproc/plugin-container.cpp:150)
Kyle said this stack looks like something is sending us a message and it is too late, and that I should use IPC logging to figure out what the message is.
I bet it's either DataStore (bug 1037625, oops!) or WebApps (bug 1035454)
Attached file IPDL log
It looks more like PHttpChannel to me:
  [PHttpChannelParent] Received Msg_Cancel([TODO])
  [PRenderFrameParent] Received Msg___delete__([TODO])
  [PBrowserParent] Received Msg___delete__([TODO])
  [PHttpChannelParent] Sending Msg_OnStartRequest([TODO])
  [PHttpChannelParent] Sending Msg_OnStopRequest([TODO])
Hrm, yeah. Looks like... Jason might want to see this.
Jason, do you have some ideas here?  I guess PBrowserParent could tell PHttpeChannelParent to not send anything to the child after it is destroyed?
Component: DOM: Content Processes → Networking
Flags: needinfo?(jduell.mcbugs)
Summary: child process attempts to send/recv too late, causing content process abort → PHttpChannelParent sends OnStartRequest/OnStopRequest after PBrowserChild is destroyed
PBrowser being deleted does not indicate anything particularly actionable from the point of view of the HTTP channel. We probably want a closing/ack dance to occur when the child process knows it's shutting down, after which the parent transport should refuse to send any more messages. Until the ack is received, the child could just discard messages silently.
Hmm, it is possible that one of my other patches is causing the child to send Cancel where it wasn't before, thereby triggering this issue, as I'm not seeing this failure on trunk.  I'll try to figure out if that's the case.  I might be able to just prevent that.
Flags: needinfo?(jduell.mcbugs)
Well, so this particular case is in TabChild::BrowserFrameProvideWindow, where we create a new TabChild, then decide we don't need it, so we tear it down.  Maybe it is some weird half-setup stage, which is why we get this error.  Without running the tear down (DestroyWindow()), we leak, and maybe by leaking the TabChild, we keep it alive long enough to get the message, or some other mechanism is stopping PHttpChannelParent.
Blocks: 1051230
No longer blocks: 831223
Blocks: 1083897
No longer blocks: 1051230
Blocks: 1067633
No longer blocks: 1083897
Whiteboard: [necko-backlog]
Bulk change to priority:
Priority: -- → P1
Bulk change to priority:
Priority: P1 → P3

Bulk-downgrade of unassigned, untouched DOM/Storage bug's priority.

If you have reason to believe, this is wrong, please write a comment and ni :jstutte.

Severity: normal → S4
Priority: P3 → P5

This test is gone and I got debug content processes working a long time ago, so eh.

Closed: 3 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.