Closed Bug 680784 Opened 8 years ago Closed 7 years ago

lots of cpu time spent in FindInJSObjectScope with large amount of tabs

Categories

(Core :: XPConnect, defect)

6 Branch
defect
Not set

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: bugzilla_mozilla_org, Unassigned)

References

Details

in a session that >2000 (estimated) tabs on this machine, a lot of time is spent in FindInJSObjectScope when new tabs are opened. for profiling, about 50 new tabs are opened by ctrl clicking a link in an existing page and then closing the tabs one by one, it took about 5 minutes total.

here's the top of that report:

    32.21%  firefox-bin  libxul.so                   [.] XPCWrappedNativeScope::FindInJSObjectScope(JSContext*, JSObject*, int, XPCJSRuntime*)
            |
            --- XPCWrappedNativeScope::FindInJSObjectScope(JSContext*, JSObject*, int, XPCJSRuntime*)
               |          
               |--33.16%-- 0x7fff1ba3ce90
               |          
               |--17.60%-- (nil)
               |          
               |--16.42%-- 0x7fff1ba3d120
               |          
               |--8.29%-- 0x7fff1ba372d0
               |          
               |--8.27%-- 0x7fff1ba3da10
               |          
               |--8.26%-- 0x7fff1ba3b6a0
               |          
                --7.99%-- 0x7fff1ba3ad30

    10.01%  firefox-bin  libxul.so                   [.] JS_GetCompartmentPrivate
            |
            --- JS_GetCompartmentPrivate

     5.35%  firefox-bin  libxul.so                   [.] TraverseExpandoObjects(xpc::PtrAndPrincipalHashKey*, JSCompartment*, void*)
            |
            --- TraverseExpandoObjects(xpc::PtrAndPrincipalHashKey*, JSCompartment*, void*)

     1.61%  firefox-bin  libxul.so                   [.] SearchTable
            |
            --- SearchTable
               |          
                --100.00%-- (nil)
                          |          
                           --100.00%-- PL_DHashFreeTable
                                     0xc3a4f3d78948144f

     1.43%  firefox-bin  libxul.so                   [.] js::Interpret(JSContext*, js::StackFrame*, unsigned int, js::InterpMode)
            |
            --- js::Interpret(JSContext*, js::StackFrame*, unsigned int, js::InterpMode)
               |          
               |--8.93%-- 0x7f08a30a9d77
               |          
               |--8.90%-- 0x7f08a1d3eb19
               |          
               |--8.90%-- 0x7f08827a71ec
               |          
               |--8.88%-- 0x7f08adb403d4
               |          
               |--5.93%-- 0x7f08a1d48a42
               |          
               |--5.93%-- 0x7f08a1fd94bf
               |          
               |--5.86%-- 0x7f08a1fba9de
               |          
               |--5.81%-- 0x7f08a1d489d2
               |          
               |--5.73%-- 0x7f08a30a9d86
               |          
               |--2.98%-- 0x7f08827a72eb
               |          
               |--2.97%-- 0x7f08a1d3ece8
               |          
               |--2.97%-- 0x7f08a1d489d5
               |          
               |--2.97%-- 0x7f08a1f13966
               |          
               |--2.97%-- 0x7f08a1d3ebf9
               |          
               |--2.96%-- 0x7f08a1d48a03
               |          
               |--2.96%-- 0x7f08adb403d8
               |          
               |--2.96%-- 0x7f08a1f1397f
               |          
               |--2.90%-- 0x7f08827f4615
               |          
               |--2.88%-- 0x7f08a1d2e009
               |          
               |--2.87%-- 0x7f08adbfd53e
               |          
                --2.77%-- 0x7f08a1d3eb33

     1.23%  firefox-bin  libpthread-2.13.so          [.] pthread_mutex_lock
            |
            --- pthread_mutex_lock
               |          
               |--28.21%-- 0x7f08b92b2288
               |          
               |--28.06%-- 0x7f08b92b2368
               |          
               |--12.97%-- 0x7f08b92b22f8
               |          
               |--7.40%-- 0x7f088dd00938
               |          
               |--2.59%-- 0x7f08b92b2218
               |          
               |--2.56%-- 0x7f0879fa02e0
               |          0x7f0800000007
               |          
               |--1.12%-- 0x7f0818901808
               |          
               |--0.82%-- 0x7f0867900b30
               |          
               |--0.74%-- 0x7f086cd01808
               |          
               |--0.74%-- 0x1001100000006
               |          nsAttrAndChildArray::GetAttr(nsIAtom*, int) const
               |          
               |--0.74%-- 0x7f08a21edae0
               |          |          
               |          |--50.11%-- 0x7f0800000007
               |          |          
               |           --49.89%-- 0x7fff00000007
               |          
               |--0.73%-- 0x7f08a21edaa0
               |          0x7f0800000007
               |          
               |--0.72%-- 0x7f08b92b21a8
               |          
               |--0.72%-- 0x7f08b92b2138
               |          
               |--0.56%-- 0x7fff1ba39d90
               |          
               |--0.55%-- 0x7fff1ba3b530
                --10.76%-- [...]
This is a great bug report. Thanks.
Status: UNCONFIRMED → NEW
Ever confirmed: true
OS: Linux → All
Hardware: x86_64 → All
Is this a regression? Did you not see this issue in Firefox 5, 4, 3.6?
This might have regressed slightly between 3.6 and 4 when we added compartments (we enter a compartment), but I am pretty sure the real issue here is that we are doing a linear search across all scopes. mrbkap and I have discussed this before as being potentially slow. I am glad we have actually proof now it is.
slightly related to last comment, and initial bug, the profile looks like this and stays this way (profiled almost a half hour) when tab candy is open in one of the windows, takes a few seconds to do anything, lots of seconds to type in search queries in the tab candy view.

    27.29%  firefox-bin  libxul.so                   [.] JS_GetCompartmentPrivate
            |
            --- JS_GetCompartmentPrivate

    20.15%  firefox-bin  libxul.so                   [.] TraverseExpandoObjects(xpc::PtrAndPrincipalHashKey*, JSCompartment*, void*)
            |
            --- TraverseExpandoObjects(xpc::PtrAndPrincipalHashKey*, JSCompartment*, void*)

    10.54%  firefox-bin  libxul.so                   [.] XPCWrappedNativeScope::FindInJSObjectScope(JSContext*, JSObject*, int, XPCJSRuntime*)
            |
            --- XPCWrappedNativeScope::FindInJSObjectScope(JSContext*, JSObject*, int, XPCJSRuntime*)
               |          
               |--43.03%-- (nil)
               |          
               |--29.56%-- 0x7fff68edab50
               |          
               |--14.60%-- 0x7fff68edaed0
               |          
                --12.81%-- 0x7fff68edab10
anything going on with this? other profiles i've sharded off my main profile have started to do the same thing

Mozilla/5.0 (Ubuntu; X11; Linux x86_64; rv:9.0.1) Gecko/20100101 Firefox/9.0.1

              2 -- js-compartments-system
            692 -- js-compartments-user
sorry for not putting this all in one message;

the memory usage is actually quite good considering

1,958,678,528 B (100.0%) -- resident
├──1,941,463,040 B (99.12%) -- anonymous
│  ├──1,930,919,936 B (98.58%) -- anonymous, outside brk() [rw-p] [681]
│  └─────10,543,104 B (00.54%) -- anonymous, outside brk() [rwxp] [86]
└─────16,461,824 B (00.84%) -- shared-libraries

              4 -- js-compartments-system
          1,798 -- js-compartments-user

are the numbers from the profile i created the original report with/for

the linear slowdown with ff3, or basically pre-compartments was manageable, and i could migrate stuff if needed; but with ff4+ there's just huge long pauses, and i don't know why but it seems there's a situation where you have just a handful more tabs and get huge pauses, close them and it acts normally, so it's not all the compartment count and the linear walk, maybe visiting every compartment to collect things?
Hm. So this should be constant time for global objects with the special XPConnect magic in them:

http://mxr.mozilla.org/mozilla-central/source/js/xpconnect/src/XPCWrappedNativeScope.cpp#760

I'd always assumed that that was the common case. Andreas or blake - do you guys know why we'd want a global without JSCLASS_XPCONNECT_GLOBAL? What are the situations where we don't have it? Can we just make sure we always have it?
I just realized this will actually be fixed entirely by compartment-per-global, which Luke and I are going to be doing this quarter. So keep an eye on bug 650353!
Depends on: cpg
Depends on: 797821
I haven't seen this lately, and since bug 650353 is fixed, I assume also this one is.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.