1 Demonstrations of ugc. 2 3 4 ugc traces garbage collection events in high-level languages, including Java, 5 Python, Ruby, and Node. Each GC event is printed with some additional 6 information provided by that language's runtime, if available. The duration of 7 the GC event is also provided. 8 9 For example, to trace all garbage collection events in a specific Node process: 10 11 # ugc $(pidof node) 12 Tracing garbage collections in node process 30012... Ctrl-C to quit. 13 START TIME (us) DESCRIPTION 14 1.500 1181.00 GC scavenge 15 1.505 1704.00 GC scavenge 16 1.509 1534.00 GC scavenge 17 1.515 1953.00 GC scavenge 18 1.519 2155.00 GC scavenge 19 1.525 2055.00 GC scavenge 20 1.530 2164.00 GC scavenge 21 1.536 2170.00 GC scavenge 22 1.541 2237.00 GC scavenge 23 1.547 1982.00 GC scavenge 24 1.551 2333.00 GC scavenge 25 1.557 2043.00 GC scavenge 26 1.561 2028.00 GC scavenge 27 1.573 3650.00 GC scavenge 28 1.580 4443.00 GC scavenge 29 1.604 6236.00 GC scavenge 30 1.615 8324.00 GC scavenge 31 1.659 11249.00 GC scavenge 32 1.678 16084.00 GC scavenge 33 1.747 15250.00 GC scavenge 34 1.937 191.00 GC incremental mark 35 2.001 63120.00 GC mark-sweep-compact 36 3.185 153.00 GC incremental mark 37 3.207 20847.00 GC mark-sweep-compact 38 ^C 39 40 The above output shows some fairly long GCs, notably around 2 seconds in there 41 is a collection that takes over 60ms (mark-sweep-compact). 42 43 Occasionally, it might be useful to filter out collections that are very short, 44 or display only collections that have a specific description. The -M and -F 45 switches can be useful for this: 46 47 # ugc -F Tenured $(pidof java) 48 Tracing garbage collections in java process 29907... Ctrl-C to quit. 49 START TIME (us) DESCRIPTION 50 0.360 4309.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 51 2.459 4232.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 52 4.648 4139.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 53 ^C 54 55 # ugc -M 1 $(pidof java) 56 Tracing garbage collections in java process 29907... Ctrl-C to quit. 57 START TIME (us) DESCRIPTION 58 0.160 3715.00 MarkSweepCompact Code Cache used=287528->3209472 max=173408256->251658240 59 0.160 3975.00 MarkSweepCompact Metaspace used=287528->3092104 max=173408256->18446744073709551615 60 0.160 4058.00 MarkSweepCompact Compressed Class Space used=287528->266840 max=173408256->1073741824 61 0.160 4110.00 MarkSweepCompact Eden Space used=287528->0 max=173408256->69337088 62 0.160 4159.00 MarkSweepCompact Survivor Space used=287528->0 max=173408256->8650752 63 0.160 4207.00 MarkSweepCompact Tenured Gen used=287528->287528 max=173408256->173408256 64 0.160 4289.00 used=0->0 max=0->0 65 ^C 66 67 68 USAGE message: 69 70 # ugc -h 71 usage: ugc.py [-h] [-l {java,python,ruby,node}] [-v] [-m] [-M MINIMUM] 72 [-F FILTER] 73 pid 74 75 Summarize garbage collection events in high-level languages. 76 77 positional arguments: 78 pid process id to attach to 79 80 optional 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 92 examples: 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
