Skip to content

Commit 2d46b17

Browse files
vadimskipinvadimskipin
committed
Use USDT probes to collect latency histogram
1 parent bcb7ead commit 2d46b17

6 files changed

Lines changed: 605 additions & 141 deletions

File tree

‎bb‎

Lines changed: 144 additions & 87 deletions
Original file line numberDiff line numberDiff line change
@@ -391,26 +391,30 @@ def _render_flamegraph(folded_file: str, out_svg: str, title: str) -> None:
391391
)
392392

393393

394-
def _run_flamegraph(preset: str, name: str, client_args: list[str]) -> None:
394+
def _run_profiler(
395+
preset: str,
396+
name: str,
397+
client_args: list[str],
398+
profiler_args: list[str],
399+
out_suffix: str,
400+
) -> str:
395401
cmd_build(preset, ["profiler"])
396402

397403
profiler_bin = os.path.join(ROOT, f"build/{preset}/bin/profiler")
398-
folded_stacks = os.path.join(ROOT, f"build/{preset}/{name}.flamegraph.folded")
399-
out_svg = os.path.join(ROOT, f"build/{preset}/{name}.flamegraph.svg")
404+
out_file = os.path.join(ROOT, f"build/{preset}/{name}.{out_suffix}")
400405
verbose_flag = ["--verbose"] if log.isEnabledFor(logging.DEBUG) else []
401406

402-
log.info("profiling %s -> %s", name, out_svg)
407+
log.info("profiling %s -> %s", name, out_file)
403408

404409
client = start_process(*client_args, stdout=subprocess.DEVNULL)
405410

406411
try:
407-
with open(folded_stacks, "w") as f:
412+
with open(out_file, "w") as f:
408413
profiler = start_process(
409414
profiler_bin,
410415
"--pid",
411416
str(client.pid),
412-
"--off-cpu",
413-
"--kernel-stacks",
417+
*profiler_args,
414418
*verbose_flag,
415419
stdout=f,
416420
)
@@ -427,12 +431,35 @@ def _run_flamegraph(preset: str, name: str, client_args: list[str]) -> None:
427431
client.kill()
428432
raise
429433

434+
return out_file
435+
436+
437+
def _run_flamegraph(preset: str, name: str, client_args: list[str]) -> None:
438+
folded_stacks = _run_profiler(
439+
preset,
440+
name,
441+
client_args,
442+
["--on-cpu", "--off-cpu", "--kernel-stacks"],
443+
"flamegraph.folded",
444+
)
445+
446+
out_svg = os.path.join(ROOT, f"build/{preset}/{name}.flamegraph.svg")
430447
_render_flamegraph(folded_stacks, out_svg, f"{name} on-CPU + off-CPU")
431448

432449
log.info("folded stacks: %s", folded_stacks)
433450
log.info("flamegraph: %s", out_svg)
434451

435452

453+
def _run_latency(preset: str, name: str, client_args: list[str]) -> None:
454+
latency_report = _run_profiler(preset, name, client_args, ["--usdt"], "latency.txt")
455+
456+
# Echo the latency table to the user in addition to leaving it on disk.
457+
with open(latency_report) as f:
458+
sys.stdout.write(f.read())
459+
460+
log.info("latency report: %s", latency_report)
461+
462+
436463
def _print_counters(data: dict[str, Any]) -> None:
437464
counters = data.get("counters", {})
438465
if not counters:
@@ -504,6 +531,7 @@ class NetPerfParams:
504531
connections: list[int] = field(default_factory=lambda: [1000])
505532
delay: str = "0"
506533
flamegraph: bool = False
534+
latency: bool = False
507535
print_counters: bool = False
508536
timeout: int = 180
509537

@@ -553,31 +581,31 @@ def _cmd_net_perf_impl(preset: str, params: NetPerfParams, binary: str) -> None:
553581
)
554582

555583
try:
556-
if params.flamegraph:
557-
_run_flamegraph(
558-
preset,
559-
binary,
560-
[
561-
"taskset",
562-
"-c",
563-
client_cpus,
564-
net_perf,
565-
"client",
566-
"--host",
567-
params.host,
568-
"--port",
569-
str(params.port),
570-
"--connections",
571-
str(params.connections[0]),
572-
"--msg-size",
573-
str(params.msg_size),
574-
"--duration",
575-
str(params.duration),
576-
"--warmup",
577-
str(params.warmup),
578-
*verbose_flag,
579-
],
580-
)
584+
if params.flamegraph or params.latency:
585+
client_cmd = [
586+
"taskset",
587+
"-c",
588+
client_cpus,
589+
net_perf,
590+
"client",
591+
"--host",
592+
params.host,
593+
"--port",
594+
str(params.port),
595+
"--connections",
596+
str(params.connections[0]),
597+
"--msg-size",
598+
str(params.msg_size),
599+
"--duration",
600+
str(params.duration),
601+
"--warmup",
602+
str(params.warmup),
603+
*verbose_flag,
604+
]
605+
if params.flamegraph:
606+
_run_flamegraph(preset, binary, client_cmd)
607+
else:
608+
_run_latency(preset, binary, client_cmd)
581609
else:
582610
print(_perf_row(_NP_HEADERS, _NP_WIDTH))
583611
print(_perf_sep(_NP_WIDTH))
@@ -645,6 +673,7 @@ class FilePerfParams:
645673
iodepth: list[int] = field(default_factory=lambda: [16])
646674
rw: list[str] = field(default_factory=lambda: ["randread"])
647675
flamegraph: bool = False
676+
latency: bool = False
648677
print_counters: bool = False
649678
timeout: int = 180
650679

@@ -683,32 +712,32 @@ def cmd_file_perf(preset: str, params: FilePerfParams) -> None:
683712
verbose_flag = ["--verbose"] if log.isEnabledFor(logging.DEBUG) else []
684713

685714
try:
686-
if params.flamegraph:
715+
if params.flamegraph or params.latency:
687716
jobs, depth, mode = configs[0]
688-
_run_flamegraph(
689-
preset,
690-
"file-perf",
691-
[
692-
file_perf,
693-
"--numjobs",
694-
str(jobs),
695-
"--iodepth",
696-
str(depth),
697-
"--bs",
698-
params.bs,
699-
"--rw",
700-
mode,
701-
"--size",
702-
params.size,
703-
"--runtime",
704-
str(params.duration),
705-
"--warmup",
706-
str(params.warmup),
707-
"--filename",
708-
params.file,
709-
*verbose_flag,
710-
],
711-
)
717+
client_cmd = [
718+
file_perf,
719+
"--numjobs",
720+
str(jobs),
721+
"--iodepth",
722+
str(depth),
723+
"--bs",
724+
params.bs,
725+
"--rw",
726+
mode,
727+
"--size",
728+
params.size,
729+
"--runtime",
730+
str(params.duration),
731+
"--warmup",
732+
str(params.warmup),
733+
"--filename",
734+
params.file,
735+
*verbose_flag,
736+
]
737+
if params.flamegraph:
738+
_run_flamegraph(preset, "file-perf", client_cmd)
739+
else:
740+
_run_latency(preset, "file-perf", client_cmd)
712741
else:
713742
print(_perf_row(_FP_HEADERS, _FP_WIDTHS))
714743
print(_perf_sep(_FP_WIDTHS))
@@ -960,6 +989,7 @@ class HttpPerfParams:
960989
delay: str = "0"
961990
threads: bool = False
962991
flamegraph: bool = False
992+
latency: bool = False
963993
print_counters: bool = False
964994
timeout: int = 180
965995

@@ -1046,30 +1076,31 @@ def cmd_http_perf(preset: str, params: HttpPerfParams) -> None:
10461076
verbose_flag = ["--verbose"] if log.isEnabledFor(logging.DEBUG) else []
10471077

10481078
try:
1049-
if params.flamegraph:
1050-
_run_flamegraph(
1051-
preset,
1052-
"http-perf-" + mode,
1053-
[
1054-
"taskset",
1055-
"-c",
1056-
client_cpus,
1057-
http_perf,
1058-
"client",
1059-
"--host",
1060-
params.host,
1061-
"--port",
1062-
str(params.port),
1063-
"--connections",
1064-
str(params.connections[0]),
1065-
"--duration",
1066-
str(params.duration),
1067-
"--warmup",
1068-
str(params.warmup),
1069-
*threads_flag,
1070-
*verbose_flag,
1071-
],
1072-
)
1079+
if params.flamegraph or params.latency:
1080+
client_cmd = [
1081+
"taskset",
1082+
"-c",
1083+
client_cpus,
1084+
http_perf,
1085+
"client",
1086+
"--host",
1087+
params.host,
1088+
"--port",
1089+
str(params.port),
1090+
"--connections",
1091+
str(params.connections[0]),
1092+
"--duration",
1093+
str(params.duration),
1094+
"--warmup",
1095+
str(params.warmup),
1096+
*threads_flag,
1097+
*verbose_flag,
1098+
]
1099+
tag = "http-perf-" + mode
1100+
if params.flamegraph:
1101+
_run_flamegraph(preset, tag, client_cmd)
1102+
else:
1103+
_run_latency(preset, tag, client_cmd)
10731104
else:
10741105
print(_perf_row(_HP_HEADERS, _HP_WIDTHS))
10751106
print(_perf_sep(_HP_WIDTHS))
@@ -1159,6 +1190,7 @@ class S3PerfParams:
11591190
rw: list[str] = field(default_factory=lambda: ["read"])
11601191
threads: bool = False
11611192
flamegraph: bool = False
1193+
latency: bool = False
11621194
data_dir: str = "/dev/shm/minio-data"
11631195
print_counters: bool = False
11641196
timeout: int = 180
@@ -1303,13 +1335,14 @@ def cmd_s3_perf(preset: str, params: S3PerfParams) -> None:
13031335

13041336
executor = "threads" if params.threads else "fibers"
13051337

1306-
if params.flamegraph:
1338+
if params.flamegraph or params.latency:
13071339
jobs, depth, mode = configs[0]
1308-
_run_flamegraph(
1309-
preset,
1310-
f"s3-perf-{mode}-{executor}",
1311-
["taskset", "-c", client_cpus] + make_cmd(jobs, depth, mode),
1312-
)
1340+
client_cmd = ["taskset", "-c", client_cpus] + make_cmd(jobs, depth, mode)
1341+
tag = f"s3-perf-{mode}-{executor}"
1342+
if params.flamegraph:
1343+
_run_flamegraph(preset, tag, client_cmd)
1344+
else:
1345+
_run_latency(preset, tag, client_cmd)
13131346
else:
13141347
print(_perf_row(_S3P_HEADERS, _S3P_WIDTHS))
13151348
print(_perf_sep(_S3P_WIDTHS))
@@ -1552,6 +1585,12 @@ def _build_parser() -> argparse.ArgumentParser:
15521585
action="store_true",
15531586
help="profile process and generate flamegraph SVG",
15541587
)
1588+
file_perf_parser.add_argument(
1589+
"--latency",
1590+
dest="file_latency",
1591+
action="store_true",
1592+
help="profile process with USDT probes and print fiber latency breakdown",
1593+
)
15551594
file_perf_parser.add_argument(
15561595
"--print-counters",
15571596
dest="file_print_counters",
@@ -1681,6 +1720,12 @@ def _build_parser() -> argparse.ArgumentParser:
16811720
action="store_true",
16821721
help="profile client and generate flamegraph SVG",
16831722
)
1723+
parser.add_argument(
1724+
"--latency",
1725+
dest="net_latency",
1726+
action="store_true",
1727+
help="profile client with USDT probes and print fiber latency breakdown",
1728+
)
16841729
parser.add_argument(
16851730
"--timeout",
16861731
dest="net_timeout",
@@ -1797,6 +1842,12 @@ def _build_parser() -> argparse.ArgumentParser:
17971842
action="store_true",
17981843
help="profile client and generate flamegraph SVG",
17991844
)
1845+
http_perf_parser.add_argument(
1846+
"--latency",
1847+
dest="http_latency",
1848+
action="store_true",
1849+
help="profile client with USDT probes and print fiber latency breakdown",
1850+
)
18001851
http_perf_parser.add_argument(
18011852
"--print-counters",
18021853
dest="http_print_counters",
@@ -1880,6 +1931,12 @@ def _build_parser() -> argparse.ArgumentParser:
18801931
action="store_true",
18811932
help="profile first config and generate flamegraph SVG",
18821933
)
1934+
s3_perf_parser.add_argument(
1935+
"--latency",
1936+
dest="s3_latency",
1937+
action="store_true",
1938+
help="profile first config with USDT probes and print fiber latency breakdown",
1939+
)
18831940
s3_perf_parser.add_argument(
18841941
"--data-dir",
18851942
dest="s3_data_dir",

‎src/profiler/CMakeLists.txt‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,9 @@ add_custom_command(
4545
COMMENT "Generating vmlinux.h"
4646
)
4747

48+
# usdt.bpf.h transitively pulls in <linux/errno.h> -> <asm/errno.h>, which
49+
# lives in the multiarch include path on Debian/Ubuntu. Probe both x86_64 and
50+
# aarch64 multiarch dirs; the architecture mismatch path is harmless if absent.
4851
add_custom_command(
4952
OUTPUT ${BPF_OBJ}
5053
COMMAND ${CLANG}
@@ -53,6 +56,8 @@ add_custom_command(
5356
-D__TARGET_ARCH_${BPF_ARCH}
5457
-I${CMAKE_CURRENT_BINARY_DIR}
5558
-I/usr/include/bpf
59+
-I/usr/include/x86_64-linux-gnu
60+
-I/usr/include/aarch64-linux-gnu
5661
-c ${CMAKE_CURRENT_SOURCE_DIR}/profiler.bpf.c
5762
-o ${BPF_OBJ}
5863
DEPENDS ${CMAKE_CURRENT_SOURCE_DIR}/profiler.bpf.c ${VMLINUX_H}

0 commit comments

Comments
 (0)