520321 - Recursive function call patch regressed Leopard tgfx and tsspider performance

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect, P2)

Description

[Robert Sayre]

+++ This bug was initially created as a clone of Bug #459301 +++

Curiously, it speeds up Windows and Linux.

To run talos tsspider and tgfx

cvs -d :pserver:[e-mail]:/cvsroot co mozilla/testing/performance/talos

then, make a copy of the sample config file that runs only tgfx, since that had the larger regression.

Comment 1

[Robert Sayre]

you'll need to get a local web server pointed at the page-load-test directory in order to run these.

Comment 2

[David Anderson [:dvander] - inactive, e-mail if emergency]

Attachment: disables recursion

Okay, we need to narrow down which part of the recursion patch caused this regression. The attached patch stops traces from forming at callsites, which effectively nukes recursion. It also stops treecalls from forming at callsites, and disables a few other tests to be totally sure.

Comment 3

[Robert Sayre]

Comment on attachment 404977 [details] [diff] [review]
disables recursion

r=me to test this out on the TM tree

Comment 4

[David Anderson [:dvander] - inactive, e-mail if emergency]

http://hg.mozilla.org/tracemonkey/rev/f0d8feea4d9e

Comment 5

[Robert Sayre]

the tsspider regression showed up after merging to m-c:

http://groups.google.com/group/mozilla.dev.tree-management/browse_thread/thread/d546730df0a27f82#

Comment 6

[Robert Sayre]

I was able to reproduce the tgfx regression using TM nightly builds. The test didn't seem to take any longer, but the "value" fields sure are bigger!


09-30-2009 nightly TM:
([({page:"text1.html", value:2.25, stddev:0.4330127018922193}),
({page:"text2.html", value:3, stddev:0}),
({page:"tile-jpg.html", value:3, stddev:0}),
({page:"tile-png.html", value:2.5, stddev:0.5}),
({page:"borders-solid.html", value:2, stddev:0}),
({page:"borders-dashed.html", value:2.5, stddev:0.5}),
({page:"borders-rounded.html", value:3, stddev:0}),])

10-01-2009 nightly TM:
([({page:"text1.html", value:12, stddev:1.224744871391589}),
({page:"text2.html", value:12, stddev:1.224744871391589}),
({page:"tile-jpg.html", value:12.5, stddev:1.118033988749895}),
({page:"tile-png.html", value:13, stddev:1.224744871391589}),
({page:"borders-solid.html", value:12.75, stddev:1.0897247358851685}),
({page:"borders-dashed.html", value:12.5, tddev:0.8660254037844386}),
({page:"borders-rounded.html", value:12, stddev:1}),])

Comment 7

[Boris Zbarsky [:bzbarsky]]

I wonder whether the test is just measuring slightly bogus stuff....

Comment 8

[Robert Sayre]

I can get the Tsspider regression as well:

09-30-2009:
_x_x_mozilla_page_load_details,avgmedian|55.9|average|55.90|minimum|NaN|maximum|NaN|stddev|NaN

10-01-2009:
_x_x_mozilla_page_load_details,avgmedian|61.46|average|61.60|minimum|NaN|maximum|NaN|stddev|NaN

Comment 9

[Robert Sayre]

looks like date-format-tofte and 3d-cube are the big regressions:

09/30/2009: |0;3d-cube.html;69.5;73.25;67;149;149;87;67;71;68
10/01/2009: |0;3d-cube.html;146.5;151.5;143;230;230;170;148;143;145

09/30/2009: |1;3d-morph.html;46.5;46.75;45;50;49;47;50;46;45
10/01/2009: |1;3d-morph.html;47.5;47.25;46;56;46;56;48;47;48

09/30/2009: |2;3d-raytrace.html;90;90;88;93;93;88;90;90;92
10/01/2009: |2;3d-raytrace.html;99;98.75;96;102;101;102;96;99;99

09/30/2009: |3;access-binary-trees.html;68.5;68;66;71;69;69;66;68;71
10/01/2009: |3;access-binary-trees.html;78;77.25;75;80;80;75;78;78;78

09/30/2009: |4;access-fannkuch.html;79;78.5;76;82;79;76;79;80;82
10/01/2009: |4;access-fannkuch.html;79.5;79;75;84;75;81;82;78;84

09/30/2009: |5;access-nbody.html;48;48.5;46;54;52;47;54;49;46
10/01/2009: |5;access-nbody.html;49.5;49.5;48;54;49;54;50;51;48

09/30/2009: |6;access-nsieve.html;34.5;34.75;34;43;43;34;36;35;34
10/01/2009: |6;access-nsieve.html;34.5;35;32;40;40;34;35;32;39

09/30/2009: |7;bitops-3bit-bits-in-byte.html;16;16;15;17;16;16;17;15;17
10/01/2009: |7;bitops-3bit-bits-in-byte.html;15.5;15.5;14;18;18;16;14;17;15

09/30/2009: |8;bitops-bits-in-byte.html;32;30.75;27;32;32;32;32;32;27
10/01/2009: |8;bitops-bits-in-byte.html;30.5;30.25;28;34;30;34;31;32;28

09/30/2009: |9;bitops-bitwise-and.html;16.5;16.5;15;18;18;15;17;18;16
10/01/2009: |9;bitops-bitwise-and.html;16.5;16.75;16;19;17;16;18;19;16

09/30/2009: |10;bitops-nsieve-bits.html;44;44;43;46;43;45;46;45;43
10/01/2009: |10;bitops-nsieve-bits.html;43;43.5;43;46;46;45;43;43;43

09/30/2009: |11;controlflow-recursive.html;54.5;54.25;53;56;55;56;54;55;53
10/01/2009: |11;controlflow-recursive.html;32;32.5;31;36;33;31;36;31;35

09/30/2009: |12;crypto-aes.html;55;55.25;54;59;59;54;57;56;54
10/01/2009: |12;crypto-aes.html;78.5;76.75;65;91;65;81;91;85;76

09/30/2009: |13;crypto-md5.html;35;35.25;35;45;45;36;35;35;35
10/01/2009: |13;crypto-md5.html;35;34.5;31;40;35;35;40;31;37

09/30/2009: |14;crypto-sha1.html;29;29.25;28;32;32;29;29;28;31
10/01/2009: |14;crypto-sha1.html;30.5;31;29;35;29;30;35;31;34

09/30/2009: |15;date-format-tofte.html;113.5;112.5;109;117;114;117;109;113;114
10/01/2009: |15;date-format-tofte.html;312;313;310;328;328;310;314;318;310

09/30/2009: |16;date-format-xparb.html;90.5;90.75;90;92;91;90;92;90;92
10/01/2009: |16;date-format-xparb.html;99;99;98;100;100;98;100;99;99

09/30/2009: |17;math-cordic.html;30.5;31;29;34;34;32;34;29;29
10/01/2009: |17;math-cordic.html;32.5;32.75;31;36;31;31;34;35;36

09/30/2009: |18;math-partial-sums.html;35;34.75;33;37;36;34;36;37;33
10/01/2009: |18;math-partial-sums.html;33;32.75;28;38;37;30;28;36;38

09/30/2009: |19;math-spectral-norm.html;27;24.75;16;30;16;29;28;26;30
10/01/2009: |19;math-spectral-norm.html;27.5;27.75;26;33;33;30;28;27;26

09/30/2009: |20;regexp-dna.html;81;80.75;79;85;82;82;79;80;85
10/01/2009: |20;regexp-dna.html;80.5;79.25;75;86;86;80;81;75;81

09/30/2009: |21;string-base64.html;36;36.5;35;40;39;36;40;35;36
10/01/2009: |21;string-base64.html;34.5;34.25;33;40;34;35;40;35;33

09/30/2009: |22;string-fasta.html;94;94.5;94;97;97;94;96;94;94
10/01/2009: |22;string-fasta.html;97;97.25;96;100;100;98;96;99;96

09/30/2009: |23;string-tagcloud.html;122.5;121.75;116;142;142;126;122;123;116
10/01/2009: |23;string-tagcloud.html;127.5;128.25;126;144;144;132;126;127;128

09/30/2009: |24;string-unpack-code.html;132;132;128;155;155;130;136;134;128
10/01/2009: |24;string-unpack-code.html;138.5;139;137;154;154;138;142;139;137

09/30/2009: |25;string-validate-input.html;49.5;49.25;48;67;67;48;49;50;50
10/01/2009: |25;string-validate-input.html;50.5;50.75;49;65;65;51;50;49;53

Comment 10

[Robert Sayre]

data from one run of the tsspider cycle below. it is allocating more and leaking.

09-30-2009:

==38035== HEAP SUMMARY:
==38035==     in use at exit: 1,905,872 bytes in 20,999 blocks
==38035==   total heap usage: 997,076 allocs, 976,077 frees, 8,819,410,310 bytes allocated
==38035== 
==38035== LEAK SUMMARY:
==38035==    definitely lost: 5,389 bytes in 94 blocks
==38035==    indirectly lost: 6,599 bytes in 13 blocks
==38035==      possibly lost: 811,737 bytes in 11,845 blocks
==38035==    still reachable: 1,077,407 bytes in 8,929 blocks
==38035==         suppressed: 4,740 bytes in 118 blocks
==38035== Rerun with --leak-check=full to see details of leaked memory

10-01-2009:

==37996== HEAP SUMMARY:
==37996==     in use at exit: 1,920,408 bytes in 22,672 blocks
==37996==   total heap usage: 1,005,910 allocs, 983,238 frees, 9,884,078,744 bytes allocated
==37996== 
==37996== LEAK SUMMARY:
==37996==    definitely lost: 90,362 bytes in 2,965 blocks
==37996==    indirectly lost: 6,843 bytes in 14 blocks
==37996==      possibly lost: 721,350 bytes in 10,555 blocks
==37996==    still reachable: 1,097,113 bytes in 9,020 blocks
==37996==         suppressed: 4,740 bytes in 118 blocks
==37996== Rerun with --leak-check=full to see details of leaked memory

Comment 11

[Robert Sayre]

seems to be mostly atomized strings:

 15,754 bytes in 550 blocks are definitely lost in loss record 5,584 of 5,601
    at 0x12416: malloc (vg_replace_malloc.c:195)
    by 0x2A6224: JSContext::malloc(unsigned long) (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x29FF6E: js_NewStringCopyN (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x1E12DE: js_AtomizeString (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x1E145D: js_AtomizeChars (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x2A8999: js_XDRStringAtom (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x2A8D4D: js_XDRAtom (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x29A14D: js_XDRScript (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x2A6FE5: JS_XDRScript (in /Applications/trunk/10-01-2009-TM-Shark/Minefield.app/Contents/MacOS/libmozjs.dylib)
    by 0x20E2C42: mozJSComponentLoader::ReadScript(nsIFastLoadService*, char const*, nsIURI*, JSContext*, JSScript**)
    by 0x20E439C: mozJSComponentLoader::GlobalForLocation(nsILocalFile*, JSObject**, char**, long*)
    by 0x20E4969: mozJSComponentLoader::LoadModule(nsILocalFile*, nsIModule**)

Comment 12

[Robert Sayre]

Attachment: lots of mmap in the 10-01-2009 nightly that isn't there with 09-29

Comment 13

[Robert Sayre]

Attachment: tofte

Comment 14

[Robert Sayre]

Attachment: 82.5% of allocations coming from JS_ArenaAllocate under VMSideExit?

I think that's what this shows, anyway.

Comment 15

[Robert Sayre]

(In reply to comment #14)
> Created an attachment (id=405321) [details]
> 82.5% of allocations coming from JS_ArenaAllocate under VMSideExit?
> 
> I think that's what this shows, anyway.

nope, it's ExecuteTree, bad manual demangling. dvander filed bug 521309.