martin Reporter
	Description • 10 years ago

I have seen this on my main (dirty) profile a number of times, so far have been unable to reproduce on a clean profile.

User Story
Created new Profile this morning
Browsed the web using it all day long
After some time plugin-container.exe starts to consume more and more cpu
Browser becomes jerky to use
Eg Typing in entry fields like this one shows a noticable delay
Looking at the Plugin-container.exe with systinternals process explorer I see that one thread consumes about 40 % CPU
Process Explorer shows plugin-container.exe-warnonlysandbox-providelogfunction-0x12bc as its address.

Took a dump of the process and I'm currently uploading it to google drive
It will be at https://drive.google.com/folderview?id=0B75-wUAyTF5SakFIRDZBbGpmZ3c&usp=sharing

BuildID
Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:36.0) Gecko/20100101 Firefox/36.0 ID:20141023030203 CSet: 88adcf8fef83

	martin Reporter
	Comment 1 • 10 years ago

Just to clarify: This dump is from a clean profile I created today morning.

	martin Reporter
	Comment 2 • 10 years ago

Dump has finished uploading 
Available at:
https://drive.google.com/folderview?id=0B75-wUAyTF5SakFIRDZBbGpmZ3c&usp=sharing

	Bob Owen (:bobowen) Assignee
	Comment 3 • 10 years ago

I think this is just Process Explorer guessing at the start address of the thread.

This is the main thread, when I look at Nightly in Process Explorer, it also suggests a Start Address for the main thread of:
plugin-container.exe!?ProvideLogFunction@warnonlysandbox@mozilla@@YAXP6AXPBD00_NI@Z@Z+0xeb3

With the start of the stack looking like this:

xul.dll!XRE_InitChildProcess+0x47f
plugin-container.exe+0x1bb6
plugin-container.exe+0x200d
plugin-container.exe!?ProvideLogFunction@warnonlysandbox@mozilla@@YAXP6AXPBD00_NI@Z@Z+0xe36
kernel32.dll!BaseThreadInitThunk+0x12
ntdll.dll!RtlInitializeExceptionChain+0x63
ntdll.dll!RtlInitializeExceptionChain+0x36

If I point Process Explorer at my local symbol cache, which has the symbols for nightly, I get the correct Start Address:
plugin-container.exe!wmainCRTStartup

With the start of the stack as:

xul.dll!XRE_InitChildProcess+0x47f
plugin-container.exe!content_process_main+0xad
plugin-container.exe!wmain+0x111
plugin-container.exe!__tmainCRTStartup+0xfe
kernel32.dll!@BaseThreadInitThunk@12+0xe
ntdll.dll!___RtlUserThreadStart@8+0x70
ntdll.dll!__RtlUserThreadStart@8+0x1b

This makes sense looking at the code.

So, while I don't think this is anything to do with the sandbox, the question is where is the main thread when it's using all that CPU.

Loading the dmp file into WinDbg, with the correct symbols, gives the call stack for the main thread as:

Call Site
xul!js::Shape::search+0xb7 [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\js\src\vm\shape-inl.h @ 129]
xul!js::NativeObject::lookup+0x1c [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\js\src\vm\nativeobject.cpp @ 273]
xul!js::LookupNativeProperty+0x14e [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\js\src\vm\nativeobject.cpp @ 1530]
xul!js::baseops::SetPropertyHelper<0>+0xdf [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\js\src\vm\nativeobject.cpp @ 1957]
xul!js::SetObjectElement+0x11b [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\js\src\vm\interpreter.cpp @ 3833]
0x333011
0x4d922d0
0x2228a8
0x2228b0
0x2228b8

Doesn't seem to have anymore of the stack than this.
I'll be honest that this doesn't mean much to me, although lookup and search sound like things that could eat a lot of CPU.
I assume this dump is just a snap shot, so this could be totally unrelated as well.

Brad - who do you think might be able to shed some light on this?

	Bob Owen (:bobowen) Assignee
	Comment 4 • 10 years ago

Hi Martin,

If you have time, you can set up Process Explorer to download the symbols itself.
This post has a pretty good description:
http://blogs.msdn.com/b/vijaysk/archive/2009/04/02/getting-better-stack-traces-in-process-monitor-process-explorer.aspx

As it says in the article you'll need WinDbg as its version of dbghelp.dll is able to connect to a symbol server.
If you use this symbol path instead of the one it suggests you'll get the symbols for Firefox as well:

SRV*c:\symcache\*http://msdl.microsoft.com/download/symbols;SRV*c:\symcache\*http://symbols.mozilla.org/firefox

The symbol files are quite big (over 300MB), so they can take a while to download, process explorer might stop responding while it's doing this.
If you're keeping Nightly up to date regularly you won't want this sympath all the time when using Process Explorer as I think it will keep downloading new symbols.
I don't want this to take up all your bandwidth or usage limit (if you have one). :-)

If you get the high CPU usage again, it would be interesting to see if the top of the main thread call stack is often around the same area.

	martin Reporter
	Comment 5 • 10 years ago

Hi Bob, 
ok will setup Windbg and Process Explorer to use the symbols and report what I see.

	Brad Lassey [:blassey] (use needinfo?)
	Comment 6 • 10 years ago

OK, with the more accurate stack it looks like our time is being spent in js. NI'ing Naveed to get someone looking at this.

	Bob Owen (:bobowen) Assignee
	Comment 7 • 10 years ago

(In reply to martin from comment #5)
> Hi Bob, 
> ok will setup Windbg and Process Explorer to use the symbols and report what
> I see.

Excellent, thanks for doing this.

	Naveed Ihsanullah [:naveed]
	Comment 8 • 10 years ago

Shu, looks like you were in here recently. Could you take a look?

Is this search linear always? Could be getting very slow with size or its just OOMing and bailing when trying to build the table and we keep retrying?

	Shu-yu Guo [:shu]
	Comment 9 • 10 years ago

I was not there recently, more like a year ago.

What search are you talking about, the shape search? It's impossible to say what's going on in there if the top of the stack is just Shape::search. And no, the search isn't always linear. That method either does a linear search through the shape lineage, or a hash table search if the shape is already hashified, or converts the shape lineage to a hash table due to some heuristics.

	martin Reporter
	Comment 10 • 10 years ago

Just a quick Update: Setup Symbols on 2 machines, waiting for the issue to come up again.

	martin Reporter
	Comment 11 • 10 years ago

Have not seen this issue in a while, I did change my addons configuration though; I disabled the Lazarus Extension.
I will re-enable it on a test profile and try to reproduce the issue.

	Bob Owen (:bobowen) Assignee
	Comment 12 • 10 years ago

(In reply to martin from comment #11)
> Have not seen this issue in a while, I did change my addons configuration
> though; I disabled the Lazarus Extension.
> I will re-enable it on a test profile and try to reproduce the issue.

Thanks for keeping us up to date on this Martin and for continuing to investigate.

There's a lot of work going on around this at the moment, so there's a chance that something else has already fixed the issue you were seeing.

	martin Reporter
	Comment 13 • 10 years ago

Folks, I think it's time to close this , have tried to reproduce, but have failed on 2 machines.

I see various examples where the current 64bit builds lock up for some time 
ie. window not responding, UI gets white 'window unresponsive' overlay on W8.1 and W7 64bit builds)
the plugincontainer hosting the plugins locking up, ie the other FF processes recover if you kill the one hosting the plugins.... 

Any directions on how to handle these possible performance issues? 

i.e. what doc does Mozilla need in a bug to work on it?
What kind of logging/tracing/dumping would help?

	Bob Owen (:bobowen) Assignee
	Comment 14 • 10 years ago

(In reply to martin from comment #13)
> Folks, I think it's time to close this , have tried to reproduce, but have
> failed on 2 machines.
> 
> I see various examples where the current 64bit builds lock up for some time 
> ie. window not responding, UI gets white 'window unresponsive' overlay on
> W8.1 and W7 64bit builds)
> the plugincontainer hosting the plugins locking up, ie the other FF
> processes recover if you kill the one hosting the plugins.... 
> 
> Any directions on how to handle these possible performance issues? 
> 
> i.e. what doc does Mozilla need in a bug to work on it?
> What kind of logging/tracing/dumping would help?

Martin, thanks for following up on this, I'll close.
That new issue you describe is not really my area, so I'm not entirely what would be helpful.

Jim, sounds a bit like other issues I've seen talked about in #e10s.
Does what Martin is describing ring any bells or should he just file a new bug?

	Jim Mathies [:jimm]
	Comment 15 • 10 years ago

Well lets keep an eye on it, we landed a bunch of plugin work recently, so that might help or make things worse. :)

	martin Reporter
	Comment 16 • 10 years ago

Jim, thanks, will do. (The landed stuff seems to have improved things from what I can tell)