Julien Lecomte Reporter
	Description • 19 years ago

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.7.12) Gecko/20050915 Firefox/1.0.7
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.7.12) Gecko/20050915 Firefox/1.0.7

Our company develops an advanced AJAX application. All the JavaScript we write is concatenated in one large file during the build process. That file is about 3MB.

We configured our web application to set the Expires: HTTP header to a fairly large value (250 days...) so the network is not involved in this problem.

At the very beginning of the file, I wrote:

var start = new Date();

At the very end of the file, I wrote:

var end = new Date();

I then display the number of milliseconds it took Firefox to parse the entire file. The results are staggering: it oscillates between 1.3 seconds and 2.5 seconds where IE takes about 150 msec...

If the user took the hit only once, it would fine. But we spawn secondary windows from our main window, and we import the same script into those windows. So every time the user opens a window, there is a fixed cost of 1.3 seconds to 2.5 seconds (Note: my CPU is 2.8 GHz and I have 1GB of RAM...)

I tried with FF 1.0.7 and FF 1.5 Beta 2, and I get roughly the same results.

Any thoughts?

Reproducible: Always

	Julien Lecomte Reporter
	Comment 1 • 19 years ago

I am not going to attach a 3 MB JS file so I decided I would attach a utility I coded up to generate a large JS file.

	Julien Lecomte Reporter
	Comment 2 • 19 years ago

Once you have generated your test.js file, open test.html using Mozilla/FF or MSIE and compare...

	Julien Lecomte Reporter
	Comment 3 • 19 years ago

The result of the test case is (on my machine):

1.7 seconds with FF 1.0.7
175 msec with MSIE 6.0

My machine is a 2.8 GHZ / 1GB of RAM.

So FF is about 10 times slower than IE. Even though this is not too bad for regular web pages, it becomes a problem with large AJAX applications.

	Julien Lecomte Reporter
	Comment 4 • 19 years ago

The file generated is not that large, only 1 MB...

	Brendan Eich [:brendan]
	Comment 5 • 19 years ago

Hi Julien, did you try Firefox 1.5 beta2 (or the rc1 that's about to come out)?

Also, I am not set up to run the Java app, can you say whether everything in the generated .js file is on one very long line, or otherwise not broken up into more normal line lengths?  I recall a bug about that from the Firefox 1.0.x era, which may be fixed in 1.5.

Bob, anyone: please confirm if you can generate the test.js file.  Thanks,

/be

	Julien Lecomte Reporter
	Comment 6 • 19 years ago

FF 1.5 Beta 2 shows the exact same results.

The generated JS file looks like this:

function xyzzy_0(x, y) {
    var a = x+y;
    var b = x-y;
    var c = a+b
    return ( 2*c-1 );
}

function xyzzy_1(x, y) {
    var a = x+y;
    var b = x-y;
    var c = a+b
    return ( 2*c-1 );
}

function xyzzy_2(x, y) {
    var a = x+y;
    var b = x-y;
    var c = a+b
    return ( 2*c-1 );
}

...

	Julien Lecomte Reporter
	Comment 7 • 19 years ago

The compressed test case is not that big (28KB) so I am attaching it to the bug.

	Bob Clary [:bc] (inactive)
	Comment 8 • 19 years ago

I'm not sure of the component, but can confirm MSIE is 10 times faster than Firefox 1.5 in loading the testcase from disk. In my case (Pentium M 1.7Ghz) IE takes about .4 sec and FF takes 4 sec.

	Felix Lee
	Comment 9 • 18 years ago

I'm testing with firefox 2.0 on ubuntu-edgy.

firefox is spending a lot of time in JS_ArenaRelease(), which is because the tempPool arena gets pretty large during a script compile.  JS_ArenaRelease traverses the arena from the head to find the release mark, and the release mark is usually near the tail, so compiling large scripts takes quadratic time.

to verify that theory, I modified JS_ArenaRelease() so that it doesn't do anything if the release mark is more than 10 hops away from the head, and that seems to have fixed most of the unusual slowness.  the downside of that is a somewhat larger memory footprint while compiling a script (though it does get reclaimed when the compile is done).

less-simple fixes:

+ reverse the direction of the links in the arena pool, so that iteration starts from the tail.  this looks like it might be hard, because the JSArena struct seems to be part of the public api.

+ find out why the tempPool gets so large and trim that.  no idea yet what's making it grow so large.

	Felix Lee
	Comment 10 • 18 years ago

after the tempPool arena, the next bottlenecks look pretty normal:
+ lexer/parser does too much work per char, but it seems to be O(n).
+ gc is sometimes noticeable.

	Brendan Eich [:brendan]
	Comment 11 • 18 years ago

Brian, can you take this one?  Thanks,

/be

	Brendan Eich [:brendan]
	Comment 12 • 18 years ago

Need to identify cause of tempPool bloat.

Reducing cost per source char is always good, if it can be done cleanly.

GC overhead is usually a separate bug topic, but in this case perhaps we could revive an idea of Igor's and reduce/share allocations for literals when compiling. One idea is to keep the source for each function as a string, and use dependent strings for the functions' string literals.  Not clear this will reduce memory pressure enough to avoid the GC overhead.

Julien, 3MB is big enough that I wonder whether you won't want to break it up for incremental download. With your hack around the O(n^2) bug, is Firefox much different from other browsers? Most Ajax libraries trie to stay an order of magnitude smaller for the mandatory/initial .js file download size.

/be

	Brian Crowder
	Comment 13 • 18 years ago

Yeah, I was just getting setup to shark it, actually.  Will post results when I have something interesting.

	Brian Crowder
	Comment 14 • 18 years ago

I think more of us have perl at our disposal than Java, and this is what I am using to generate the following data:

50001 alloc_common AllocSrcNote:6396
50002 alloc_common EmitCheck:129
   1 alloc_common GrowTokenBuf:190
   4 alloc_common JS_ArenaGrow:273
1150002 alloc_common NewOrRecycledNode:180
50112 alloc_common NewScopeProperty:490
   1 alloc_common js_AllocRawStack:339
50000 alloc_common js_EmitTree:3906
   1 alloc_common js_NewBufferTokenStream:219
   1 alloc_common js_NewFileTokenStream:245
250000 alloc_common js_alloc_temp_entry:834
  28 alloc_common js_alloc_temp_space:817
 196 destroy js_SweepScopeProperties:1655
  12 grow_cast AllocSrcNote:6399
  18 grow_cast EmitCheck:133
   1 grow_cast GrowSrcNotes:6500
50000 release js_EmitTree:3932
50001 release js_FinishCodeGenerator:106
50001 release js_FinishCodeGenerator:107
50001 release js_FinishCodeGenerator:108
   1 release js_FreeRawStack:352

	Brian Crowder
	Comment 16 • 18 years ago

This data, btw, has been passed through sort | uniq -c.  The far left column is the number of times the macro has been used at that location, over the course of compiling the file.  I'm looking at the NewOrRecycleNode thing now to see if there's a place further up in the parse process that these allocated nodes could be let go of.

	Felix Lee
	Comment 17 • 18 years ago

the hack to JS_ArenaRelease() was me, not Julien.  sorry, I don't have a build for Windows, and I don't have an easy way to do a meaningful comparison with IE.

splitting large scripts into smaller chunks would sidestep the tempPool problem, but it slows down first-time load for all browsers.  split scripts are more network round-trips, and the requests have to be sequential.  also, combined scripts usually compress better.

re GC, I suspect it's also O(n^2) on script load, since mark-sweep is O(n) and garbage from the load triggers O(n) collections, but I don't have direct evidence of this yet.  this cost is probably about the same whether the scripts are split or combined.

	Brendan Eich [:brendan]
	Comment 18 • 18 years ago

I talked to crowder about this on IRC and hypothesized that the fix for bug 195385 was to blame.  Igor, you are cc'd here already.  I'm hoping that Brian can confirm or deny based on back-out (with merge conflicts? maybe it will just reverse-apply cleanly!) of the patch from bug 195385.

/be

	Igor Bukanov Assignee
	Comment 19 • 18 years ago

I am checking this as well. So far it looks that jsparse.c does not reuses the full recycle pool. More on that later.

	Igor Bukanov Assignee
	Comment 20 • 18 years ago

I have found the problem. It has nothing to do with RecycleTree implementation. Rather it comes from the fact that the recycle list is stored in JSTreeContext which is initialized for each function. Thus effectively after parsing each function its tree is not recycled generating a waster that is cleaned up only at the end of parsing.

	Igor Bukanov Assignee
	Comment 21 • 18 years ago

This is hack to get a minimal fix. I will ask for review after some testing.

	Igor Bukanov Assignee
	Comment 22 • 18 years ago

Comment on attachment 248704 [details] [diff] [review]
Fix

The patch speeded up the evaluation of the last perl-generated script by the factor of 15.

	Igor Bukanov Assignee
	Comment 24 • 18 years ago

Tunned test case that does epose the problem:

Before the patch:

~/m/trunk/mozilla/js/src> ./Linux_All_DBG.OBJ/js ~/m/files/time_growth_must_be_linear.js 
r coefiecent for the estimation that eval is O(N) where N is number
of functions in the script: 0.8481940894408323
uncaught exception: Eval time growth is not linear

After the patch:
~/m/trunk/mozilla/js/src> ./Linux_All_DBG.OBJ/js ~/m/files/time_growth_must_be_linear.js 
r coefiecent for the estimation that eval is O(N) where N is number
of functions in the script: 0.996770563232553
The grouth seems to be linear

	Brian Crowder
	Comment 25 • 18 years ago

Igor, thanks for the help, this code was very unfamiliar to me.

	Brendan Eich [:brendan]
	Comment 26 • 18 years ago

Comment on attachment 248704 [details] [diff] [review]
Fix

>+                /*
>+                 * Temporary transfer the owneship of the recycle list to funtc.

"Temporarily transfer ownership of ..." in both places, and r=me.

Thanks, should have seen this one years ago.  Please + the final trunk patch and nominate it for 1.8.1.2 and 1.8.0.10.

/be

	Igor Bukanov Assignee
	Comment 27 • 18 years ago

The patch to commit with comment text spelling fixes.

	Igor Bukanov Assignee
	Comment 28 • 18 years ago

I commited the patch from comment 27 to the trunk:

Checking in jsparse.c;
/cvsroot/mozilla/js/src/jsparse.c,v  <--  jsparse.c
new revision: 3.265; previous revision: 3.264
done

	Igor Bukanov Assignee
	Comment 29 • 18 years ago

Comment on attachment 248729 [details] [diff] [review]
Fix v1b

The patch applies as-is to 1.8.1 branch and fixes important performance issue.

	Igor Bukanov Assignee
	Comment 30 • 18 years ago

This is a trivial backport to 1.8.0: compared with 1.8.1 and later it is necessary to transfer the recycle list owneship once.

	Igor Bukanov Assignee
	Comment 31 • 18 years ago

Comment on attachment 248730 [details] [diff] [review]
Fix v1b for 1.8.0

The patch fixes important performance issue.

	Igor Bukanov Assignee
	Comment 32 • 18 years ago

I fixed misspellings and removed junk code at the test tail.

	Brian Crowder
	Comment 33 • 18 years ago

Looking at the perf-o-matic for the time this landed, this fix appears to yield a small but measurable drop in page-load and startup times.

	Daniel Veditz [:dveditz]
	Comment 34 • 18 years ago

Comment on attachment 248729 [details] [diff] [review]
Fix v1b

approved for 1.8/1.8.0 branches, a=dveditz for drivers

	Igor Bukanov Assignee
	Comment 35 • 18 years ago

Comment on attachment 248729 [details] [diff] [review]
Fix v1b

Added missed r+ that Brendan gave.

	Igor Bukanov Assignee
	Comment 36 • 18 years ago

I committed the patch from comment 27 to MOZILLA_1_8_BRANCH:

Checking in jsparse.c;
/cvsroot/mozilla/js/src/jsparse.c,v  <--  jsparse.c
new revision: 3.142.2.72; previous revision: 3.142.2.71
done

	Igor Bukanov Assignee
	Comment 37 • 18 years ago

I committed the patch from comment 30 to MOZILLA_1_8_0 branch:

Checking in jsparse.c;
/cvsroot/mozilla/js/src/jsparse.c,v  <--  jsparse.c
new revision: 3.142.2.6.2.11; previous revision: 3.142.2.6.2.10
done

	Bob Clary [:bc] (inactive)
	Comment 38 • 18 years ago

RCS file: /cvsroot/mozilla/js/tests/js1_5/Regress/regress-313967-01.js,v
done
Checking in regress-313967-01.js;
/cvsroot/mozilla/js/tests/js1_5/Regress/regress-313967-01.js,v  <--  regress-313967-01.js
initial revision: 1.1
done
RCS file: /cvsroot/mozilla/js/tests/js1_5/Regress/regress-313967-02.js,v
done
Checking in regress-313967-02.js;
/cvsroot/mozilla/js/tests/js1_5/Regress/regress-313967-02.js,v  <--  regress-313967-02.js
initial revision: 1.1
done

adding gc calls helps, but these tests may show failures depending on your platform.

	alice nodelman [:alice] [:anode]
	Comment 39 • 18 years ago

confirmed slowdown in 2.0.0.1
(run time for test.zip testcase 1935 ms, 1897 ms, 1934 ms, 1903 ms)

verified for 2.0.0.2pre, approx. 4x faster
(run times for test.zip testcase 506 ms, 500 ms, 508 ms, 474 ms) 

Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.2pre) Gecko/2007011103 BonEcho/2.0.0.2pre

verified for 1.5.0.10pre, approx 4.5x faster
(run times fore test.zip testcase 490 ms, 464 ms, 450 ms, 488 ms)

Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.0.10pre) Gecko/20070111 Firefox/1.5.0.10pre

	Bob Clary [:bc] (inactive)
	Comment 40 • 18 years ago

verified fixed 1.8.0, 1.8.1, 1.9.0 2007-01-28 win/mac*/linux. Note the 2007-01-23 test run had issues on all platforms but mac. This might have either due to the use of virtual machines or an issue with the tests, but checking each test -01, -02 on the shell on winxp, linux, macppc with 2007-01-28 builds works.