On 2011-03-03, at 1:11 PM, chevalma@iro.umontreal.ca wrote:

I'm think a fair share of the time and space usage for lowering is due to the several validation passes. I can't commit a fix to disable them with a flag right now because our repo seems to still be down, but you could try it yourself.

To disable all validation during lowering, in ir/lowering.js, comment out cfg.validate() on lines 157, 169, 175, 185,

Once I have access to the repo again I might add a parameter so validation is disabled in the bootstrap config only, but remains enabled for our shell and unit tests.

• Maxime

I tried commenting out the validation and it did not change much (it saved about 2% allocation overall). The report is below.

Marc

******************** Performance report

Compiling runtime: 4.847571044921875 s, 331.6191101074219 MB allocated time=70% alloc=63% -- Machine code generation time=22% alloc=25% -- IR to ASM translation time=17% alloc=9% -- Linear scan time=11% alloc=5% -- Resolution time=6% alloc=7% -- Computing live intervals time=3% alloc=3% -- Number instructions time=3% alloc=4% -- Assembly time=1% alloc=2% -- Operand assignment time=0% alloc=1% -- Computing fixed intervals time=0% alloc=0% -- Order blocks time=18% alloc=25% -- IR lowering time=4% alloc=6% -- IR generation time=4% alloc=2% -- Parsing time=1% alloc=1% -- Machine code linking

Compiling stdlib: 6.235839111328125 s, 329.2502555847168 MB allocated time=81% alloc=70% -- Machine code generation time=25% alloc=11% -- Linear scan time=21% alloc=6% -- Resolution time=19% alloc=28% -- IR to ASM translation time=5% alloc=8% -- Computing live intervals time=4% alloc=4% -- Assembly time=1% alloc=2% -- Operand assignment time=1% alloc=3% -- Number instructions time=0% alloc=1% -- Computing fixed intervals time=0% alloc=0% -- Order blocks time=12% alloc=22% -- IR lowering time=3% alloc=0% -- Parsing time=1% alloc=3% -- IR generation time=1% alloc=2% -- Machine code linking

Compiling Tachyon: 507.99649609375 s, 10758.571731567383 MB allocated time=90% alloc=68% -- Machine code generation time=52% alloc=11% -- Linear scan time=19% alloc=4% -- Resolution time=8% alloc=29% -- IR to ASM translation time=3% alloc=5% -- Assembly time=2% alloc=7% -- Computing live intervals time=1% alloc=2% -- Operand assignment time=0% alloc=1% -- Computing fixed intervals time=0% alloc=3% -- Number instructions time=0% alloc=0% -- Order blocks time=7% alloc=22% -- IR lowering time=1% alloc=5% -- IR generation time=0% alloc=2% -- Machine code linking time=0% alloc=0% -- Parsing

********************

On 2011-03-03, at 3:03 PM, Bruno Dufour wrote:

Would it help if we could record the object types as well? From what I saw in heap.cc, it shouldn't be too difficult to record them. Marc, could you share a patch of your mods to v8 for me to use as a starting point?

Sure... as soon as the repo is back on line!

Marc

On 2011-03-03, at 3:20 PM, Bruno Dufour wrote:

AFAIK, v8 is not in our repo, so emailing the patch file to the list works too :)

My changes were "quick and dirty". I added 3 lines to src/heap.cc (look for <=== ADDED):

extern "C" { double bytes_allocated = 0, bytes_alive_at_last_gc = 0; } // <=== ADDED

void Heap::GarbageCollectionPrologue() { double n = SizeOfObjects(); bytes_allocated += n-bytes_alive_at_last_gc; // <=== ADDED TranscendentalCache::Clear(); ClearJSFunctionResultCaches(); ...

void Heap::GarbageCollectionEpilogue() { ... Counters::alive_after_last_gc.Set(static_cast<int>(SizeOfObjects())); bytes_alive_at_last_gc = SizeOfObjects(); // <=== ADDED Counters::symbol_table_capacity.Set(symbol_table()->Capacity()); Counters::number_of_symbols.Set(symbol_table()->NumberOfElements()); #if defined(DEBUG) || defined(ENABLE_LOGGING_AND_PROFILING) ReportStatisticsAfterGC(); #endif #ifdef ENABLE_DEBUGGER_SUPPORT Debug::AfterGarbageCollection(); #endif }

And in d8-tachyon-exts.cc I added some functions:

v8::Handlev8::Value v8Proxy_timeCurrentMillis(const v8::Arguments& args) { if (args.Length() != 0) { printf("Error in timeCurrentMillis -- 0 argument expected\n"); exit(1); }

return v8::Number::New(v8::internal::OS::TimeCurrentMillis()); }

extern "C" { extern double bytes_allocated, bytes_alive_at_last_gc; // defined in src/heap.cc }

v8::Handlev8::Value v8Proxy_bytesAllocated(const v8::Arguments& args) { if (args.Length() != 0) { printf("Error in bytesAllocated -- 0 argument expected\n"); exit(1); }

return v8::Number::New(bytes_allocated + (v8::internal::Heap::SizeOfObjects()-bytes_alive_at_last_gc)); }

and in the function init_d8_extensions I added:

global_template->Set( v8::String::New("timeCurrentMillis"), v8::FunctionTemplate::New(v8Proxy_timeCurrentMillis) );

global_template->Set( v8::String::New("bytesAllocated"), v8::FunctionTemplate::New(v8Proxy_bytesAllocated) );

These two functions are used in the implementation of the performance measurement code (in utility/misc.js):

function PerfInfo() { this.time = 0; this.bytes_alloc = 0; this.buckets = {}; }

var perfBuckets = {};

function measurePerformance(bucket, thunk) { var perfInfo;

if (!perfBuckets.hasOwnProperty(bucket)) { perfInfo = new PerfInfo(); perfBuckets[bucket] = perfInfo; } else { perfInfo = perfBuckets[bucket]; }

var perfBucketsOld = perfBuckets;

perfBuckets = perfInfo.buckets;

var start_time = timeCurrentMillis(); var start_bytes_alloc = bytesAllocated();

var result = thunk();

var bytes_alloc = bytesAllocated() - start_bytes_alloc; var time = timeCurrentMillis() - start_time;

perfBuckets = perfBucketsOld;

perfInfo.time += time; perfInfo.bytes_alloc += bytes_alloc;

return result; }

function reportPerformance() { print("******************** Performance report");

for (var bucket in perfBuckets) { var perfInfo = perfBuckets[bucket];

print(""); print(bucket + ": " + perfInfo.time/1000 + " s, " + perfInfo.bytes_alloc/(1024*1024) + " MB allocated");

reportPerformanceSubBuckets(perfInfo, perfInfo.buckets, ""); }

print(""); print("********************"); }

function reportPerformanceSubBuckets(overall, buckets, indent) { indent += " ";

var sortedBuckets = [];

for (var bucket in buckets) sortedBuckets.push(bucket);

sortedBuckets = sortedBuckets.sort( function (x, y) { return buckets[x].time < buckets[y].time; });

for (var i = 0; i<sortedBuckets.length; i++) { var bucket = sortedBuckets[i]; var perfInfo = buckets[bucket];

print(indent + "time=" + Math.floor(perfInfo.time*100/overall.time) + "% " + "alloc=" + Math.floor(perfInfo.bytes_alloc*100/overall.bytes_alloc) + "%" + " -- " + bucket);

reportPerformanceSubBuckets(overall, perfInfo.buckets, indent); } }

That way, wherever some code needs to be monitored for execution time and space usage, all that is needed is a call like:

measurePerformance( "Compiling Tachyon", function () { // Compile the Tachyon sources tachyonIRs = compSources(tachyonSrcs, params); });

and eventually

reportPerformance();

Marc