375227 - Checking objects type using constructor is much slower than Firefox 2

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect, P2)

Description

[José Jeria]

Build id: Latest trunk build using Windows XP SP 2

Creating a table using the DOM seems noticeable slower in Alpha 3 compared to
Firefox 2

Steps to reproduce
1. Visit http://www.jeria.net/performance_test/type_checking.html
2. Click on "Check type with constructor"
3. Compare results with Firefox 2 and a trunk build

Comment 1

[Bob Clary [:bc] (inactive)]

Attachment: multiple testcase

On the original I see about .24 secs for Bon Echo vs .3 sec or Minefield on a Pentium M 1.7Ghz linux machine on the test. But with the multiple testcase I see

                                    Bon Echo (ms)  Minefield (ms)
localPropertyAccess(100000)       =  16             23

globalPropertyAccess(100000)      =  38             53

argumentPropertyAccess(100000)    =  16             23

constructorPropertyAccess(100000) = 172            219

instanceOfComparison(100000)      = 152             56

objectComparison(100000)          =   8              9

So, instanceof is lots faster on trunk while property access appears to be the culprit in the original testcase.

Comment 2

[Brendan Eich [:brendan]]

Need confirmation. Cross-platform? I hope there's no debug build confounding.

If confirmed in the browser, please test shells, trunk vs. branch. Could be DOM security checks slowing things down.

If confirmed either way, need to find hook(s) that regressed us.

/be

Comment 3

[Brendan Eich [:brendan]]

Oops, missed bc's comment reading bugmail. Still hope for shell vs. browser, and when-it-regressed.

/be

Comment 4

[:Gavin Sharp [email: [e-mail]]]

With bc's testcase,  Windows msvc7.1, 3.0GHz dual-core:

JS Shell                             Trunk    1.8 Branch
localPropertyAccess(10000000)        2965     2450
globalPropertyAccess(10000000)       4822     3620
argumentPropertyAccess(10000000)     2934     2466
constructorPropertyAccess(10000000)  8005     8177
instanceOfComparison(10000000)       4994     4666
objectComparison(10000000)           1186     1296

Browser                              Trunk    1.8 Branch
localPropertyAccess(10000000)        2154     1530
globalPropertyAccess(10000000)       4400     3449
argumentPropertyAccess(10000000)     2092     1623
constructorPropertyAccess(10000000)  26435    14061
instanceOfComparison(10000000)       4542     3917
objectComparison(10000000)           983      811

Comment 5

[Bob Clary [:bc] (inactive)]

I'm not sure we aren't seeing gc related issues in some of our larger tests. FWIW, these are the results for opt shell I see. Except for globalPropertyAccess and maybe instanceOfComparison win32 1.8.1 looks the same as 1.9.0.

win32 shell 3.06GHz dual Xeon 3G RAM

argumentPropertyAccess(1000000),1.8.0,266
argumentPropertyAccess(1000000),1.8.1,203
argumentPropertyAccess(1000000),1.9.0,203

constructorPropertyAccess(1000000),1.8.0,547
constructorPropertyAccess(1000000),1.8.1,500
constructorPropertyAccess(1000000),1.9.0,500

globalPropertyAccess(1000000),1.8.0,328
globalPropertyAccess(1000000),1.8.1,250
globalPropertyAccess(1000000),1.9.0,344

instanceOfComparison(1000000),1.8.0,390
instanceOfComparison(1000000),1.8.1,313
instanceOfComparison(1000000),1.9.0,328

localPropertyAccess(1000000),1.8.0,250
localPropertyAccess(1000000),1.8.1,203
localPropertyAccess(1000000),1.9.0,203

objectComparison(1000000),1.8.0,141
objectComparison(1000000),1.8.1,93
objectComparison(1000000),1.9.0,94

linux shell 1.7GHz Pentium M 1G RAM

argumentPropertyAccess(1000000),1.8.0,227
argumentPropertyAccess(1000000),1.8.1,139
argumentPropertyAccess(1000000),1.9.0,196

constructorPropertyAccess(1000000),1.8.0,587
constructorPropertyAccess(1000000),1.8.1,479
constructorPropertyAccess(1000000),1.9.0,550

globalPropertyAccess(1000000),1.8.0,278
globalPropertyAccess(1000000),1.8.1,190
globalPropertyAccess(1000000),1.9.0,302

instanceOfComparison(1000000),1.8.0,392
instanceOfComparison(1000000),1.8.1,275
instanceOfComparison(1000000),1.9.0,317

localPropertyAccess(1000000),1.8.0,232
localPropertyAccess(1000000),1.8.1,143
localPropertyAccess(1000000),1.9.0,199

objectComparison(1000000),1.8.0,124
objectComparison(1000000),1.8.1,70
objectComparison(1000000),1.9.0,74

Comment 6

[Martijn Wargers (dead)]

These are the results I get with various builds:
var N = 1000000;
                                     branch     trunk      trunk      trunk      trunk
                                     2007-03-21 2007-03-23 2007-01-02 2007-01-04 2007-01-05
localPropertyAccess(1000000) =       297        359        265        328        344
globalPropertyAccess(1000000) =      359        500        375        359        375
argumentPropertyAccess(1000000) =    188        266        219        203        203
constructorPropertyAccess(1000000) = 1469       1969       1328       1359       2125
instanceOfComparison(1000000) =      453        484        453        454        453
objectComparison(1000000) =          94         109        109        109        109

So it seems to me the performance of constructorPropertyAccess has regressed between 2007-01-4 and 2007-01-05, which is the time period when bug 333078 was checked in.

Comment 7

[Brendan Eich [:brendan]]

Are we running more GCs, or is GC just slower due to XPCOM CC?

/be

Comment 8

[Brendan Eich [:brendan]]

Also note that many synthetic benchmarks are over-sensitive to the "GC pause" cost of our mark&sweep global GC. This suggests keeping an eye on that cost, but also not conflating it with the cost the benchmark is trying to measure. So tuning the synthetic benchmark to avoid measuring GC, as well as measuring both GC and the cost the benchmark ostensibly measures.

/be

Comment 9

[Boris Zbarsky [:bzbarsky]]

Attachment: Profile of constructorPropertyAccess

So I ran a jprof of just the constructorPropertyAccess test in this bug using a 2007-03-27 build.  Some notes:

1)  The collection phase of the cycle collector doesn't actually run until the page has finished loading, at least over here.  It does NOT run during this test.
2)  GC also does not run during this test, according to the profile.

I don't know the exact hours for the builds in comment 6, so it's hard to tell what regression range I'm looking at; no matter how I slice it however, there are lots of changes other than the cycle collector in there.

Analysis of the profile follows.

Pretty much all of the time is spent under js_Interpret: 17412 hits split up as:

  9983 js_GetProperty
  3541 js_SetProperty
  855 js_FindIdentifierBase
  290 nsJSContext::DOMBranchCallback(JSContext*, JSScript*)
  212 JS_GetContextPrivate

with 2335 hits in the function itself.

js_GetProperty is almost entirely js_NativeGet, which is almost entirely CheckCtorGetAccess, which is almost entirely js_CheckAccess.  In general, of the 17412 hits here, 7377 are under nsScriptSecurityManager::CheckObjectAccess.

Total time in cycle collector code, as far as I can see, is about 1200 hits (Suspect and Forget).

No idea why the time increased, exactly... someone familiar with the JS engine should look at the profile.

Comment 10

[Brian Crowder]

Wondering if mrbkap has any thoughts on this.

Comment 11

[Mike Schroepfer]

Today's trunk:

localPropertyAccess(100000) = 35

globalPropertyAccess(100000) = 69

argumentPropertyAccess(100000) = 33

constructorPropertyAccess(100000) = 198

instanceOfComparison(100000) = 73

objectComparison(100000) = 31

vs branch

localPropertyAccess(100000) = 27

globalPropertyAccess(100000) = 54

argumentPropertyAccess(100000) = 28

constructorPropertyAccess(100000) = 230

instanceOfComparison(100000) = 67

objectComparison(100000) = 16

Note this got much better overnight (-O2 patch sayre?).  and right now we are better than we were for branch.  Not sure if the rest of the small deltas are interesting or not?

Comment 12

[Robert Sayre]

(In reply to comment #11)
> 
> Note this got much better overnight (-O2 patch sayre?).  

Could be.

> and right now we are
> better than we were for branch.  Not sure if the rest of the small deltas are
> interesting or not?

Would be interesting to profile with my update of Brendan's patch in bug 395993.

Comment 13

[Robert Sayre]

(In reply to comment #12)
> 
> Would be interesting to profile with my update of Brendan's patch in bug
> 395993.

Turns out the interesting patch is bug 365851.

                                    Trunk  Branch  Trunk w/ bug 365851
localPropertyAccess(100000) =       18     15      13
globalPropertyAccess(100000) =      41     31      28
argumentPropertyAccess(100000) =    18     13      12
constructorPropertyAccess(100000) = 127    132     104
instanceOfComparison(100000) =      43     40      36
objectComparison(100000) =          12     7       11

Comment 14

[Mike Schroepfer]

Constructor access now ~2x perf of branch andeverything else either same or better.  Close the bug?

200x

localPropertyAccess(100000) = 10
globalPropertyAccess(100000) = 22
argumentPropertyAccess(100000) = 9
constructorPropertyAccess(100000) = 105
instanceOfComparison(100000) = 28
objectComparison(100000) = 4

Today's trunk:

localPropertyAccess(100000) = 11
globalPropertyAccess(100000) = 17
argumentPropertyAccess(100000) = 8
constructorPropertyAccess(100000) = 56
instanceOfComparison(100000) = 24
objectComparison(100000) = 7

Comment 15

[José Jeria]

This bug should be closed yes. Trunk was slower when I reported this, now it is the opposite, it is faster.

Comment 16

[Mike Schroepfer]

Per Comment 15 - closing bug