Closed Bug 1430586 Opened 3 years ago Closed 3 years ago

Intermittent PROCESS-CRASH | Main app process exited normally | application crashed [@ Checker::StartReadOp()]

Categories

(Core :: Plug-ins, defect, P1)

defect

Tracking

()

RESOLVED FIXED
mozilla60
Tracking Status
firefox-esr52 --- unaffected
firefox58 --- unaffected
firefox59 --- wontfix
firefox60 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: handyman)

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Attachments

(1 file)

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=155656012&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/D1RLyLiURTy3vJSn1MnERw/runs/0/artifacts/public/logs/live_backing.log

15:05:24     INFO -  307 INFO TEST-OK | dom/plugins/test/mochitest/test_zero_opacity.html | took 299ms
15:05:24     INFO -  GECKO(5572) | ++DOMWINDOW == 116 (0F5FAC00) [pid = 5572] [serial = 434] [outer = 25E31700]
15:05:24     INFO -  308 INFO None309 INFO TEST-START | Shutdown
15:05:24     INFO -  310 INFO Passed:  11940
15:05:24     INFO -  311 INFO Failed:  0
15:05:24     INFO -  312 INFO Todo:    202
15:05:24     INFO -  313 INFO Mode:    non-e10s
15:05:24     INFO -  314 INFO Slowest: 16275ms - /tests/dom/plugins/test/mochitest/test_pluginstream_err.html


...

15:05:30     INFO -  zombiecheck | Checking for orphan process with PID: 5788
15:05:30     INFO -  mozcrash Copy/paste: Z:\task_1515681501\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmpkpv3if.mozrunner\minidumps\dc884f05-6f27-473c-ad9d-b6dee0e4a793.dmp Z:\task_1515681501\build\symbols
15:05:51     INFO -  mozcrash Saved minidump as Z:\task_1515681501\build\blobber_upload_dir\dc884f05-6f27-473c-ad9d-b6dee0e4a793.dmp
15:05:51     INFO -  mozcrash Saved app info as Z:\task_1515681501\build\blobber_upload_dir\dc884f05-6f27-473c-ad9d-b6dee0e4a793.extra
15:05:51  WARNING -  PROCESS-CRASH | Main app process exited normally | application crashed [@ Checker::StartReadOp()]
15:05:51     INFO -  Crash dump filename: c:\users\genericworker\appdata\local\temp\tmpkpv3if.mozrunner\minidumps\dc884f05-6f27-473c-ad9d-b6dee0e4a793.dmp
15:05:51     INFO -  Operating system: Windows NT
15:05:51     INFO -                    6.1.7601 Service Pack 1
15:05:51     INFO -  CPU: x86
15:05:51     INFO -       GenuineIntel family 6 model 63 stepping 2
15:05:51     INFO -       8 CPUs
15:05:51     INFO -  GPU: UNKNOWN
15:05:51     INFO -  Crash reason:  EXCEPTION_ACCESS_VIOLATION_WRITE
15:05:51     INFO -  Crash address: 0x14
15:05:51     INFO -  Assertion: Unknown assertion type 0x00000000
15:05:51     INFO -  Process uptime: 63 seconds
15:05:51     INFO -  Thread 0 (crashed)
15:05:51     INFO -   0  xul.dll!Checker::StartReadOp() [PLDHashTable.h:68e0118f11a2 : 117 + 0x3]
15:05:51     INFO -      eip = 0x5c42a9d6   esp = 0x0028f5e4   ebp = 0x0028f5f4   ebx = 0x00810f00
15:05:51     INFO -      esi = 0x00813d30   edi = 0x00000000   eax = 0x0028fd01   ecx = 0x00000014
15:05:51     INFO -      edx = 0x00000001   efl = 0x00010202
15:05:51     INFO -      Found by: given as instruction pointer in context
15:05:51     INFO -   1  xul.dll!PLDHashTable::Search(void const *) [PLDHashTable.cpp:68e0118f11a2 : 535 + 0x8]
15:05:51     INFO -      eip = 0x5c42a20c   esp = 0x0028f5e8   ebp = 0x0028f5f4
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   2  xul.dll!mozilla::plugins::PluginScriptableObjectChild::GetInstanceForNPObject(NPObject *) [PluginScriptableObjectChild.cpp:68e0118f11a2 : 1276 + 0xe]
15:05:51     INFO -      eip = 0x5de7bda5   esp = 0x0028f5fc   ebp = 0x0028f600
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   3  xul.dll!mozilla::plugins::PluginModuleChild::NPN_ReleaseObject(NPObject *) [PluginModuleChild.cpp:68e0118f11a2 : 1901 + 0x9]
15:05:51     INFO -      eip = 0x5de410af   esp = 0x0028f608   ebp = 0x0028f610
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   4  xul.dll!`anonymous namespace'::DeferNPObjectReleaseRunnable::Run [PluginMessageUtils.cpp:68e0118f11a2 : 43 + 0xc]
15:05:51     INFO -      eip = 0x5de6f808   esp = 0x0028f618   ebp = 0x0028f61c
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   5  xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:68e0118f11a2 : 1040 + 0x11]
15:05:51     INFO -      eip = 0x5c47660f   esp = 0x0028f624   ebp = 0x0028fb90
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   6  xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:68e0118f11a2 : 517 + 0xd]
15:05:51     INFO -      eip = 0x5c47eb5e   esp = 0x0028fb98   ebp = 0x0028fbb8
15:05:51     INFO -      Found by: previous frame's frame pointer
15:05:51     INFO -   7  xul.dll!nsThread::Shutdown() [nsThread.cpp:68e0118f11a2 : 796 + 0x1d]
15:05:51     INFO -      eip = 0x5c47a62f   esp = 0x0028fbc0   ebp = 0x0028fbd4
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   8  xul.dll!mozilla::ChildProfilerController::ShutdownAndMaybeGrabShutdownProfileFirst(nsTString<char> *) [ChildProfilerController.cpp:68e0118f11a2 : 69 + 0xd]
15:05:51     INFO -      eip = 0x5f0eba91   esp = 0x0028fbdc   ebp = 0x0028fbf4
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -   9  xul.dll!mozilla::ChildProfilerController::Shutdown() [ChildProfilerController.cpp:68e0118f11a2 : 54 + 0x7]
15:05:51     INFO -      eip = 0x5f0eba31   esp = 0x0028fbfc   ebp = 0x0028fc10
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  10  xul.dll!mozilla::plugins::PluginModuleChild::ActorDestroy(mozilla::ipc::IProtocol::ActorDestroyReason) [PluginModuleChild.cpp:68e0118f11a2 : 735 + 0xe]
15:05:51     INFO -      eip = 0x5de5780b   esp = 0x0028fc04   ebp = 0x0028fc10
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  11  xul.dll!mozilla::plugins::PPluginModuleChild::DestroySubtree(mozilla::ipc::IProtocol::ActorDestroyReason) [PPluginModuleChild.cpp: : 1284 + 0xb]
15:05:51     INFO -      eip = 0x5c968613   esp = 0x0028fc18   ebp = 0x0028fc3c
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  12  xul.dll!mozilla::plugins::PPluginModuleChild::OnChannelClose() [PPluginModuleChild.cpp: : 1235 + 0x9]
15:05:51     INFO -      eip = 0x5c96dd29   esp = 0x0028fc44   ebp = 0x0028fc64
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  13  xul.dll!mozilla::ipc::MessageChannel::OnNotifyMaybeChannelError() [MessageChannel.cpp:68e0118f11a2 : 2605 + 0x7]
15:05:51     INFO -      eip = 0x5c854b03   esp = 0x0028fc50   ebp = 0x0028fc64
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  14  xul.dll!mozilla::detail::RunnableMethodImpl<mozilla::ipc::MessageChannel *,void ( mozilla::ipc::MessageChannel::*)(void),0,1>::Run() [nsThreadUtils.h:68e0118f11a2 : 1192 + 0xa]
15:05:51     INFO -      eip = 0x5c8569d3   esp = 0x0028fc6c   ebp = 0x0028fc6c
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  15  xul.dll!MessageLoop::RunTask(already_AddRefed<nsIRunnable>) [message_loop.cc:68e0118f11a2 : 452 + 0xe]
15:05:51     INFO -      eip = 0x5c831ebd   esp = 0x0028fc74   ebp = 0x0028fc94
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  16  xul.dll!MessageLoop::DeferOrRunPendingTask(MessageLoop::PendingTask &&) [message_loop.cc:68e0118f11a2 : 460 + 0xe]
15:05:51     INFO -      eip = 0x5c82d7ca   esp = 0x0028fc9c   ebp = 0x0028fca4
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  17  xul.dll!MessageLoop::DoWork() [message_loop.cc:68e0118f11a2 : 535 + 0x5]
15:05:51     INFO -      eip = 0x5c82db71   esp = 0x0028fcac   ebp = 0x0028fcd0
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  18  xul.dll!base::MessagePumpForUI::DoRunLoop() [message_pump_win.cc:68e0118f11a2 : 210 + 0xb]
15:05:51     INFO -      eip = 0x5c8223b7   esp = 0x0028fcd8   ebp = 0x0028fd00
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  19  xul.dll!base::MessagePumpWin::RunWithDispatcher(base::MessagePump::Delegate *,base::MessagePumpWin::Dispatcher *) [message_pump_win.cc:68e0118f11a2 : 56 + 0x5]
15:05:51     INFO -      eip = 0x5c8229ef   esp = 0x0028fce8   ebp = 0x0028fd00
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  20  xul.dll!base::MessagePumpWin::Run(base::MessagePump::Delegate *) [message_pump_win.h:68e0118f11a2 : 80 + 0xd]
15:05:51     INFO -      eip = 0x5c8229af   esp = 0x0028fd08   ebp = 0x0028fd10
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  21  xul.dll!MessageLoop::RunInternal() [message_loop.cc:68e0118f11a2 : 326 + 0xf]
15:05:51     INFO -      eip = 0x5c831e69   esp = 0x0028fd18   ebp = 0x0028fd30
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  22  xul.dll!MessageLoop::RunHandler() [message_loop.cc:68e0118f11a2 : 312 + 0x7]
15:05:51     INFO -      eip = 0x5c831e02   esp = 0x0028fd38   ebp = 0x0028fd64
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  23  xul.dll!MessageLoop::Run() [message_loop.cc:68e0118f11a2 : 299 + 0x7]
15:05:51     INFO -      eip = 0x5c831b63   esp = 0x0028fd6c   ebp = 0x0028fd84
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  24  xul.dll!XRE_InitChildProcess(int,char * * const,XREChildData const *) [nsEmbedFunctions.cpp:68e0118f11a2 : 703 + 0xb]
15:05:51     INFO -      eip = 0x5f2cebb1   esp = 0x0028fd8c   ebp = 0x0028fe9c
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  25  xul.dll!mozilla::BootstrapImpl::XRE_InitChildProcess(int,char * * const,XREChildData const *) [Bootstrap.cpp:68e0118f11a2 : 69 + 0xe]
15:05:51     INFO -      eip = 0x5f2d72c6   esp = 0x0028fea4   ebp = 0x0028feb0
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  26  plugin-container.exe!content_process_main(mozilla::Bootstrap *,int,char * * const) [plugin-container.cpp:68e0118f11a2 : 63 + 0xd]
15:05:51     INFO -      eip = 0x00e911fe   esp = 0x0028feb8   ebp = 0x0028fed8
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  27  plugin-container.exe!NS_internal_main(int,char * *) [MozillaRuntimeMain.cpp:68e0118f11a2 : 25 + 0xc]
15:05:51     INFO -      eip = 0x00e910cc   esp = 0x0028fee0   ebp = 0x0028fef4
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  28  plugin-container.exe!wmain [nsWindowsWMain.cpp:68e0118f11a2 : 108 + 0x7]
15:05:51     INFO -      eip = 0x00e91435   esp = 0x0028fefc   ebp = 0x0028ff2c
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  29  plugin-container.exe!__scrt_common_main_seh [exe_common.inl : 283 + 0x1c]
15:05:51     INFO -      eip = 0x00ec9515   esp = 0x0028ff34   ebp = 0x0028ff74
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  30  kernel32.dll!BaseThreadInitThunk + 0x12
15:05:51     INFO -      eip = 0x75d13c45   esp = 0x0028ff7c   ebp = 0x0028ff80
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  31  ntdll.dll!__RtlUserThreadStart + 0x27
15:05:51     INFO -      eip = 0x772f37f5   esp = 0x0028ff88   ebp = 0x0028ffc0
15:05:51     INFO -      Found by: call frame info
15:05:51     INFO -  32  ntdll.dll!_RtlUserThreadStart + 0x1b
15:05:51     INFO -      eip = 0x772f37c8   esp = 0x0028ffc8   ebp = 0x0028ffd8
15:05:51     INFO -      Found by: call frame info
Assignee: nobody → davidp99
Blocks: 1382251
Component: General → Plug-ins
Priority: P5 → P1
First, the actual crash is because the global hash map sObjectMap is null here [1], despite the apparent code invariant that this shouldn't happen.  It happens because plugin process shutdown breaks the expected behavior by freeing all of the PluginScriptableObjects in PluginInstanceChild::Destroy [2].  The engine may still be planning to delete one, tho, using a DeferNPObjectReleaseRunnable [3].  The deferred release is this crash.

I wanted to keep the NS_ERROR assertion but, in order to track it, I'd either have to keep track of NPObjects that have been scheduled for deferred delete and cross-validate them... or keep track of NPObjects deleted at PluginInstanceChild destruction and cross-validate them.  The assert is not worth much and its definitely not worth all that.

----

Detail:
There is no great repro for this so the analysis is all just logic.  The crash is a write at 0x1c because sObjectMap is null.  So when PluginScriptableObjectChild::GetInstanceForNPObject calls PLDHashTable::GetEntry, 'this' is null.  Before anything else has a chance to crash, GetEntry calls PLDHashTable::Search, which creates a AutoReadOp using mChecker.  'this' was still null and this (incorrect) comment tells us the rest [4]:


>  // These fields are packed carefully. On 32-bit platforms,
>  // sizeof(PLDHashTable) is 20. On 64-bit platforms, sizeof(PLDHashTable) is
>  // 32; 28 bytes of data followed by 4 bytes of padding for alignment.
>  const PLDHashTableOps* const mOps;  // Virtual operations; see below.
>  EntryStore          mEntryStore;    // (Lazy) entry storage and generation.
>  uint16_t            mGeneration;    // The storage generation.
>  uint8_t             mHashShift;     // Multiplicative hash shift.
>  const uint8_t       mEntrySize;     // Number of bytes in an entry.
>  uint32_t            mEntryCount;    // Number of entries in table.
>  uint32_t            mRemovedCount;  // Removed entry sentinels in table.

>  #ifdef DEBUG
>    mutable Checker mChecker;
>  #endif

The comment is correct... except for the DEBUG mChecker.  So we know that mChecker is at byte 28 in the object... which happens to be 0x1c.  We crash when it calls mChecker.StartReadOp().

----

[1] https://searchfox.org/mozilla-central/rev/e3cba77cee3ff1be38313abe9c804d13c51bd95b/dom/plugins/ipc/PluginScriptableObjectChild.cpp#1276
[2] https://searchfox.org/mozilla-central/rev/b7e3ec2468d42fa59d86c03ec7afeb209813f1d4/dom/plugins/ipc/PluginInstanceChild.cpp#4243
[3] https://searchfox.org/mozilla-central/rev/b7e3ec2468d42fa59d86c03ec7afeb209813f1d4/dom/plugins/ipc/PluginMessageUtils.cpp#22
[4] https://searchfox.org/mozilla-central/rev/b7e3ec2468d42fa59d86c03ec7afeb209813f1d4/xpcom/ds/PLDHashTable.h#241
Comment on attachment 8944872 [details] [diff] [review]
Make sure the NPObjectData map still exists before use

You appear to be the only 'normal' plugin peer left.  Fortunately, this is an easy one.  FYI, its blocking NPAPI SSL (it makes an intermittent orange more frequent).
Attachment #8944872 - Flags: review?(jmathies)
Attachment #8944872 - Flags: review?(jmathies) → review+
Keywords: checkin-needed
Pushed by ryanvm@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/0514c55fb1d1
Make sure the NPObjectData map still exists before use. r=jimm
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/0514c55fb1d1
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla60
You need to log in before you can comment on or make changes to this bug.