1156800 - crash in hang | WaitForMultipleObjectsEx | RealMsgWaitForMultipleObjectsEx | MsgWaitForMultipleObjects | mozilla::ipc::MessageChannel::WaitForInterruptNotify() | mozilla::ipc::MessageChannel::Call(IPC::Message*, IPC::Message*)

Status: RESOLVED FIXED

(Core Graveyard :: Plug-ins, defect)

Description

[Robert Kaiser]

[Tracking Requested - why for this release]:

This bug was filed from the Socorro interface and is 
report bp-bc8760cb-5c03-4afb-9d59-8d2c82150420.
=============================================================

Top frames:
0 	ntdll.dll 	NtWaitForMultipleObjects 	
1 	kernelbase.dll 	WaitForMultipleObjectsEx 	
2 	kernel32.dll 	WaitForMultipleObjectsExImplementation 	
3 	user32.dll 	RealMsgWaitForMultipleObjectsEx 	
4 	user32.dll 	MsgWaitForMultipleObjects 	
5 	xul.dll 	mozilla::ipc::MessageChannel::WaitForInterruptNotify() 	ipc/glue/WindowsMessageLoop.cpp
6 	xul.dll 	mozilla::ipc::MessageChannel::Call(IPC::Message*, IPC::Message*) 	ipc/glue/MessageChannel.cpp
7 	xul.dll 	mozilla::plugins::PPluginInstanceChild::CallNPN_GetValue_NPNVdocumentOrigin(nsCString*, short*) 	obj-firefox/ipc/ipdl/PPluginInstanceChild.cpp
8 	xul.dll 	mozilla::plugins::PluginInstanceChild::NPN_GetValue(NPNVariable, void*) 	dom/plugins/ipc/PluginInstanceChild.cpp
9 	xul.dll 	mozilla::plugins::child::_getvalue 	dom/plugins/ipc/PluginModuleChild.cpp
10 	npswf32_17_0_0_169.dll 	F21225463__________________________________________________________________________________________________________ 	F209679109___________________________________________________________________________________:1234
11 	npswf32_17_0_0_169.dll 	F_1746776035_______________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________ 	F462186421___________________________________________________________:859
12 	npswf32_17_0_0_169.dll 	F_1557046174___________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________________ 	F1104190711_____________________________________________________________________________:302
13 	npswf32_17_0_0_169.dll 	F1250129937___________________________________________ 	F1237873649__________________________________________________________________:16
14 	npswf32_17_0_0_169.dll 	F_341120320___________________________ 	F_1396628823_______________________________________________________________________:32
15 	user32.dll 	MsgWaitForMultipleObjects 	
16 	npswf32_17_0_0_169.dll 	F_1513036030________________________________________ 	F_1654095196__________________________________________________________________:47
17 	npswf32_17_0_0_169.dll 	F_652032984_____________________________________________________ 	F_1951567228__________________________________________________________:261
18 	npswf32_17_0_0_169.dll 	F1607135317_____________________________________________________________________ 	F_851861807__________________________________________________________:134
19 	npswf32_17_0_0_169.dll 	F2166389_____________________________________________________________________ 	F_851861807__________________________________________________________:560
20 	npswf32_17_0_0_169.dll 	F_917831355____________________________________________ 	F_851861807__________________________________________________________:488
[...]

This is the largest plugin hang on Dev Edition 39 right now (with a good margin over bug 1151794), and our plugin hang rate is 5-10x what it was for previous trains.

Aaron, are you investigating this?

Comment 1

[Lawrence Mandel [:lmandel] (use needinfo)]

Note that 37+ are affected but the frequency is substantially larger for 39. As such, I am tracking 39+ and not 38.

Comment 2

[(No longer employed by Mozilla) Aaron Klotz]

I was able to reproduce this on dev edition by loading FarmVille.

I think this might be an IPC issue but I'll need to look more closely to confirm. Both the browser and the plugin container are trying to make intr calls to each other at the same time, but neither side seems to be receiving the requests -- it's like they're just disappearing into the ether.

Comment 3

[Robert Kaiser]

[note that we need to have the crash keyword on any bug that produces crash reports so that the crash-stats system can connect crash signatures with bugs]

Comment 4

[(No longer employed by Mozilla) Aaron Klotz]

Attachment: Put sending of async NPP_New result into its own task

This mitigates the problem in this particular case, however I'm concerned that we might have some issues in our mediation of interrupt calls. I'll address those in follow-up bugs.

Comment 5

[(No longer employed by Mozilla) Aaron Klotz]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=01a6b7a62a2f

Comment 6

[Jim Mathies [:jimm]]

Comment on attachment 8598302 [details] [diff] [review]
Put sending of async NPP_New result into its own task

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

::: dom/plugins/ipc/PluginModuleChild.cpp
@@ +2197,5 @@
> +
> +    void Run() override
> +    {
> +        RemoveFromAsyncList();
> +        DebugOnly<bool> sendOk = mInstance->SendAsyncNPP_NewResult(mResult);

So the whole goal here is to get this off the stack?

Comment 7

[(No longer employed by Mozilla) Aaron Klotz]

(In reply to Jim Mathies [:jimm] from comment #6)
> So the whole goal here is to get this off the stack?
Yeah, this should not be run from within any interrupt calls.

Comment 8

[(No longer employed by Mozilla) Aaron Klotz]

https://hg.mozilla.org/integration/mozilla-inbound/rev/dd7c9daab76d

Comment 9

[(No longer employed by Mozilla) Aaron Klotz]

Comment on attachment 8598302 [details] [diff] [review]
Put sending of async NPP_New result into its own task

Approval Request Comment
[Feature/regressing bug #]: async plugin init
[User impact if declined]: browser+plugin hang
[Describe test coverage new/current, TreeHerder]: Run on try with asyncInit enabled https://treeherder.mozilla.org/#/jobs?repo=try&revision=01a6b7a62a2f, also verified locally using STR from comment 2.
[Risks and why]: Low, simple patch
[String/UUID change made/needed]: None

Comment 10

[Liz Henry (:lizzard) (relman/hg->git project)]

Comment on attachment 8598302 [details] [diff] [review]
Put sending of async NPP_New result into its own task

Approving for uplift to aurora, since this feature isn't enabled in nightly, it may not be useful to wait to see how it looks in treeherder in m-c.  The try run looks good.

Comment 11

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

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

Comment 12

[(No longer employed by Mozilla) Aaron Klotz]

https://hg.mozilla.org/releases/mozilla-aurora/rev/5193c1c752ed

Comment 14

[Robert Kaiser]

Aaron, we are still seeing this signature in high numbers on 39.0b1, do you know what's going on there? Do we need a new bug for that?

Comment 15

[(No longer employed by Mozilla) Aaron Klotz]

Let's open a new bug for it. The lower frames are different enough that we should consider any additional work to be a separate fix.

Comment 16

[alexey]

Hi All, We're having issues with v.39 - our plugin started to hang quite often while handling window load event. Before this version we've never experienced those kind of issues.

Here's the stack trace:

Microsoft (R) Windows Debugger Version 6.3.9600.17298 X86
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [C:\temp\20150727_141158_Hang_Mode\FULLDUMP_HangMode_plugin-container.exe__297c_2015-07-27_14-11-59-224_1f60.dmp]
User Mini Dump File with Full Memory: Only application data is available

Comment: 'HangMode'

************* Symbol Path validation summary **************
Response                         Time (ms)     Location
OK                                             c:\symbols
Symbol search path is: c:\symbols
Executable search path is: 
Windows 7 Version 7601 (Service Pack 1) MP (4 procs) Free x86 compatible
Product: WinNt, suite: SingleUserTS
Built by: 6.1.7601.17965 (win7sp1_gdr.121004-0333)
Machine Name:
Debug session time: Mon Jul 27 14:11:59.000 2015 (UTC + 3:00)
System Uptime: 0 days 16:41:24.915
Process Uptime: 0 days 0:02:03.000
................................................................
...........................
This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(1f60.2b28): Wake debugger - code 80000007 (first/second chance not available)
eax=0000004c ebx=0054f494 ecx=00000000 edx=00000000 esi=00000001 edi=00000000
eip=77240159 esp=0054f444 ebp=0054f4e0 iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
ntdll!NtWaitForMultipleObjects+0x15:
77240159 83c404          add     esp,4
0:000> kb
ChildEBP RetAddr  Args to Child              
0054f444 76a615f7 00000001 0054f494 00000001 ntdll!NtWaitForMultipleObjects+0x15
0054f4e0 761719fc 0054f494 0054f508 00000000 KERNELBASE!WaitForMultipleObjectsEx+0x100
0054f528 75e7086a 00000001 fffde000 00000000 kernel32!WaitForMultipleObjectsExImplementation+0xe0
0054f57c 026fac6a 0000004c 00000000 ffffffff user32!RealMsgWaitForMultipleObjectsEx+0x14d
0054f5c8 026fc54f 00000000 024012c0 00000009 xul!mozilla::widget::WinUtils::WaitForMessage+0x37 [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\widget\windows\winutils.cpp @ 638]
0054f5f8 026faaea 0054f6f8 0054f6f8 0054f6f8 xul!base::MessagePumpForUI::DoRunLoop+0xad [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\chromium\src\base\message_pump_win.cc @ 242]
0054f618 026fabef 0054f6f8 024012c0 026fd427 xul!base::MessagePumpWin::RunWithDispatcher+0x31 [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\chromium\src\base\message_pump_win.cc @ 56]
0054f624 026fd427 0054f6f8 02be2e23 c64872b6 xul!base::MessagePumpWin::Run+0xa [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\chromium\src\base\message_pump_win.h @ 78]
0054f62c 02be2e23 c64872b6 00000000 0054f6f8 xul!MessageLoop::RunInternal+0xa [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\chromium\src\base\message_loop.cc @ 234]
0054f660 026fd243 02466c00 00000001 036adc00 xul!MessageLoop::RunHandler+0x4e5a2c [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\chromium\src\base\message_loop.cc @ 219]
0054f680 03ad8c64 0000000c 00000000 02414118 xul!MessageLoop::Run+0x19 [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\chromium\src\base\message_loop.cc @ 201]
0054fa80 003a5458 0000000c 02401040 00000000 xul!XRE_InitChildProcess+0x51f [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\toolkit\xre\nsembedfunctions.cpp @ 584]
0054faa0 003a5271 00000000 00000000 00000000 plugin_container!content_process_main+0xf7 [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\ipc\contentproc\plugin-container.cpp @ 212]
0054fad4 003ae967 0000000d fe2d2e58 006d4210 plugin_container!wmain+0x12d [c:\builds\moz2_slave\rel-m-rel-w32_bld-000000000000\build\toolkit\xre\nswindowswmain.cpp @ 138]
0054fb1c 7617336a fffde000 0054fb68 772592b2 plugin_container!__tmainCRTStartup+0xfe [f:\dd\vctools\crt\crtw32\startup\crt0.c @ 255]
0054fb28 772592b2 fffde000 74f430ec 00000000 kernel32!BaseThreadInitThunk+0xe
0054fb68 77259285 003ae9e4 fffde000 00000000 ntdll!__RtlUserThreadStart+0x70
0054fb80 00000000 003ae9e4 fffde000 00000000 ntdll!_RtlUserThreadStart+0x1b

Comment 17

[Yorgos]

https://crash-stats.mozilla.com/report/index/5ca21e26-f063-47f0-8a38-94c402151004

Comment 18

[Yorgos]

it seems NOT fixed, as you can see here:
https://crash-stats.mozilla.com/report/index/b17e59bc-d363-469b-bbce-888962151010

Comment 19

[Yorgos]

https://crash-stats.mozilla.com/report/index/cde34dd7-2c9a-4840-81c3-dd6352151010

Comment 20

[katherine]

(In reply to Aaron Klotz [:aklotz] (please use needinfo) from comment #15)
> Let's open a new bug for it. The lower frames are different enough that we
> should consider any additional work to be a separate fix.

Hi Aaron, the bug still happens in firefox 41.0.1