372618 - 7% Txul regression on Linux

Status: RESOLVED INCOMPLETE

(Core :: General, defect)

Description

[Steve England [:stevee]]

http://tinyurl.com/22mgwu

There is ~7% increase for Txul on 'Linux bl-bldlnx01 Dep argo-vm test perf' that occured between 2007-03-01 and 2007-03-02; jumping from ~720ms to ~770ms.

Only two checking that could have caused it, bug 324142 and bug 368523; both checked in by bz so taking the liberty of CC'ng him. (Also, plse note this is different from bug 371761)

Comment 1

[Boris Zbarsky [:bzbarsky]]

I'll look, I guess.  But note that before bug 368523 landed we didn't really run the cycle collector in many cases, it may be that now we're actually doing that.  I highly doubt that bug 324142 is the problem unless there are lots of chrome JS errors in Firefox...

Comment 2

[Boris Zbarsky [:bzbarsky]]

I tried backing out those patches locally, and times got _slower_ by about 5% here.  At least the times reported by the test.  Since there's about 40% noise locally in the actual numbers, I don't particularly trust anything it tells me.

So my guess, again, is that now we're actually running the cycle collector.  Except this is an opt build.  graydon, could the null-pointer-free thing have been calling Fault() in non-debug builds?

Comment 3

[Boris Zbarsky [:bzbarsky]]

That said, if this is in fact the cycle collector we should figure out why it's taking this big a bite with that change...

If it's the exception thing, I'd really love to know.

The problem is that I can't get any sane numbers out of Txul, so I need to either start backing out on tinderbox or find someone who _can_ get sane numbers out of it.  :(

Comment 4

[Boris Zbarsky [:bzbarsky]]

For what it's worth, if we get nowhere on this by Friday I'll probably try backouts on tinderbox.  I just hate the CVS log noise that causes.  :(

Comment 5

[Boris Zbarsky [:bzbarsky]]

OK, I tried backouts on tinderbox.  This is due to the change for bug 368523.  Which means it's really due to the cycle collector now running during this test.

I guess the real question is why this takes so much time....

See some of the Firefox window open perf analysis in bug 372637.  In particular, in that test JS GC is 18% of the total time, and the entry point to JS GC is the cycle collector....  I guess I can try profiling Txul to see whether it has the same issue.

Comment 6

[Boris Zbarsky [:bzbarsky]]

Attachment: bzip2-compressed profile (only way I could get it small enough to attach)

Highlights:

Total hit count: 177843

18709 hits under js_GC.

JS_GC about 85% called from nsXPConnect::BeginCycleCollection.

nsCycleCollector::Collect is called off the timer in nsJSContext.

That 85% of 10% is about the regression in this bug.  So conclusion is that we were not running the collector before and are now...

Comment 7

[Boris Zbarsky [:bzbarsky]]

So basically, you can think of this as one of:

1) GC is slow (bugs already filed)
2) Firefox has too much JS gunk (basically bug 372637).
3) GC should run less often (not sure how often....)

Comment 8

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Why are we running the cycle collector during Txul at all? Seems like we should avoid cc'ing until later.

Comment 9

[Damon Sicore (:damons)]

This is a cycle collector bug, and we're a lot faster now (30% Txul on Linux).