{"id":154,"date":"2024-01-01T23:38:50","date_gmt":"2024-01-01T23:38:50","guid":{"rendered":"https:\/\/mvermeulen.org\/perf\/?p=154"},"modified":"2024-01-01T23:38:52","modified_gmt":"2024-01-01T23:38:52","slug":"topdown-adding-process-trees-and-statistics","status":"publish","type":"post","link":"https:\/\/mvermeulen.org\/perf\/2024\/01\/01\/topdown-adding-process-trees-and-statistics\/","title":{"rendered":"topdown &#8211; adding process trees and statistics"},"content":{"rendered":"\n<p>I have not enhanced the topdown tool with ability to print process trees.  This enables the key features of my previous &#8220;wspy&#8221; command.<\/p>\n\n\n\n<p>The interfaces is as follows. I added the following options to topdown to record process information:<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>\t--tree &lt;file>             - create CSV of processes\n\t--tree-cmdline            - record full command lines<\/code><\/pre>\n\n\n\n<p>The &#8211;tree option uses strace(2) to record fork\/exec\/exit events  and save information to the file for later processing.  An example of some information saved is as follows:<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>0.000 14119 root\n0.002 14119 fork 14120\n0.017 14120 comm cc1\n0.017 14120 cmdline \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/cc1 -quiet -imultiarch x86_64-linux-gnu hello.c -quiet -dumpbase hello.c -dumpbase-ext .c -mtune=generic -march=x86-64 -fasynchronous-unwind-tables -fstack-protector-strong -Wformat -Wformat-security -fstack-clash-protection -fcf-protection -o \/tmp\/ccIyphnx.s\n0.017 14120 exit 14120 (cc1) t 14119 14118 13158 34819 14118 1077936128 1221 0 0 0 1 0 0 0 20 0 1 0 1313576 46571520 3835 18446744073709551615 5890048 21573621 140722169364960 0 0 0 0 0 1256 1 0 0 17 18 0 0 0 0 0 30095936 30148584 59514880 140722169373230 140722169373523 140722169373523 140722169376723 0\n0.018 14119 fork 14121\n0.021 14121 comm as\n0.021 14121 cmdline as --64 -o \/tmp\/cceku4R5.o \/tmp\/ccIyphnx.s\n0.021 14121 exit 14121 (as) t 14119 14118 13158 34819 14118 1077936128 441 0 0 0 0 0 0 0 20 0 1 0 1313578 12435456 1332 18446744073709551615 94138168020992 94138168333961 140723056042896 0 0 0 0 0 1256 1 0 0 17 11 0 0 0 0 0 94138168430896 94138168453272 94138176069632 140723056051009 140723056051052 140723056051052 140723056054252 0\n0.022 14119 fork 14124\n0.023 14124 fork 14125\n0.040 14125 comm ld\n0.040 14125 cmdline \/usr\/bin\/ld -plugin \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/liblto_plugin.so -plugin-opt=\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/lto-wrapper -plugin-opt=-fresolution=\/tmp\/ccWwmx4O.res -plugin-opt=-pass-through=-lgcc -plugin-opt=-pass-through=-lgcc_s -plugin-opt=-pass-through=-lc -plugin-opt=-pass-through=-lgcc -plugin-opt=-pass-through=-lgcc_s --build-id --eh-frame-hdr -m elf_x86_64 --hash-style=gnu --as-needed -dynamic-linker \/lib64\/ld-linux-x86-64.so.2 -pie -z now -z relro -o hello \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu\/Scrt1.o \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu\/crti.o \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/crtbeginS.o -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11 -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/..\/lib -L\/lib\/x86_64-linux-gnu -L\/lib\/..\/lib -L\/usr\/lib\/x86_64-linux-gnu -L\/usr\/lib\/..\/lib -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/.. \/tmp\/cceku4R5.o -lgcc --push-state --as-needed -lgcc_s --pop-state -lc -lgcc --push-state --as-needed -lgcc_s --pop-state \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/crtendS.o \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu\/crtn.o\n0.040 14125 exit 14125 (ld) t 14124 14118 13158 34819 14118 1077936128 1732 0 0 0 1 0 0 0 20 0 1 0 1313578 16846848 2276 18446744073709551615 94366230806528 94366231102693 140724178835088 0 0 0 0 0 0 1 0 0 17 20 0 0 0 0 0 94366232461104 94366232495352 94366259900416 140724178836727 140724178837886 140724178837886 140724178841580 0\n0.040 14124 comm collect2\n0.040 14124 cmdline \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/collect2 -plugin \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/liblto_plugin.so -plugin-opt=\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/lto-wrapper -plugin-opt=-fresolution=\/tmp\/ccWwmx4O.res -plugin-opt=-pass-through=-lgcc -plugin-opt=-pass-through=-lgcc_s -plugin-opt=-pass-through=-lc -plugin-opt=-pass-through=-lgcc -plugin-opt=-pass-through=-lgcc_s --build-id --eh-frame-hdr -m elf_x86_64 --hash-style=gnu --as-needed -dynamic-linker \/lib64\/ld-linux-x86-64.so.2 -pie -z now -z relro -o hello \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu\/Scrt1.o \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu\/crti.o \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/crtbeginS.o -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11 -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/..\/lib -L\/lib\/x86_64-linux-gnu -L\/lib\/..\/lib -L\/usr\/lib\/x86_64-linux-gnu -L\/usr\/lib\/..\/lib -L\/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/.. \/tmp\/cceku4R5.o -lgcc --push-state --as-needed -lgcc_s --pop-state -lc -lgcc --push-state --as-needed -lgcc_s --pop-state \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/crtendS.o \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/..\/..\/..\/x86_64-linux-gnu\/crtn.o\n0.040 14124 exit 14124 (collect2) t 14119 14118 13158 34819 14118 1077936128 85 1732 0 0 0 0 1 0 20 0 1 0 1313578 8839168 250 18446744073709551615 4202496 4414097 140733621318048 0 0 0 0 0 9287 1 0 0 17 19 0 0 0 0 0 4488704 4494640 30085120 140733621320891 140733621322080 140733621322080 140733621325774 0\n0.041 14119 comm gcc\n0.041 14119 cmdline gcc -o hello hello.c\n0.041 14119 exit 14119 (gcc) t 14118 14118 13158 34819 14118 1077936128 135 3479 0 0 0 0 2 1 20 0 1 0 1313576 9617408 251 18446744073709551615 4206592 4563953 140732373361024 0 0 0 0 0 20483 1 0 0 17 14 0 0 0 0 0 5114624 5124176 36139008 140732373369904 140732373369925 140732373369925 140732373372907 0<\/code><\/pre>\n\n\n\n<p>The &#8220;exit&#8221; event captures the contents of \/proc\/&lt;pid>\/stat when the process exits.  I am not sure if this is reliable for hundreds of thousands of processes but for smaller several hundred examples it works find.  If the &#8211;tree-cmdline option is given then we also capture \/proc\/&lt;pid>\/cmdline when the process exits.<\/p>\n\n\n\n<p>This data file can then be processed with the proctree program with the following options<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>.\/source\/wspy\/proctree: fatal error: usage: .\/source\/wspy\/proctree -&#91;CcFfSsTtuv]&#91;-w width] file\n\t-C\tturn on longer command line\n\t-c\tturn on abbreviated command (default)\n\t-F\turn on start\/finish info (default)\n\t-f\tturn off start\/finish info\n\t-S\tturn on summary output\n\t-s\tturn off summary output (default)\n\t-T\tturn on tree output (default)\n\t-t\tturn off tree output\n\t-U\tturn off utime in tree\n\t-u\tturn on utime in tree\n\t-v\tverbose messages\n\t-w width\tset command width<\/code><\/pre>\n\n\n\n<p>Here is a basic output with both summary statistics and tree information<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>5 processes\n\t  1 cc1                      0.01     0.00\n\t  1 ld                       0.01     0.00\n\t  1 as                       0.00     0.00\n\t  1 collect2                 0.00     0.00\n\t  1 gcc                      0.00     0.00\n0 processes running\n3 maximum processes\n\n14119) gcc start=0.00  finish=0.04 \n  14120) cc1 start=0.00  finish=0.02 \n  14121) as start=0.02  finish=0.02 \n  14124) collect2 start=0.02  finish=0.04 \n    14125) ld start=0.02  finish=0.04 <\/code><\/pre>\n\n\n\n<p>We can see more of the command line by adding the -C switch and also increasing the -w width<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>5 processes\n\t  1 cc1                      0.01     0.00\n\t  1 ld                       0.01     0.00\n\t  1 as                       0.00     0.00\n\t  1 collect2                 0.00     0.00\n\t  1 gcc                      0.00     0.00\n0 processes running\n3 maximum processes\n\n14119) gcc -o hello hello.c start=0.00  finish=0.04 \n  14120) \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/cc1 -quiet -imultiarch x86_64-linux-gnu hello.c -quiet -dumpbase hello.c -dum start=0.00  finish=0.02 \n  14121) as --64 -o \/tmp\/cceku4R5.o \/tmp\/ccIyphnx.s start=0.02  finish=0.02 \n  14124) \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/collect2 -plugin \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/liblto_plugin.so -plugin-op start=0.02  finish=0.04 \n    14125) \/usr\/bin\/ld -plugin \/usr\/lib\/gcc\/x86_64-linux-gnu\/11\/liblto_plugin.so -plugin-opt=\/usr\/lib\/gcc\/x86_64-linux- start=0.02  finish=0.04 <\/code><\/pre>\n\n\n\n<p>Overall, this is a useful tool that helps me get more of the process overview e.g. single-threaded vs multi-threaded as well as summarizing processes that take the most time.  As needed I also have a mechanism to decorate with additional instrumentation.  Two examples might be (a) checking for particular syscalls e.g. file open events (b) investigating more of a process drill down not to the initial parent but to multiple sub-runs.<\/p>\n\n\n\n<p>However, for now I have a basic topdown tool with both periodic output and a process tree to examine different workloads.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>I have not enhanced the topdown tool with ability to print process trees. This enables the key features of my previous &#8220;wspy&#8221; command. The interfaces is as follows. I added the following options to topdown to record process information: The <span class=\"excerpt-dots\">&hellip;<\/span> <a class=\"more-link\" href=\"https:\/\/mvermeulen.org\/perf\/2024\/01\/01\/topdown-adding-process-trees-and-statistics\/\"><span class=\"more-msg\">Continue reading &rarr;<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[5],"tags":[8,20],"class_list":["post-154","post","type-post","status-publish","format-standard","hentry","category-tools","tag-topdown","tag-tree"],"_links":{"self":[{"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/posts\/154","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/comments?post=154"}],"version-history":[{"count":1,"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/posts\/154\/revisions"}],"predecessor-version":[{"id":155,"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/posts\/154\/revisions\/155"}],"wp:attachment":[{"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/media?parent=154"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/categories?post=154"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/mvermeulen.org\/perf\/wp-json\/wp\/v2\/tags?post=154"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}