You can not select more than 25 topics
Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.
247 lines
7.6 KiB
247 lines
7.6 KiB
#!/usr/bin/python |
|
# @lint-avoid-python-3-compatibility-imports |
|
# |
|
# ugc Summarize garbage collection events in high-level languages. |
|
# For Linux, uses BCC, eBPF. |
|
# |
|
# USAGE: ugc [-v] [-m] [-M MSEC] [-F FILTER] {java,node,python,ruby} pid |
|
# |
|
# Copyright 2016 Sasha Goldshtein |
|
# Licensed under the Apache License, Version 2.0 (the "License") |
|
# |
|
# 19-Oct-2016 Sasha Goldshtein Created this. |
|
|
|
from __future__ import print_function |
|
import argparse |
|
from bcc import BPF, USDT, utils |
|
import ctypes as ct |
|
import time |
|
import os |
|
|
|
languages = ["java", "node", "python", "ruby"] |
|
|
|
examples = """examples: |
|
./ugc -l java 185 # trace Java GCs in process 185 |
|
./ugc -l ruby 1344 -m # trace Ruby GCs reporting in ms |
|
./ugc -M 10 -l java 185 # trace only Java GCs longer than 10ms |
|
""" |
|
parser = argparse.ArgumentParser( |
|
description="Summarize garbage collection events in high-level languages.", |
|
formatter_class=argparse.RawDescriptionHelpFormatter, |
|
epilog=examples) |
|
parser.add_argument("-l", "--language", choices=languages, |
|
help="language to trace") |
|
parser.add_argument("pid", type=int, help="process id to attach to") |
|
parser.add_argument("-v", "--verbose", action="store_true", |
|
help="verbose mode: print the BPF program (for debugging purposes)") |
|
parser.add_argument("-m", "--milliseconds", action="store_true", |
|
help="report times in milliseconds (default is microseconds)") |
|
parser.add_argument("-M", "--minimum", type=int, default=0, |
|
help="display only GCs longer than this many milliseconds") |
|
parser.add_argument("-F", "--filter", type=str, |
|
help="display only GCs whose description contains this text") |
|
parser.add_argument("--ebpf", action="store_true", |
|
help=argparse.SUPPRESS) |
|
args = parser.parse_args() |
|
|
|
usdt = USDT(pid=args.pid) |
|
|
|
program = """ |
|
struct gc_event_t { |
|
u64 probe_index; |
|
u64 elapsed_ns; |
|
u64 field1; |
|
u64 field2; |
|
u64 field3; |
|
u64 field4; |
|
char string1[32]; |
|
char string2[32]; |
|
}; |
|
struct entry_t { |
|
u64 start_ns; |
|
u64 field1; |
|
u64 field2; |
|
}; |
|
|
|
BPF_PERF_OUTPUT(gcs); |
|
BPF_HASH(entry, u64, struct entry_t); |
|
""" |
|
|
|
class Probe(object): |
|
def __init__(self, begin, end, begin_save, end_save, formatter): |
|
self.begin = begin |
|
self.end = end |
|
self.begin_save = begin_save |
|
self.end_save = end_save |
|
self.formatter = formatter |
|
|
|
def generate(self): |
|
text = """ |
|
int trace_%s(struct pt_regs *ctx) { |
|
u64 pid = bpf_get_current_pid_tgid(); |
|
struct entry_t e = {}; |
|
e.start_ns = bpf_ktime_get_ns(); |
|
%s |
|
entry.update(&pid, &e); |
|
return 0; |
|
} |
|
int trace_%s(struct pt_regs *ctx) { |
|
u64 elapsed; |
|
struct entry_t *e; |
|
struct gc_event_t event = {}; |
|
u64 pid = bpf_get_current_pid_tgid(); |
|
e = entry.lookup(&pid); |
|
if (!e) { |
|
return 0; // missed the entry event on this thread |
|
} |
|
elapsed = bpf_ktime_get_ns() - e->start_ns; |
|
if (elapsed < %d) { |
|
return 0; |
|
} |
|
event.elapsed_ns = elapsed; |
|
%s |
|
gcs.perf_submit(ctx, &event, sizeof(event)); |
|
return 0; |
|
} |
|
""" % (self.begin, self.begin_save, self.end, |
|
args.minimum * 1000000, self.end_save) |
|
return text |
|
|
|
def attach(self): |
|
usdt.enable_probe_or_bail(self.begin, "trace_%s" % self.begin) |
|
usdt.enable_probe_or_bail(self.end, "trace_%s" % self.end) |
|
|
|
def format(self, data): |
|
return self.formatter(data) |
|
|
|
probes = [] |
|
|
|
language = args.language |
|
if not language: |
|
language = utils.detect_language(languages, args.pid) |
|
|
|
# |
|
# Java |
|
# |
|
if language == "java": |
|
# Oddly, the gc__begin/gc__end probes don't really have any useful |
|
# information, while the mem__pool* ones do. There's also a bunch of |
|
# probes described in the hotspot_gc*.stp file which aren't there |
|
# when looking at a live Java process. |
|
begin_save = """ |
|
bpf_usdt_readarg(6, ctx, &e.field1); // used bytes |
|
bpf_usdt_readarg(8, ctx, &e.field2); // max bytes |
|
""" |
|
end_save = """ |
|
event.field1 = e->field1; // used bytes at start |
|
event.field2 = e->field2; // max bytes at start |
|
bpf_usdt_readarg(6, ctx, &event.field3); // used bytes at end |
|
bpf_usdt_readarg(8, ctx, &event.field4); // max bytes at end |
|
u64 manager = 0, pool = 0; |
|
bpf_usdt_readarg(1, ctx, &manager); // ptr to manager name |
|
bpf_usdt_readarg(3, ctx, &pool); // ptr to pool name |
|
bpf_probe_read(&event.string1, sizeof(event.string1), (void *)manager); |
|
bpf_probe_read(&event.string2, sizeof(event.string2), (void *)pool); |
|
""" |
|
|
|
def formatter(e): |
|
"%s %s used=%d->%d max=%d->%d" % \ |
|
(e.string1, e.string2, e.field1, e.field3, e.field2, e.field4) |
|
probes.append(Probe("mem__pool__gc__begin", "mem__pool__gc__end", |
|
begin_save, end_save, formatter)) |
|
probes.append(Probe("gc__begin", "gc__end", |
|
"", "", lambda _: "no additional info available")) |
|
# |
|
# Node |
|
# |
|
elif language == "node": |
|
end_save = """ |
|
u32 gc_type = 0; |
|
bpf_usdt_readarg(1, ctx, &gc_type); |
|
event.field1 = gc_type; |
|
""" |
|
descs = {"GC scavenge": 1, "GC mark-sweep-compact": 2, |
|
"GC incremental mark": 4, "GC weak callbacks": 8} |
|
probes.append(Probe("gc__start", "gc__done", "", end_save, |
|
lambda e: str.join(", ", |
|
[desc for desc, val in descs.items() |
|
if e.field1 & val != 0]))) |
|
# |
|
# Python |
|
# |
|
elif language == "python": |
|
begin_save = """ |
|
int gen = 0; |
|
bpf_usdt_readarg(1, ctx, &gen); |
|
e.field1 = gen; |
|
""" |
|
end_save = """ |
|
long objs = 0; |
|
bpf_usdt_readarg(1, ctx, &objs); |
|
event.field1 = e->field1; |
|
event.field2 = objs; |
|
""" |
|
|
|
def formatter(event): |
|
"gen %d GC collected %d objects" % \ |
|
(event.field1, event.field2) |
|
probes.append(Probe("gc__start", "gc__done", |
|
begin_save, end_save, formatter)) |
|
# |
|
# Ruby |
|
# |
|
elif language == "ruby": |
|
# Ruby GC probes do not have any additional information available. |
|
probes.append(Probe("gc__mark__begin", "gc__mark__end", |
|
"", "", lambda _: "GC mark stage")) |
|
probes.append(Probe("gc__sweep__begin", "gc__sweep__end", |
|
"", "", lambda _: "GC sweep stage")) |
|
|
|
else: |
|
print("No language detected; use -l to trace a language.") |
|
exit(1) |
|
|
|
|
|
for probe in probes: |
|
program += probe.generate() |
|
probe.attach() |
|
|
|
if args.ebpf or args.verbose: |
|
if args.verbose: |
|
print(usdt.get_text()) |
|
print(program) |
|
if args.ebpf: |
|
exit() |
|
|
|
bpf = BPF(text=program, usdt_contexts=[usdt]) |
|
print("Tracing garbage collections in %s process %d... Ctrl-C to quit." % |
|
(language, args.pid)) |
|
time_col = "TIME (ms)" if args.milliseconds else "TIME (us)" |
|
print("%-8s %-8s %-40s" % ("START", time_col, "DESCRIPTION")) |
|
|
|
class GCEvent(ct.Structure): |
|
_fields_ = [ |
|
("probe_index", ct.c_ulonglong), |
|
("elapsed_ns", ct.c_ulonglong), |
|
("field1", ct.c_ulonglong), |
|
("field2", ct.c_ulonglong), |
|
("field3", ct.c_ulonglong), |
|
("field4", ct.c_ulonglong), |
|
("string1", ct.c_char * 32), |
|
("string2", ct.c_char * 32) |
|
] |
|
|
|
start_ts = time.time() |
|
|
|
def print_event(cpu, data, size): |
|
event = ct.cast(data, ct.POINTER(GCEvent)).contents |
|
elapsed = event.elapsed_ns / 1000000 if args.milliseconds else \ |
|
event.elapsed_ns / 1000 |
|
description = probes[event.probe_index].format(event) |
|
if args.filter and args.filter not in description: |
|
return |
|
print("%-8.3f %-8.2f %s" % (time.time() - start_ts, elapsed, description)) |
|
|
|
bpf["gcs"].open_perf_buffer(print_event) |
|
while 1: |
|
bpf.perf_buffer_poll()
|
|
|