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

Reporter

Description

•

6 years ago

treeherder

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

Comment hidden (Intermittent Failures Robot)

6 failures in 657 pushes (0.009 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 6

Platform breakdown:
* windows7-32: 4
* windows10-64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1430586&startday=2018-01-15&endday=2018-01-21&tree=all

David Parks [:handyman]

Assignee

Updated

•

6 years ago

Assignee: nobody → davidp99

Blocks: 1382251

Component: General → Plug-ins

Priority: P5 → P1

David Parks [:handyman]

Assignee

Comment 2

•

6 years ago

Attached patch Make sure the NPObjectData map still exists before use — Details — Splinter Review

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

David Parks [:handyman]

Assignee

Comment 3

•

6 years ago

Tests:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=af6434e6ea6c5bb23a0071aeee9862b90cc9e6b5

David Parks [:handyman]

Assignee

Comment 4

•

6 years ago

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)

Jim Mathies [:jimm]

Updated

•

6 years ago

Attachment #8944872 - Flags: review?(jmathies) → review+

David Parks [:handyman]

Assignee

Updated

•

6 years ago

Keywords: checkin-needed

Pulsebot

Comment 5

•

6 years ago

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

Raul Gurzau (:RaulG)

Comment 6

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/0514c55fb1d1

Status: NEW → RESOLVED

Closed: 6 years ago

status-firefox60: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla60

Ryan VanderMeulen [:RyanVM]

Updated

•

6 years ago

status-firefox58: --- → unaffected

status-firefox59: --- → wontfix

status-firefox-esr52: --- → unaffected

BMO Automation

Updated

•

2 years ago

Product: Core → Core Graveyard

Bugzilla

Quick Search

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

Categories

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

Tracking

(firefox-esr52 unaffected, firefox58 unaffected, firefox59 wontfix, firefox60 fixed)

People

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

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Updated

Comment 2

Comment 3

Comment 4

Updated

Updated

Comment 5

Comment 6

Updated

Updated

Attachment

General

Description

File Name

Content Type