{"id":19,"date":"2013-02-20T14:41:40","date_gmt":"2013-02-20T09:11:40","guid":{"rendered":"http:\/\/blog.anuram.in\/?p=4"},"modified":"2013-02-20T14:41:40","modified_gmt":"2013-02-20T09:11:40","slug":"debugging-memory-leak","status":"publish","type":"post","link":"https:\/\/blog.anuram.in\/?p=19","title":{"rendered":"Debugging memory leak"},"content":{"rendered":"<h2>How to generate a core file unobtrusively<\/h2>\n<p><a href=\"https:\/\/blog.anuram.in\/wp-content\/uploads\/2013\/02\/gdb-1-590x396.jpg\"><img loading=\"lazy\" decoding=\"async\" class=\"alignnone size-medium wp-image-52\" alt=\"gdb-1-590x396\" src=\"https:\/\/blog.anuram.in\/wp-content\/uploads\/2013\/02\/gdb-1-590x396-300x201.jpg\" width=\"300\" height=\"201\" \/><\/a><\/p>\n<p>This method is not nearly as powerful as some of the other options, but it has one big advantage: you can get a core file from a running daemon without killing it and restarting. It just interrupts the daemon for as long as it takes to write out the core file.<\/p>\n<pre class=\"lang:sh decode:true\">cd \/path\/to\/space\/for\/core\/file\ngdb -p gcore\nquit<\/pre>\n<p>Now you have a core file. You can load it up in gdb and walk around in data structures to see if some of them are larger than expected. You can also run &#8216;strings&#8217; on it to see if anything unexpected jumps out. For example, if a particular string is repeated many more times than it should be, that could be a clue to help you find a leak or source of bloat.<\/p>\n<pre class=\"lang:sh decode:true\">strings corefile | sort | uniq -c | sort -n<\/pre>\n<h2>How to use valgrind to check a daemon for memory leaks<\/h2>\n<p>Valgrind is a powerful tool for catching memory leaks and sources of bloat. The main disadvantage of the tool is that it slows things down quite a lot (~20 times in my experience). You also need to stop the running daemon and restart it under valgrind.<\/p>\n<p>Here is an example of how to use it. In this example, it is the collector that is being checked.<\/p>\n<pre class=\"lang:sh decode:true\">condor_off -collector\n# become the user that runs HTCondor\nsudo su root\nenv _CONDOR_USE_CLONE_TO_CREATE_PROCESSES=False valgrind --tool=memcheck --leak-check=yes --show-reachable=yes --leak-resolution=high &gt;&amp; \/tmp\/valgrind.log &lt; \/dev\/null \/path\/to\/condor_collector -f -p 9621 &amp;<\/pre>\n<p>Note that valgrind (as of 2.4.0) crashes due to the way we use clone(), so the above example disables the clone() optimization. As of 7.1.2, HTCondor should auto-detect that it is running under valgrind and automatically disable the clone optimization.<\/p>\n<p>To check for leaks, run for a while and then do a graceful shutdown (kill -TERM). To check for bloat, kill with SIGINT instead. This will prevent it from doing a normal exit, freeing up memory, etc. That way, we can see memory that it has referenced (but which may be unexpectedly bloated). The valgrind output will contain information on the blocks of memory that were allocated at exit.<\/p>\n<p>valgrind gives more detailed information when you run it with an unstripped binary (including line numbers in the call stack).<\/p>\n<h2>Running the test suite under valgrind<\/h2>\n<p> <span class=\"lang:sh decode:true  crayon-inline \" >batch_test.pl<\/span> \u00a0is the means by which the test suite is run. It can be told to start up its own person HTCondor and use that for testing. The tests ran by\u00a0<span class=\"lang:sh decode:true  crayon-inline \" >batch_test.pl<\/span>\u00a0may also start their own personal condors.<\/p>\n<p>In order to test all of these personal condors under valgrind, valgrind can be told to follow all forked\/execed children and where to dump its output. So we&#8217;ll do just that and start up the master. You can either be root or a normal user for this, depending upon what you are testing.<\/p>\n<p>After the test suite codes are built, cd into\u00a0<span class=\"lang:sh decode:true  crayon-inline \" >condor_tests\/<\/span>.<\/p>\n<p>We&#8217;ll invoke\u00a0<span class=\"lang:sh decode:true  crayon-inline \" >batch_test.pl<\/span>\u00a0under valgrind. We tell batch test to start up its own personal condors and clean up everything when it is done. We don&#8217;t ask it to run tests in parallel since there likely are race conditions in the tests over that behavior.<\/p>\n<p>We make sure to specify the logfile pattern in a valid and empty directory. This is because valgrind will write a new log file with the pid associated with it for\u00a0<strong>every<\/strong>\u00a0program executed under batch_test.pl. You can put them into \/tmp like I have here, but I would recommend you put them into a special directory since there will be LOTS of log files.<\/p>\n<pre class=\"lang:sh decode:true\">valgrind --tool=memcheck --leak-check=yes --show-reachable=yes --leak-resolution=high\n--log-file=\/tmp\/tests.%p --trace-children=yes --num-callers=16 .\/batch_test.pl -b -c<\/pre>\n<p>Then, in the same directory as the pile of\u00a0<span class=\"lang:sh decode:true  crayon-inline \" >tests.*<\/span>\u00a0files, run this script, which will collate the\u00a0<span class=\"lang:sh decode:true  crayon-inline \" >tests.*<\/span>\u00a0files associated with HTCondor daemons and tools into directories.<\/p>\n<pre class=\"lang:Perl decode:true\" title=\"Perl\">#! \/usr\/bin\/env perl\n\nuse warnings;\nuse strict;\nuse File::Basename;\nuse File::Path;\n\nsub collate_valgrind_logs\n{\nmy $prefix = shift @_;\nmy @files;\nmy $file;\nmy @lines;\nmy $line;\nmy @pieces;\n\n@files = `\/bin\/ls -1 $prefix*`;\nmap {chomp $_} @files;\n\n# foreach file which has a pattern of ^$prefix[0-9]+$ (some corefiles might\n# exist which could have that prefix which we don't want to process) we\n# figure out the command associated with it\nforeach $file (@files) {\nnext if ($file !~ \/^Q$prefixE[0-9]+$\/);\n\n# Get the line out of the file which represents the command that\n# the file is valgrinding.\n@lines = `egrep -e '== Command:' $file`;\nnext if ((scalar @lines) == 0);\nmap {chomp $_} @lines;\n\n# figure out the actual command\n@pieces = split \/ \/, $lines[0];\nmap {s\/^s+\/\/; chomp $_} @pieces;\n\n# make sure I have something to work with.\nnext if (!defined($pieces[2]));\n\n# get rid of an easy set of commands that aren't HTCondor processes.\nnext if ($pieces[2] !~ m:condor_w+$:);\n\n# get rid of any HTCondor process that appears to be a test suite\n# executable\nnext if ($pieces[2] =~ m:condor_exec:);\n\n# get the basename of the file\n$pieces[2] = basename($pieces[2]);\n\n# Now, mkdir the basename and copy the file into it.\nmkpath($pieces[2]);\nif (-d $pieces[2]) {\nsystem(\"cp $file $pieces[2]\");\n}\n\nprint \"$file, $pieces[2]n\";\n\n}\n}\n\nsub main\n{\ncollate_valgrind_logs(\"tests.\");\n}\n\nexit main();<\/pre>\n<h2>How to use the google heap profiler<\/h2>\n<p>The google heap profiler is part of the google-perftools package, which may be easily downloaded and compiled. This example used version 0.98.<\/p>\n<p>The heap profiler is useful for watching heap usage over time. Although the package documentation recommends linking the application with the tcmalloc library, I have had success with the LD_PRELOAD mechanism.<\/p>\n<p>This example shows how I used the google heap profiler on the startd:<\/p>\n<pre class=\"lang:sh decode:true \" ># from the central manager\ncondor_off -startd\n# back on the startd node\n# become the user who runs HTCondor\nksu\nenv LD_PRELOAD=\/p\/condor\/workspaces\/danb\/google-perftools-0.98-rh5\/lib\/libtcmalloc.so HEAPPROFILE=\/tmp\/startd.hprof HEAP_PROFILE_ALLOCATION_INTERVAL=5000000 \/unsup\/condor\/sbin\/condor_startd -f &gt;&amp; \/tmp\/startd.hprof.log &lt; \/dev\/null &amp;<\/pre>\n<p>Every 5M of heap allocation will result in a new file  <span class=\"lang:sh decode:true  crayon-inline \" >\/tmp\/startd.hprof.000x.heap<\/span>. These files can be analyzed using the pprof tool from the google-perftools. In addition to looking at individual snapshots, you can look at the difference between two files. One nice way to look at the output is with kcachegrind, the callgrind GUI. Example:<\/p>\n<pre class=\"lang:sh decode:true \" >pprof --callgrind \/path\/to\/condor_startd \/tmp\/startd.hprof.0001.heap &gt; \/tmp\/startd.0001.callgrind\nkcachegrind \/tmp\/startd.0001.callgrind<\/pre>\n<p>Then you can look at the call tree and see which paths allocated lots of heap, hopefully leading you to discover the source of trouble. If you configure kcachegrind to know where the source code is, you can even pull up a panel showing where in the code the allocations happened.<\/p>\n<p>One thing to beware of is that any code compiled with -fomit-frame-pointer may be untracked by the heap profiler. For example, openssl is usually compiled this way and I have found that the pprof &#8211;text report shows some things allocated in libcrypt code to show up as allocations in default_malloc_ex() but the pprof &#8211;callgrind report does not show this memory allocation at all. By turning off the compiler option when compiling openssl, I was able to get things to work as expected. This same issue may affect other memory profiling tools too.<\/p>\n<h2>How to use igprof for memory profiling<\/h2>\n<p>Igprof (the ignominous profiler,\u00a0<a href=\"http:\/\/igprof.sf.net\/\">http:\/\/igprof.sf.net<\/a>) is another convenient tool for tracking CPU performance and memory. RHEL5 RPMs are available here:<\/p>\n<p><a href=\"http:\/\/koji.hep.caltech.edu\/koji\/buildinfo?buildID=557\">http:\/\/koji.hep.caltech.edu\/koji\/buildinfo?buildID=557<\/a>.<\/p>\n<p>HTCondor isn&#8217;t really performance critical, but let&#8217;s use it for tracking leaks. Igprof normally tracks a process from beginning to end, and dumps a profile at process exit. Instead, we&#8217;ll use it to monitor the HTCondor tree and dump a periodic heap dump. A useful invocation of condor_master under igprof follows:<\/p>\n<pre class=\"lang:sh decode:true \" >igprof -D \/var\/log\/condor\/dump_profile -mp condor_master<\/pre>\n<p>Whenever a process sees the file \/var\/log\/condor\/dump_profile, it will dump a heap profile into $CWD (\/var\/log\/condor if you use the RPMs). An example output filename follows:<\/p>\n<pre class=\"lang:sh decode:true \" >igprof.condor_schedd.21553.1324688401.945964.gz<\/pre>\n<p>If you only want to monitor the condor_schedd, you can have igprof filter the processes it tracks with &#8220;-t&#8221;:<\/p>\n<pre class=\"lang:sh decode:true \" >igprof -D \/var\/log\/condor\/dump_profile -t condor_schedd -mp condor_master<\/pre>\n<p>Be careful about the dump_profile file: the HTCondor process will attempt to remove it after dumping the profile; if it is owned by root and the process runs as user condor, the removal will fail and the heap dump will occur again 1\/3 second later.<\/p>\n<p>If I&#8217;m tracking a slow leak, I setup a cron job to do a periodic dump:<\/p>\n<pre class=\"lang:sh decode:true \" >*\/10 * * * * condor touch \/var\/log\/condor\/dump_profile<\/pre>\n<p>Igprof produces compressed ASCII dumps about memory allocations which are pretty useless to humans. However, igprof-analyse can analyze the dumps and produce a sqlite3 database:<\/p>\n<pre class=\"wrap:true lang:sh decode:true \" >igprof-analyse -r MEM_LIVE --sqlite -d -v -g igprof.condor_schedd.21553.1324687875.867257.gz | sqlite3 ~\/igreport_condor_schedd.sql3<\/pre>\n<p>This will show the origination of all currently live memory allocations on the heap. A more useful snapshot would be to compare the current heap to a previous snapshot to see the difference:<\/p>\n<pre class=\"wrap:true lang:sh decode:true \" >igprof-analyse -r MEM_LIVE --sqlite -d -v -g --diff-mode -b igprof.condor_schedd.21553.1324687875.867257.gz igprof.condor_schedd.21553.1324689001.637857.gz | sqlite3 ~\/igreport_condor_schedd.sql3<\/pre>\n<p>Finally, sqlite3 databases aren&#8217;t very useful to humans either, so igprof can run an embedded webserver to display its results:<\/p>\n<pre class=\"lang:sh decode:true \" >igprof-navigator ~\/igreport_condor_schedd.sql3<\/pre>\n<h2>How to use gdb to trap memory allocations<\/h2>\n<p>I mention this only because it is a clever idea from Greg Thain that might be helpful in some situation. In practice, I have found it to slow down the application so much that timeouts happen and normal operation ceases. Too bad!<\/p>\n<p>The idea is to attach to a running daemon and log all of the memory allocation calls that are being made. After sufficient time, you can detach and let the program continue running.<\/p>\n<p>Here&#8217;s a gdb script that we used to watch the 64-bit collector:<\/p>\n<pre class=\"lang:sh decode:true \" >add-symbol-file \/tmp\/condor_collector.dbg\nset pagination off\nbreak malloc\ncommands 1\nwhere\nfinish\nend\ndefine hookpost-finish\ninfo reg rax\ncontinue\nend\nbreak free\ncommands 2\ninfo reg rdi\ncontinue\nend\ncontinue<\/pre>\n<p>With the above commands in a file named gdb_malloc_script, you can then attach to the daemon with the following command:<\/p>\n<pre class=\"wrap:true lang:sh decode:true \" >gdb gdb_malloc_script \/path\/to\/collector_malloc.log -p <\/pre>\n<p>Stopping it is a bit annoying. You have to kill gdb and then kill -CONT the program if it is in T state.<\/p>\n<p>With a suitable script for analyzing the malloc log, you could then see things like places in the code that allocated a lot of new memory during the time you were watching.<\/p>\n<p>Source :\u00a0<a href=\"https:\/\/htcondor-wiki.cs.wisc.edu\/index.cgi\/wiki?p=MemoryProfiling\" target=\"_blank\">https:\/\/htcondor-wiki.cs.wisc.edu\/index.cgi\/wiki?p=MemoryProfiling<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"<p>How to generate a core file unobtrusively This method is not nearly as powerful as some of the other options, but it has one big advantage: you can get a core file from a running daemon without killing it and restarting. It just interrupts the daemon for as long as it takes to write out [&hellip;]<\/p>\n","protected":false},"author":1,"featured_media":52,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[7,8,9,4],"tags":[12,13],"class_list":["post-19","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-cprogramming","category-cppprogramming","category-linuxos","category-programing","tag-gdb","tag-linux"],"_links":{"self":[{"href":"https:\/\/blog.anuram.in\/index.php?rest_route=\/wp\/v2\/posts\/19","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/blog.anuram.in\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/blog.anuram.in\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/blog.anuram.in\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/blog.anuram.in\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=19"}],"version-history":[{"count":0,"href":"https:\/\/blog.anuram.in\/index.php?rest_route=\/wp\/v2\/posts\/19\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/blog.anuram.in\/index.php?rest_route=\/"}],"wp:attachment":[{"href":"https:\/\/blog.anuram.in\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=19"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/blog.anuram.in\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=19"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/blog.anuram.in\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=19"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}