Closed Bug 1646592 Opened 4 years ago Closed 4 years ago

Sending endpoint of stream filter should not block main thread IPC

Categories

(Core :: Networking: HTTP, enhancement, P2)

enhancement

Tracking

()

RESOLVED FIXED
mozilla80
Tracking Status
firefox80 --- fixed

People

(Reporter: CuveeHsu, Assigned: CuveeHsu)

References

(Blocks 1 open bug)

Details

(Whiteboard: [necko-triaged])

Attachments

(4 files)

In bug 1633935, SendAttachStreamFilter is passed to child process on main thread IPC, which is racy with PHttpChannelBackground::OnStartRequest.

This hits the performance and we need to have a way to bring the endpoint information through pBackground given many extensions rely on stream filter.

Assignee: nobody → juhsu
See Also: → 1648132

Like bug 1647133, we need this to be nsISerialEventTarget for the InvokeAsync

Endpoint would be passed by a series of std::move via
nsHttpChannel -> HttpChannelParent -> HttpBackgroundChannelParent ---> HttpBackgroundChannelChild -> HttpChannelChild
|
|
Resolve promise after successfully send IPC<-/

Depends on D81273

Pushed by juhsu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/31aab78792d8
P1 Use nsISerialEventTarget for HttpBackgroundChannelParent,  r=valentin,necko-reviewers
https://hg.mozilla.org/integration/autoland/rev/de9ba1eaded1
P2 remove NeckoTargetChannelEvent which could not be specialized for HttpChannelChild, r=mayhemer,necko-reviewers
https://hg.mozilla.org/integration/autoland/rev/3a514b227127
P3 Sending endpoint of stream filter via PHttpBackgroundChannel, r=mayhemer,necko-reviewers
https://hg.mozilla.org/integration/autoland/rev/cc60e258290e
P4 Remove the depedency between OnStartRequestSent and AttachStreamFilter, r=mayhemer,necko-reviewers

Hello Lee,
I'm hitting this assertion but I'm not familiar with IPC code.
https://searchfox.org/mozilla-central/rev/5a4aaccb28665807a6fd49cf48367d47fbb5a19a/ipc/chromium/src/base/message_loop.cc#379

Does it mean we send IPC (or dispatch runnable) when firefox is shutting down? (or the IPC bridge is destoryed)
Thanks!

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=308055036&repo=autoland&lineNumber=4769


[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -  Thread 5 (crashed)
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -   0  XUL!MessageLoop::PostTask_Helper(already_AddRefed<nsIRunnable>, int) [message_loop.cc:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 397 + 0x29]
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      rax = 0x000000011d744106   rdx = 0x0000000000000000
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      rcx = 0x0000000107648480   rbx = 0x000070000cf0da90
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      rsi = 0x00000000000120a8   rdi = 0x00007fffb115c028
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      rbp = 0x000070000cf0da80   rsp = 0x000070000cf0da10
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -       r8 = 0x00000000000130a8    r9 = 0x00007fffb115c048
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      r10 = 0x0000000000000000   r11 = 0x00007fffb115c040
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      r12 = 0x0000000107850800   r13 = 0x00000001150ba600
[task 2020-06-30T18:22:13.233Z] 18:22:13     INFO -      r14 = 0x0000000000000000   r15 = 0x00007ffee8997778
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      rip = 0x00000001150b8964
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      Found by: given as instruction pointer in context
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -   1  XUL!MessageLoop::PostTask(already_AddRefed<nsIRunnable>) [message_loop.cc:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 365 + 0x19]
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      rbp = 0x000070000cf0daa0   rsp = 0x000070000cf0da90
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      rip = 0x00000001150b67bf
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -   2  XUL!mozilla::ipc::MessageChannel::PostErrorNotifyTask() [MessageChannel.cpp:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 2627 + 0x11]
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      rbp = 0x000070000cf0dad0   rsp = 0x000070000cf0dab0
[task 2020-06-30T18:22:13.234Z] 18:22:13     INFO -      rip = 0x000000011512843c
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -   3  XUL!mozilla::ipc::ProcessLink::OnChannelError() [MessageLink.cpp:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 357 + 0x9]
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      rbp = 0x000070000cf0db00   rsp = 0x000070000cf0dae0
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      rip = 0x000000011512afbc
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -   4  XUL!event_process_active_single_queue [event.c:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 1639 + 0xb1]
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      rbp = 0x000070000cf0db90   rsp = 0x000070000cf0db10
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      rip = 0x00000001150da673
[task 2020-06-30T18:22:13.235Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -   5  XUL!event_base_loop [event.c:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 1961 + 0xde]
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      rbp = 0x000070000cf0dc20   rsp = 0x000070000cf0dba0
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      rip = 0x00000001150d763c
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -   6  XUL!base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [message_pump_libevent.cc:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 0 + 0xe]
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      rbp = 0x000070000cf0dca0   rsp = 0x000070000cf0dc30
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      rip = 0x00000001150ba8fd
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -   7  XUL!MessageLoop::Run() [message_loop.cc:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 309 + 0x5]
[task 2020-06-30T18:22:13.236Z] 18:22:13     INFO -      rbp = 0x000070000cf0dcd0   rsp = 0x000070000cf0dcb0
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -      rip = 0x00000001150b7e6e
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -   8  XUL!base::Thread::ThreadMain() [thread.cc:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 192 + 0x8]
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -      rbp = 0x000070000cf0df00   rsp = 0x000070000cf0dce0
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -      rip = 0x00000001150c7fe3
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.237Z] 18:22:13     INFO -   9  XUL!ThreadFunc(void*) [platform_thread_posix.cc:cc60e258290ea538e6f63b60d1c3080917d0e5a9 : 40 + 0x6]
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      rbp = 0x000070000cf0df10   rsp = 0x000070000cf0df10
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      rip = 0x00000001150c232a
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -  10  libsystem_pthread.dylib!_pthread_body + 0x7e
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      rbp = 0x000070000cf0df30   rsp = 0x000070000cf0df20
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      rip = 0x00007fff7a9e82eb
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -  11  libsystem_pthread.dylib!_pthread_start + 0x42
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      rbp = 0x000070000cf0df50   rsp = 0x000070000cf0df40
[task 2020-06-30T18:22:13.238Z] 18:22:13     INFO -      rip = 0x00007fff7a9eb249
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -  12  libsystem_pthread.dylib!thread_start + 0xd
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -      rbp = 0x000070000cf0df78   rsp = 0x000070000cf0df60
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -      rip = 0x00007fff7a9e740d
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -      Found by: previous frame's frame pointer
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -  13  XUL!std::__1::__deque_base<MessageLoop::PendingTask, std::__1::allocator<MessageLoop::PendingTask> >::clear() [deque : 1195 + 0xf]
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -      rsp = 0x000070000cf0e090   rip = 0x00000001150c2320
[task 2020-06-30T18:22:13.239Z] 18:22:13     INFO -      Found by: stack scanning
Flags: needinfo?(juhsu) → needinfo?(lsalzman)

Here's a better stack

0:26.77 pid:2867 ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
 0:54.77 pid:2867 #01: MessageLoop::PostTask_Helper(already_AddRefed<nsIRunnable>, int) (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_loop.cc:397)
 0:54.77 pid:2867 #02: MessageLoop::PostTask(already_AddRefed<nsIRunnable>) (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_loop.cc:365)
 0:54.77 pid:2867 8)
 0:54.77 pid:2867 [Child 2886, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /Users/jhsu/mozilla-central/xpcom/base/nsCycleCollector.cpp, line 3359
 0:54.77 pid:2867 #04: mozilla::ipc::MessageChannel::OnChannelErrorFromLink() (/Users/jhsu/mozilla-central/ipc/glue/MessageChannel.cpp:2555)
 0:54.77 pid:2867 #05: mozilla::ipc::ProcessLink::OnChannelError() (/Users/jhsu/mozilla-central/ipc/glue/MessageLink.cpp:358)
 0:54.77 pid:2867 #06: IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) (/Users/jhsu/mozilla-central/ipc/chromium/src/chrome/common/ipc_channel_posix.cc:840)
 0:54.77 pid:2867 #07: base::MessagePumpLibevent::OnLibeventNotification(int, short, void*) (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_pump_libevent.cc:246)
 0:54.77 pid:2867 #08: event_persist_closure (/Users/jhsu/mozilla-central/ipc/chromium/src/third_party/libevent/event.c:1580)
 0:54.77 pid:2867 lude/mozilla/MozPromise.h:772)
 0:54.77 pid:2867 #10: event_process_active (/Users/jhsu/mozilla-central/ipc/chromium/src/third_party/libevent/event.c:1738)
 0:54.77 pid:2867 #11: event_base_loop (/Users/jhsu/mozilla-central/ipc/chromium/src/third_party/libevent/event.c:1961)
 0:54.77 pid:2867 #12: base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_pump_libevent.cc:338)
 0:54.77 pid:2867 #13: MessageLoop::RunInternal() (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_loop.cc:334)
 0:54.77 pid:2867 #14: MessageLoop::RunHandler() (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_loop.cc:328)
 0:54.77 pid:2866 #08: mozilla::SimpleTaskQueue::DrainTasks() (/Users/jhsu/mozilla-central/obj-x86_64-apple-darwin19.5.0/dist/include/mozilla/TaskDispatcher.h:44)
 0:54.77 pid:2867 #15: MessageLoop::Run() (/Users/jhsu/mozilla-central/ipc/chromium/src/base/message_loop.cc:310)
 0:54.77 pid:2867 #16: base::Thread::ThreadMain() (/Users/jhsu/mozilla-central/ipc/chromium/src/base/thread.cc:192)
 0:54.78 pid:2867 #17: ThreadFunc(void*) (/Users/jhsu/mozilla-central/ipc/chromium/src/base/platform_thread_posix.cc:40)
 0:54.78 pid:2867 cpp:513)
Blocks: 1651072

bug 1634846 fixes the crash

Flags: needinfo?(lsalzman)
Pushed by juhsu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7a1db7543f3c
P1 Use nsISerialEventTarget for HttpBackgroundChannelParent,  r=valentin,necko-reviewers
https://hg.mozilla.org/integration/autoland/rev/e34eddef39c8
P2 remove NeckoTargetChannelEvent which could not be specialized for HttpChannelChild, r=mayhemer,necko-reviewers
https://hg.mozilla.org/integration/autoland/rev/48adf08a7371
P3 Sending endpoint of stream filter via PHttpBackgroundChannel, r=mayhemer,necko-reviewers
https://hg.mozilla.org/integration/autoland/rev/eb15ef7bbe26
P4 Remove the depedency between OnStartRequestSent and AttachStreamFilter, r=mayhemer,necko-reviewers
You need to log in before you can comment on or make changes to this bug.