{"id":497,"date":"2010-04-08T01:00:53","date_gmt":"2010-04-08T09:00:53","guid":{"rendered":"http:\/\/www.visophyte.org\/blog\/?p=497"},"modified":"2010-04-08T01:00:53","modified_gmt":"2010-04-08T09:00:53","slug":"a-systemtap-script-to-attribute-js-string-memory-costs-to-the-creating-js-functions","status":"publish","type":"post","link":"https:\/\/www.visophyte.org\/blog\/2010\/04\/08\/a-systemtap-script-to-attribute-js-string-memory-costs-to-the-creating-js-functions\/","title":{"rendered":"a systemtap script to attribute JS string memory costs to the creating JS functions"},"content":{"rendered":"
----- js_GC data pages: 96731 total vm pages: 234849\r\n   ###      KiB\r\n 11376      839 BF_format                                        log4moz.j:487\r\n 15906      725 mime_emitter_writeBody                           jsmimeemitter.j:381\r\n   148      576 MimeMessage_coerceBodyToPlaintext                mimemsg.j:341\r\n  4460      492 gloda_ds_queryFromQuery                          datastore.j:2988\r\n  9655      387 <MYSTERIOUS>                                     <BEYOND THE VEIL>:0\r\n   911      237 gloda_content_quoted                             connotent.j:267\r\n  1723      144 gloda_indexMessage                               index_msg.j:2597\r\n   187      141 gloda_content_content                            connotent.j:290\r\n   170      108 gloda_content_getContent                         connotent.j:166\r\n  1917       73 gloda_identity_toString                          datamodel.j:785\r\n  1775       69 Log4Moz_enumerateProps                           log4moz.j:220\r\nvalue |-------------------------------------------------- count\r\n    0 |@                                                    366\r\n    1 |@@@@                                                1371\r\n    2 |@@@@@                                               1584\r\n    4 |@@@@@@@@@@@@@@@@@@@@@@@@                            6863\r\n    8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          11784\r\n   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@      12794\r\n   32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  14016\r\n   64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                      8662\r\n  128 |@@@@@@@@@@@@@@                                      4093\r\n  256 |@@@@@                                               1567\r\n  512 |@                                                    309\r\n 1024 |                                                     105\r\n 2048 |                                                      58\r\n 4096 |                                                      28\r\n 8192 |                                                      17\r\n16384 |                                                      12\r\n32768 |                                                       0\r\n65536 |                                                       0\r\n<\/pre>\n
The script<\/a>.\u00a0 It tells you what JS code has been creating strings since the last GC and the overall distribution of the marginal costs of those strings, leaving out puny code that allocates less than 64k’s worth.\u00a0 Marginal costs because spidermonkey has support for dependent strings.\u00a0 “a += b” will actually result in the storage of a<\/em> being realloc’d with a<\/em> pointing into the storage of a’<\/em>.\u00a0 I forgot to check for the js_ConcatStrings case at first and, let me tell you, the stats were not pretty.\u00a0 Poor mime_emitter_writeBody was accused of allocating 11 gigabytes of strings in one intra-GC cycle!<\/p>\n
What is interesting about this script is that it is actually pulling all of the function name\/script name\/line number information directly out of a JSContext object.\u00a0 What is exciting is that it was pretty easy to do thanks to systemtap’s understanding of DWARF debug symbols.\u00a0 This is in severe comparison to my efforts using VProbes<\/a> where there was no such support and I had to write a gdbpython script to begin to approach the same thing.\u00a0 Also, because systemtap’s guru mode allows you to bail into real C code when you need, I was able to write a function that truncates the jschar (16-bit unicode) strings that make up the function names into ASCII that is both straightforward and efficient.\u00a0 It also allowed for a quick\/easy\/fast basename() implementation too.<\/p>\n
It is worth noting that spidermonkey does have built-in (conditionally compiled) static probe points originally created for DTrace and that they do provide more generic object lifetime hooks.\u00a0 Although they were created for DTrace, systemtap is also able to use them.\u00a0 The limitations with those probes is that once any probe is active using a hook, a non-trivial cost is incurred because filtering can only be performed inside the probe and you may receive orders of magnitude more calls than you actually care about.\u00a0 The cost is worst for probes that provide function names since that requires a call to js_GetStringBytes every time (although there is some caching.)\u00a0 Keep in mind that I’m not saying the systemtap userspace probes are free, but since they can be placed at arbitrary points, you can have probes that fire only in the cases you actually care about, only incur data-processing costs when desired, and are disturbingly easy to implement since you can just reach into the data structures you care about.<\/p>\n
Since everyone loves an implementation fight, DTrace, great and magical though it is, is basically incapable of pulling off the JS stack-walking trick that systemtap makes possible.\u00a0 Unless DTrace has grown these features since I last checked, it lacks the DWARF magic to do such things easily and the language intentionally avoids the control-flow constructs that would allow it to do anything quite so complex.\u00a0 And you can entirely forget about arbitrary C code for the unicode string truncation…<\/p>\n
This post is brought to you by efforts to decrease the memory footprint of Thunderbird when gloda’s indexer is active.\u00a0 Because Thunderbird loves you.\u00a0 But it loves your memory more.\u00a0 For now.\u00a0 That’s what we’re trying to fix.<\/p>\n","protected":false},"excerpt":{"rendered":"
—– js_GC data pages: 96731 total vm pages: 234849 ### KiB 11376 839 BF_format log4moz.j:487 15906 725 mime_emitter_writeBody jsmimeemitter.j:381 148 576 MimeMessage_coerceBodyToPlaintext mimemsg.j:341 4460 492 gloda_ds_queryFromQuery datastore.j:2988 9655 387 <MYSTERIOUS> <BEYOND THE VEIL>:0 911 237 gloda_content_quoted connotent.j:267 1723 144 gloda_indexMessage … Continue reading →<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"inline_featured_image":false,"footnotes":""},"categories":[3,8],"tags":[76],"class_list":["post-497","post","type-post","status-publish","format-standard","hentry","category-mozilla","category-program-execution","tag-systemtap"],"_links":{"self":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts\/497","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/comments?post=497"}],"version-history":[{"count":9,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts\/497\/revisions"}],"predecessor-version":[{"id":506,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/posts\/497\/revisions\/506"}],"wp:attachment":[{"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/media?parent=497"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/categories?post=497"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.visophyte.org\/blog\/wp-json\/wp\/v2\/tags?post=497"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}