{"id":4,"date":"2010-12-05T23:40:19","date_gmt":"2010-12-05T22:40:19","guid":{"rendered":"http:\/\/blog.mozilla.org\/jseward\/?p=4"},"modified":"2010-12-15T06:40:36","modified_gmt":"2010-12-15T05:40:36","slug":"fun-n-games-with-dhat","status":"publish","type":"post","link":"https:\/\/blog.mozilla.org\/jseward\/2010\/12\/05\/fun-n-games-with-dhat\/","title":{"rendered":"Fun ‘n’ games with DHAT"},"content":{"rendered":"

Back in 2007 Nick Nethercote morphed his Massif<\/a> heap profiler into
\nits present form.\u00a0 Massif intercepts malloc\/free et al, takes
\nperiodic snapshots of the heap and shows results using stack trees.
\nIt answers the questions “what’s in the heap?” and “who put it there?”<\/p>\n

Since then, I’d been mulling over a heap profiler that could also tell
\nme something about block lifetimes and usages.\u00a0 This year I finally
\ngot around to hacking something up — DHAT<\/a>.\u00a0 Like Massif, DHAT
\nintercepts malloc\/free, but it also inspects every (data) memory
\nreference, to see which block, if any, it is to.\u00a0 By doing that we can
\nidentify hot blocks and under-used ones.\u00a0 For allocation points which
\nalways allocate blocks of the same size, DHAT keeps count of how often
\neach block offset is accessed, thereby giving information on hot and
\ncold object fields, and showing up probable aligment holes.<\/p>\n

DHAT also records block lifetime information.\u00a0 Time is measured in
\ninstructions executed, as does Massif.\u00a0 DHAT notes the age at death of
\neach block and shows the average value for each allocation point.
\nDoing that makes it easy to find allocation points which chew through
\nlots of heap, but don’t hold on to it for long, or, conversely, points
\nthat allocate heap and hold on to it for the entire process lifetime.<\/p>\n

DHAT tracks two kinds of entities: blocks and allocation points (APs).\u00a0 A block
\nis just a heap block.\u00a0 An AP is a stack trace that has allocated one
\nor more blocks.\u00a0 When a block is freed, its statistics are merged back
\ninto its AP.\u00a0 At the end of the run, DHAT shows statistics for the top
\nN APs, as sorted by one of three user-selectable metrics.\u00a0 Most of the
\nart of using DHAT is in interpreting the mass of numbers it produces.<\/p>\n

DHAT perhaps ought to be merged with Massif at some point.\u00a0 For now,
\nthe emphasis was to get something up and running quickly, to see if it
\ngenerates any useful information.<\/p>\n

So does it show up anything interesting in Firefox?<\/p>\n

Here’s a no-brainer, bug 609905<\/a>:<\/p>\n

-------------------- 32 of 5000 --------------------
\nmax-live:\u00a0\u00a0\u00a0 524,328 in 1 blocks
\ntot-alloc:\u00a0\u00a0 524,328 in 1 blocks (avg size 524328.00)
\ndeaths:\u00a0\u00a0\u00a0\u00a0\u00a0 1, at avg age 15,015,989,851 (99.60% of prog lifetime)
\nacc-ratios:\u00a0 0.00 rd, 0.00 wr\u00a0 (192 b-read, 825 b-written)
\nat 0x4C27ECA: operator new(unsigned long) (vg_replace_malloc.c:261)
\nby 0x661D01D: js::InitJIT(js::TraceMonitor*) (jstracer.cpp:7807)
\nby 0x651FBEB: JSThreadData::init() (jscntxt.cpp:497)
\nby 0x652049D: js_CurrentThread(JSRuntime*) (jscntxt.cpp:588)
\nby 0x652085C: js_InitContextThread(JSContext*) (jscntxt.cpp:659)
\n<\/code><\/p>\n

This is a half-megabyte block that’s allocated, held onto for the
\nentire browser run, but never accessed.\u00a0 The key is to look at the
\nacc-ratios field, which shows the average number of times each byte
\nin the block got read and written — here, 0.00 for both.\u00a0 Turns out
\nto be a leftover allocator from the regexp engine that predated YARR.<\/p>\n

Here’s another, bug 611400<\/a>, that’s more
\ninteresting.\u00a0 When profiling the browser I noticed quite a lot heap
\noccupied by allocations from Jaegermonkey’s method
\njs::mjit::Compiler::finishThisUp.\u00a0 I wondered what it was but didn’t
\nthink much more about it until I profiled the JS engine running
\nKraken, and fell across this:<\/p>\n

-------------------- 4 of 100 --------------------
\nmax-live:\u00a0\u00a0\u00a0 12,197,056 in 1 blocks
\ntot-alloc:\u00a0\u00a0 12,197,056 in 1 blocks (avg size 12197056.00)
\ndeaths:\u00a0\u00a0\u00a0\u00a0\u00a0 1, at avg age 1,432,667,675 (42.98% of prog lifetime)
\nacc-ratios:\u00a0 0.00 rd, 0.00 wr\u00a0 (59 b-read, 129 b-written)
\nat 0x47B44FF: calloc (vg_replace_malloc.c:467)
\nby 0x81FF24D: js::mjit::Compiler::finishThisUp(js::mjit::JITSc
\nby 0x8215E47: js::mjit::Compiler::performCompilation(js::mjit:
\nby 0xC2F402F: ???
\n<\/code><\/p>\n

Hmm, a 12.2 MB allocation which is never used!\u00a0 That’s around 12% of
\nthe maximum live heap in this run.\u00a0 Turns out the method JIT creates
\ntables mapping JS bytecodes to the corresponding native code entry
\npoints.\u00a0 This Kraken test (imaging-darkroom) includes huge tables of
\nconstants, for which there are no entry points, so the 12MB allocation
\nis a completely empty table.<\/p>\n

This is an extreme case of a more general problem, though.
\nInstrumenting the method jit shows that about 98% of table entries are
\nunused when running more “normal” Javascript, when
\nsurfing at fairly complex-looking web pages, with 5 open tabs.<\/p>\n

I changed the table representation to only store useful entries.\u00a0 That
\nsaves the 12.2MB in Kraken.\u00a0 For a browser with 5 tabs, it saves
\nsomewhere in the region of 1%-2% of the entire C++ heap, which is a
\nnice outcome.<\/p>\n

And there’s more:<\/p>\n