{"id":131,"date":"2011-05-26T11:03:29","date_gmt":"2011-05-26T10:03:29","guid":{"rendered":"http:\/\/blog.mozilla.org\/jseward\/?p=131"},"modified":"2011-05-26T11:03:29","modified_gmt":"2011-05-26T10:03:29","slug":"a-low-overhead-always-on-system-wide-memory-event-log","status":"publish","type":"post","link":"https:\/\/blog.mozilla.org\/jseward\/2011\/05\/26\/a-low-overhead-always-on-system-wide-memory-event-log\/","title":{"rendered":"A low overhead, always-on, system-wide memory event log"},"content":{"rendered":"<p>This is really a RFC.<\/p>\n<p>It seems to me that many end-user bugzilla reports about excessive memory use share a common structure.\u00a0 First, the user reports that &#8220;I did A, B and C, had a coffee, went back to my machine and found that Firefox was sitting on N gigabytes of memory.&#8221;\u00a0 Then follows lots of<br \/>\ndiscussion along the lines of &#8220;oh, so the cycle collector did\/didn&#8217;t run while Fx was idle&#8221;, and &#8220;but no, that&#8217;s not right, because the tertiary FooBar timer inhibit mechanism will have made the XYZ collector run instead&#8221; kind of thing.<\/p>\n<p>This goes on and on, while everybody tries to figure out what Firefox was actually doing in the period leading up to the too-much-memory observation.\u00a0 Meanwhile the original reporter gets bored with the discussion and moves on to something else, and there&#8217;s general confusion, annoyance, and lack of reproducibility all round.<\/p>\n<p>So the idea is simple: make a log file listing events which are known to have a significant impact on memory usage.\u00a0 Nothing heavyweight, just one line per event, timestamped, plus brief relevant stats.\u00a0 For example:<\/p>\n<ul>\n<li> GC started \/ ended, total size N, reclaimed M bytes<\/li>\n<\/ul>\n<ul>\n<li> GC mapped in new heap \/ unmapped heap<\/li>\n<\/ul>\n<ul>\n<li> CC started \/ ended, total size N, reclaimed M bytes<\/li>\n<\/ul>\n<ul>\n<li> image discard ran<\/li>\n<\/ul>\n<ul>\n<li> jemalloc mmap&#8217;d more pages \/ munmapped some pages<\/li>\n<\/ul>\n<ul>\n<li> nanojit \/ mjit mapped \/ unmapped code pages<\/li>\n<\/ul>\n<p>Perhaps with some indirectly relevant events such as<\/p>\n<ul>\n<li>downloaded another chunk of the phishing database<\/li>\n<\/ul>\n<ul>\n<li> no user input seen for 17 minutes<\/li>\n<\/ul>\n<ul>\n<li> new tab created; now there are 23 of them<\/li>\n<\/ul>\n<ul>\n<li> user requested about:memory (+ what it produced)<\/li>\n<\/ul>\n<ul>\n<li> extension Xyzzy loaded\/initialised<\/li>\n<\/ul>\n<p>That way, we&#8217;d at least have some information about the space history leading up to a situation where a user says &#8220;urk!\u00a0 massive memory leak!&#8221;.<\/p>\n<p>The log would be low overhead, so it can be used in production.\u00a0 For sure we don&#8217;t want to log more than a couple of events per second.\u00a0 Perhaps a moderate sized circular buffer (64KB? 1MB?) that could be dumped to disk on request.\u00a0 Then, when someone reports excessive memory use, the first thing we ask for is the log file.<\/p>\n<p>Partial implementations of this exist already.\u00a0 There&#8217;s javascript.options.mem.log, for example, and I&#8217;m sure other subsystems have their own schemes.\u00a0 But AFAIK there&#8217;s no uniform,\u00a0 system-wide, lightweight, easy-to-use mechanism.\u00a0 Would one be useful?<\/p>\n","protected":false},"excerpt":{"rendered":"<p>This is really a RFC. It seems to me that many end-user bugzilla reports about excessive memory use share a common structure.\u00a0 First, the user reports that &#8220;I did A, B and C, had a coffee, went back to my &hellip; <a class=\"go\" href=\"https:\/\/blog.mozilla.org\/jseward\/2011\/05\/26\/a-low-overhead-always-on-system-wide-memory-event-log\/\">Continue reading<\/a><\/p>\n","protected":false},"author":240,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"_links":{"self":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/posts\/131"}],"collection":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/users\/240"}],"replies":[{"embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/comments?post=131"}],"version-history":[{"count":0,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/posts\/131\/revisions"}],"wp:attachment":[{"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/media?parent=131"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/categories?post=131"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/blog.mozilla.org\/jseward\/wp-json\/wp\/v2\/tags?post=131"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}