In bug 702813 comment 35 I attached the results of extracting GC and CC times during the load of the top 10,000 sites from Alexa. Smaug suggested I file a JS bug on the long GC times. The top 10 times were: Site gctype gcduration http://jsonline.com/ GC 1396.5 http://haaretz.co.il GC 1258.2 http://crictime.com/ GC 646.6 http://haaretz.com/ GC 303 http://ilemi.me/ GC 289 http://mako.co.il/ CC 288 http://archdaily.com/ CC 233 http://hindustantimes.com/ GC 232.9 http://redmondpie.com/ CC 224 http://deadspin.com/ CC 192 I set javascript.options.mem.log to true then extracted what I think was the total time for the GC from the Total value in the log. e.g. GC(T+9.4) Type:Glob, Total:1396.5, Wait:1.5, Mark:21.4, Sweep:16.8, FinObj:2.4, FinStr:0.2, FinScr:0.9, FinShp:2.3, DisCod:1.4, DisAnl:5.1, XPCnct:1.7, Destry:0.1, End:1358.3, +Chu:2, -Chu:0, Reason: API I used a Nightly nightly build from 2011-12-28 on 32bit Linux (Centos5). The test consisted of starting the browser, loading the page, waiting 15 seconds, shutting down the browser, repeat...

(In reply to Bob Clary [:bc:] from comment #0) > GC(T+9.4) Type:Glob, Total:1396.5, Wait:1.5, Mark:21.4, Sweep:16.8, > FinObj:2.4, FinStr:0.2, FinScr:0.9, FinShp:2.3, DisCod:1.4, DisAnl:5.1, > XPCnct:1.7, Destry:0.1, End:1358.3, +Chu:2, -Chu:0, Reason: API Interesting, the total mark/sweep time is 38.2 ms, so something outside the mark/sweep contributes a lot. So the problems is either in begin/end GC callbacks or with purge. I suppose we need more detailed GC time split to find the reason.

(In reply to Bob Clary [:bc:] from comment #0) > In bug 702813 comment 35 I attached the results of extracting GC and CC > times during the load of the top 10,000 sites from Alexa. Smaug suggested I > file a JS bug on the long GC times. Just to be sure - the test is just running a particular site in a browser for 15 seconds and observing the max total GC time during the test, right?

I cannot reproduce the results. With a build from http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2011-12-28-03-10-49-mozilla-central/firefox-12.0a1.en-US.linux-i686.tar.bz2 the worst GC time I got was 35 ms after loading the first 3 cites from the list.

The browser is started and the page loaded with the pref set and the messages sent to the console are captured and dumped to stdout. After the page loads the browser sits idle for 15 seconds then shuts down. This is repeated for each of the urls in the list using the same profile. In the jsonline case, the log says: Spider: Start: -url "http://jsonline.com/" -hook "http://test.mozilla.com/tests/mozilla.org/top-sites/userhooks/userhook-base.js" -depth 0 -timeout 120 -wait 0 -start -quit -jserrors Spider: Begin loading http://jsonline.com/ DOM Events Warning: ["An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http ://www.jsonline.com/" line: 584}]. Source File: http://www.jsonline.com/, Line: 584. DOM Events Warning: ["An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http ://c5.zedo.com//ads2/f/1085579/3840/27/0/305006688/305006688/0/305/1578/zz-V1-LMB_Canada_1x1.html?a=s%3D1578%3Bg%3D27%3Bm%3D57%3Bw%3D8%3Bu%3D3wv8TsyOk4wOndMAZsLFPAJv~122911%3Bi%3D0%3B;l=;p=;t=1325421364" line: 43}]. Source File: http:/ /c5.zedo.com//ads2/f/1085579/3840/27/0/305006688/305006688/0/305/1578/zz-V1-LMB_Canada_1x1.html?a=s%3D1578%3Bg%3D27%3Bm%3D57%3Bw%3D8%3Bu%3D3wv8TsyOk4wOndMAZsLFPAJv~122911%3Bi%3D0%3B;l=;p=;t=1325421364, Line: 43. malformed-xml Error: ["junk after document element" {file: "http://www.jsonline.com/templates/JSO_Get_Newswatch_Items?m=46&h=20&day=31&c=y" line: 9 column: 2 source: " <p class="contentblock">"}]. Source File: http://www.jsonline.com/t emplates/JSO_Get_Newswatch_Items?m=46&h=20&day=31&c=y, Line: 9, Column: 2, Source Code: <p class="contentblock"> GC(T+0.0) Type:Glob, Total:77.5, Wait:2.5, Mark:17.6, Sweep:40.2, FinObj:13.0, FinStr:0.9, FinScr:1.6, FinShp:6.7, DisCod:3.4, DisAnl:5.3, XPCnct:2.9, Destry:0.1, End:19.8, +Chu:11, -Chu:0, Reason: API DOM Warning: ["Empty string passed to getElementById()." {file: "http://www.jsonline.com/" line: 0}]. Source File: http://www.jsonline.com/, Line: 0. DOM Warning: ["Empty string passed to getElementById()." {file: "http://www.jsonline.com/" line: 0}]. Source File: http://www.jsonline.com/, Line: 0. DOM Warning: ["Empty string passed to getElementById()." {file: "http://www.jsonline.com/" line: 0}]. Source File: http://www.jsonline.com/, Line: 0. DOM Warning: ["Empty string passed to getElementById()." {file: "http://www.jsonline.com/" line: 0}]. Source File: http://www.jsonline.com/, Line: 0. malformed-xml Error: ["mismatched tag. Expected: </br>." {file: "http://www.jsonline.com/templates/JSO.PagePart.FeaturedBlogs" line: 30 column: 5 source: " </p> "}]. Source File: http://www.jsonline.com/templates/JSO.Pag ePart.FeaturedBlogs, Line: 30, Column: 5, Source Code: </p> DOM Events Warning: ["An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http ://www.jsonline.com/" line: 7211}]. Source File: http://www.jsonline.com/, Line: 7211. DOM Events Warning: ["An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http ://www.jsonline.com/" line: 8770}]. Source File: http://www.jsonline.com/, Line: 8770. affiliates.upickem.net : server does not support RFC 5746, see CVE-2009-3555 eblastengine.upickem.net : server does not support RFC 5746, see CVE-2009-3555 DOM Core Warning: ["Use of getAttributeNode() is deprecated. Use getAttribute() instead." {file: "http://www.jsonline.com/" line: 0}]. Source File: http://www.jsonline.com/, Line: 0. affiliates.upickem.net : server does not support RFC 5746, see CVE-2009-3555 *** Failed to get string typeException in bundle: chrome://global/locale/console.properties JavaScript[JavaScript Error: "function statement requires a name" {file: "http://tag.admeld.com/ad/iframe/344/journalinteractive/300x250/btf?t=1325393181535&tz=480&hu=&ht=js&hp=0&url=http%3A%2F%2Fwww.jsonline.com%2F&refer=" line: 23 co lumn: 8 source: "function() { var src="http://b.ermisvc.com"; }"}] GC(T+4.0) Type:Glob, Total:39.7, Wait:1.2, Mark:17.6, Sweep:16.2, FinObj:3.6, FinStr:1.1, FinScr:0.8, FinShp:2.0, DisCod:1.4, DisAnl:3.6, XPCnct:1.2, Destry:0.2, End:5.9, +Chu:0, -Chu:0, Reason: API CC(T+5.0) collected: 4763 (4763 waiting for GC), suspected: 14212, duration: 36 ms. Spider: Finish loading http://jsonline.com/ Spider: Current Url: http://jsonline.com/, Referer: null, Depth: 0 GC(T+9.4) Type:Glob, Total:1396.5, Wait:1.5, Mark:21.4, Sweep:16.8, FinObj:2.4, FinStr:0.2, FinScr:0.9, FinShp:2.3, DisCod:1.4, DisAnl:5.1, XPCnct:1.7, Destry:0.1, End:1358.3, +Chu:2, -Chu:0, Reason: API CC(T+12.7) collected: 167 (167 waiting for GC), suspected: 2292, duration: 15 ms. GC(T+13.5) Type:Glob, Total:33.5, Wait:0.1, Mark:21.3, Sweep:11.7, FinObj:0.8, FinStr:0.1, FinScr:0.3, FinShp:1.5, DisCod:1.0, DisAnl:4.3, XPCnct:1.1, Destry:0.1, End:1.2, +Chu:0, -Chu:0, Reason: API GC(T+17.5) Type:Glob, Total:33.0, Wait:0.1, Mark:21.2, Sweep:11.5, FinObj:0.6, FinStr:0.1, FinScr:0.4, FinShp:1.5, DisCod:1.0, DisAnl:4.3, XPCnct:1.0, Destry:0.1, End:1.2, +Chu:0, -Chu:0, Reason: API CC(T+18.5) collected: 56 (56 waiting for GC), suspected: 190, duration: 13 ms. GC(T+21.5) Type:Glob, Total:32.5, Wait:0.1, Mark:21.3, Sweep:10.8, FinObj:0.7, FinStr:0.1, FinScr:0.3, FinShp:1.5, DisCod:1.0, DisAnl:3.8, XPCnct:1.1, Destry:0.1, End:1.2, +Chu:0, -Chu:0, Reason: API Spider: stopped... loaded 1 pages NOTE: child process received `Goodbye', closing down http://jsonline.com/: EXIT STATUS: NORMAL (35.100040 seconds) Perhaps the long time was due to transitory content or due to the profile being used. If you want to refine the collection times to collect more data I can rerun the test.

When I tried to run using Spider I got: Compile Failed [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE)" nsresult: "0x80004005 (NS_ERROR_FAILURE)" location: "JS frame :: chrome://spider/content/script-loader.js :: loadScriptXHR :: line 74" data: no] undefined What I am doing wrong?

You did nothing wrong. You were just missing the user hook I used to delay the page before transitioning. There are a couple of approaches: 1. place the attached hook script on a locally available web server and change the -hook "http://test.mozilla.com/tests/mozilla.org/top-sites/userhooks/userhook-base.js" to point to it. 2. remove the -hook "http://test.mozilla.com/tests/mozilla.org/top-sites/userhooks/userhook-base.js" stuff from the command line altogether and then: change -wait 0 to -wait 15 which will terminate the browser after the 15 seconds or remove the -quit which will leave the browser running until you terminate it manually.

Igor, I am in the process of testing out a try build from Smaug and have been running it in parallel with a Nightly build as well. I've again seems some outliers (though different from before) but when attempting to reproduce locally I can not. I'm not sure whether this is a real issue that is not reproducible or if it is an artifact of how I am testing. I'm ok with marking this WFM if you want.