1Demonstrations of ugc. 2 3 4ugc traces garbage collection events in high-level languages, including Java, 5Python, Ruby, and Node. Each GC event is printed with some additional 6information provided by that language's runtime, if available. The duration of 7the GC event is also provided. 8 9For example, to trace all garbage collection events in a specific Node process: 10 11# ugc $(pidof node) 12Tracing garbage collections in node process 30012... Ctrl-C to quit. 13START TIME (us) DESCRIPTION 141.500 1181.00 GC scavenge 151.505 1704.00 GC scavenge 161.509 1534.00 GC scavenge 171.515 1953.00 GC scavenge 181.519 2155.00 GC scavenge 191.525 2055.00 GC scavenge 201.530 2164.00 GC scavenge 211.536 2170.00 GC scavenge 221.541 2237.00 GC scavenge 231.547 1982.00 GC scavenge 241.551 2333.00 GC scavenge 251.557 2043.00 GC scavenge 261.561 2028.00 GC scavenge 271.573 3650.00 GC scavenge 281.580 4443.00 GC scavenge 291.604 6236.00 GC scavenge 301.615 8324.00 GC scavenge 311.659 11249.00 GC scavenge 321.678 16084.00 GC scavenge 331.747 15250.00 GC scavenge 341.937 191.00 GC incremental mark 352.001 63120.00 GC mark-sweep-compact 363.185 153.00 GC incremental mark 373.207 20847.00 GC mark-sweep-compact 38^C 39 40The above output shows some fairly long GCs, notably around 2 seconds in there 41is a collection that takes over 60ms (mark-sweep-compact). 42 43Occasionally, it might be useful to filter out collections that are very short, 44or display only collections that have a specific description. The -M and -F 45switches can be useful for this: 46 47# ugc -F Tenured $(pidof java) 48Tracing garbage collections in java process 29907... Ctrl-C to quit. 49START TIME (us) DESCRIPTION 500.360 4309.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 512.459 4232.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 524.648 4139.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 53^C 54 55# ugc -M 1 $(pidof java) 56Tracing garbage collections in java process 29907... Ctrl-C to quit. 57START TIME (us) DESCRIPTION 580.160 3715.00 MarkSweepCompact Code Cache used=287528->3209472 max=173408256->251658240 590.160 3975.00 MarkSweepCompact Metaspace used=287528->3092104 max=173408256->18446744073709551615 600.160 4058.00 MarkSweepCompact Compressed Class Space used=287528->266840 max=173408256->1073741824 610.160 4110.00 MarkSweepCompact Eden Space used=287528->0 max=173408256->69337088 620.160 4159.00 MarkSweepCompact Survivor Space used=287528->0 max=173408256->8650752 630.160 4207.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 640.160 4289.00 used=0->0 max=0->0 65^C 66 67 68USAGE message: 69 70# ugc -h 71usage: ugc.py [-h] [-l {java,python,ruby,node}] [-v] [-m] [-M MINIMUM] 72 [-F FILTER] 73 pid 74 75Summarize garbage collection events in high-level languages. 76 77positional arguments: 78 pid process id to attach to 79 80optional arguments: 81 -h, --help show this help message and exit 82 -l {java,python,ruby,node}, --language {java,python,ruby,node} 83 language to trace 84 -v, --verbose verbose mode: print the BPF program (for debugging 85 purposes) 86 -m, --milliseconds report times in milliseconds (default is microseconds) 87 -M MINIMUM, --minimum MINIMUM 88 display only GCs longer than this many milliseconds 89 -F FILTER, --filter FILTER 90 display only GCs whose description contains this text 91 92examples: 93 ./ugc -l java 185 # trace Java GCs in process 185 94 ./ugc -l ruby 1344 -m # trace Ruby GCs reporting in ms 95 ./ugc -M 10 -l java 185 # trace only Java GCs longer than 10ms 96