1 // SPDX-License-Identifier: (LGPL-2.1 OR BSD-2-Clause)
2 /* Copyright (c) 2021 Google LLC.
3 *
4 * Based on funclatency from BCC by Brendan Gregg and others
5 * 2021-02-26 Barret Rhoden Created this.
6 *
7 * TODO:
8 * - support uprobes on libraries without -p PID. (parse ld.so.cache)
9 * - support regexp pattern matching and per-function histograms
10 */
11 #include <argp.h>
12 #include <errno.h>
13 #include <signal.h>
14 #include <stdio.h>
15 #include <stdlib.h>
16 #include <string.h>
17 #include <time.h>
18 #include <unistd.h>
19 #include <fcntl.h>
20
21 #include <bpf/libbpf.h>
22 #include <bpf/bpf.h>
23 #include "funclatency.h"
24 #include "funclatency.skel.h"
25 #include "trace_helpers.h"
26 #include "map_helpers.h"
27 #include "btf_helpers.h"
28 #include "uprobe_helpers.h"
29
30 #define warn(...) fprintf(stderr, __VA_ARGS__)
31
32 static struct prog_env {
33 int units;
34 pid_t pid;
35 unsigned int duration;
36 unsigned int interval;
37 unsigned int iterations;
38 bool timestamp;
39 char *funcname;
40 bool verbose;
41 bool kprobes;
42 char *cgroupspath;
43 bool cg;
44 bool is_kernel_func;
45 } env = {
46 .interval = 99999999,
47 .iterations = 99999999,
48 };
49
50 const char *argp_program_version = "funclatency 0.1";
51 const char *argp_program_bug_address =
52 "https://github.com/iovisor/bcc/tree/master/libbpf-tools";
53 static const char args_doc[] = "FUNCTION";
54 static const char program_doc[] =
55 "Time functions and print latency as a histogram\n"
56 "\n"
57 "Usage: funclatency [-h] [-m|-u] [-p PID] [-d DURATION] [ -i INTERVAL ] [-c CG]\n"
58 " [-T] FUNCTION\n"
59 " Choices for FUNCTION: FUNCTION (kprobe)\n"
60 " LIBRARY:FUNCTION (uprobe a library in -p PID)\n"
61 " :FUNCTION (uprobe the binary of -p PID)\n"
62 " PROGRAM:FUNCTION (uprobe the binary PROGRAM)\n"
63 "\v"
64 "Examples:\n"
65 " ./funclatency do_sys_open # time the do_sys_open() kernel function\n"
66 " ./funclatency -m do_nanosleep # time do_nanosleep(), in milliseconds\n"
67 " ./funclatency -c CG # Trace process under cgroupsPath CG\n"
68 " ./funclatency -u vfs_read # time vfs_read(), in microseconds\n"
69 " ./funclatency -p 181 vfs_read # time process 181 only\n"
70 " ./funclatency -p 181 c:read # time the read() C library function\n"
71 " ./funclatency -p 181 :foo # time foo() from pid 181's userspace\n"
72 " ./funclatency -i 2 -d 10 vfs_read # output every 2 seconds, for 10s\n"
73 " ./funclatency -mTi 5 vfs_read # output every 5 seconds, with timestamps\n"
74 ;
75
76 static const struct argp_option opts[] = {
77 { "milliseconds", 'm', NULL, 0, "Output in milliseconds"},
78 { "microseconds", 'u', NULL, 0, "Output in microseconds"},
79 {0, 0, 0, 0, ""},
80 { "pid", 'p', "PID", 0, "Process ID to trace"},
81 {0, 0, 0, 0, ""},
82 { "interval", 'i', "INTERVAL", 0, "Summary interval in seconds"},
83 { "cgroup", 'c', "/sys/fs/cgroup/unified", 0, "Trace process in cgroup path" },
84 { "duration", 'd', "DURATION", 0, "Duration to trace"},
85 { "timestamp", 'T', NULL, 0, "Print timestamp"},
86 { "verbose", 'v', NULL, 0, "Verbose debug output" },
87 { "kprobes", 'k', NULL, 0, "Use kprobes instead of fentry" },
88 { NULL, 'h', NULL, OPTION_HIDDEN, "Show the full help"},
89 {},
90 };
91
parse_arg(int key,char * arg,struct argp_state * state)92 static error_t parse_arg(int key, char *arg, struct argp_state *state)
93 {
94 struct prog_env *env = state->input;
95 long duration, interval, pid;
96
97 switch (key) {
98 case 'p':
99 errno = 0;
100 pid = strtol(arg, NULL, 10);
101 if (errno || pid <= 0) {
102 warn("Invalid PID: %s\n", arg);
103 argp_usage(state);
104 }
105 env->pid = pid;
106 break;
107 case 'm':
108 if (env->units != NSEC) {
109 warn("only set one of -m or -u\n");
110 argp_usage(state);
111 }
112 env->units = MSEC;
113 break;
114 case 'c':
115 env->cgroupspath = arg;
116 env->cg = true;
117 break;
118 case 'u':
119 if (env->units != NSEC) {
120 warn("only set one of -m or -u\n");
121 argp_usage(state);
122 }
123 env->units = USEC;
124 break;
125 case 'd':
126 errno = 0;
127 duration = strtol(arg, NULL, 10);
128 if (errno || duration <= 0) {
129 warn("Invalid duration: %s\n", arg);
130 argp_usage(state);
131 }
132 env->duration = duration;
133 break;
134 case 'i':
135 errno = 0;
136 interval = strtol(arg, NULL, 10);
137 if (errno || interval <= 0) {
138 warn("Invalid interval: %s\n", arg);
139 argp_usage(state);
140 }
141 env->interval = interval;
142 break;
143 case 'T':
144 env->timestamp = true;
145 break;
146 case 'k':
147 env->kprobes = true;
148 break;
149 case 'v':
150 env->verbose = true;
151 break;
152 case 'h':
153 argp_state_help(state, stderr, ARGP_HELP_STD_HELP);
154 break;
155 case ARGP_KEY_ARG:
156 if (env->funcname) {
157 warn("Too many function names: %s\n", arg);
158 argp_usage(state);
159 }
160 env->funcname = arg;
161 break;
162 case ARGP_KEY_END:
163 if (!env->funcname) {
164 warn("Need a function to trace\n");
165 argp_usage(state);
166 }
167 if (env->duration) {
168 if (env->interval > env->duration)
169 env->interval = env->duration;
170 env->iterations = env->duration / env->interval;
171 }
172 break;
173 default:
174 return ARGP_ERR_UNKNOWN;
175 }
176 return 0;
177 }
178
libbpf_print_fn(enum libbpf_print_level level,const char * format,va_list args)179 static int libbpf_print_fn(enum libbpf_print_level level, const char *format, va_list args)
180 {
181 if (level == LIBBPF_DEBUG && !env.verbose)
182 return 0;
183 return vfprintf(stderr, format, args);
184 }
185
unit_str(void)186 static const char *unit_str(void)
187 {
188 switch (env.units) {
189 case NSEC:
190 return "nsec";
191 case USEC:
192 return "usec";
193 case MSEC:
194 return "msec";
195 };
196
197 return "bad units";
198 }
199
try_fentry(struct funclatency_bpf * obj)200 static bool try_fentry(struct funclatency_bpf *obj)
201 {
202 long err;
203
204 if (env.kprobes || !env.is_kernel_func ||
205 !fentry_can_attach(env.funcname, NULL)) {
206 goto out_no_fentry;
207 }
208
209 err = bpf_program__set_attach_target(obj->progs.dummy_fentry, 0,
210 env.funcname);
211 if (err) {
212 warn("failed to set attach fentry: %s\n", strerror(-err));
213 goto out_no_fentry;
214 }
215
216 err = bpf_program__set_attach_target(obj->progs.dummy_fexit, 0,
217 env.funcname);
218 if (err) {
219 warn("failed to set attach fexit: %s\n", strerror(-err));
220 goto out_no_fentry;
221 }
222
223 bpf_program__set_autoload(obj->progs.dummy_kprobe, false);
224 bpf_program__set_autoload(obj->progs.dummy_kretprobe, false);
225
226 return true;
227
228 out_no_fentry:
229 bpf_program__set_autoload(obj->progs.dummy_fentry, false);
230 bpf_program__set_autoload(obj->progs.dummy_fexit, false);
231
232 return false;
233 }
234
attach_kprobes(struct funclatency_bpf * obj)235 static int attach_kprobes(struct funclatency_bpf *obj)
236 {
237 obj->links.dummy_kprobe =
238 bpf_program__attach_kprobe(obj->progs.dummy_kprobe, false,
239 env.funcname);
240 if (!obj->links.dummy_kprobe) {
241 warn("failed to attach kprobe: %d\n", -errno);
242 return -1;
243 }
244
245 obj->links.dummy_kretprobe =
246 bpf_program__attach_kprobe(obj->progs.dummy_kretprobe, true,
247 env.funcname);
248 if (!obj->links.dummy_kretprobe) {
249 warn("failed to attach kretprobe: %d\n", -errno);
250 return -1;
251 }
252
253 return 0;
254 }
255
attach_uprobes(struct funclatency_bpf * obj)256 static int attach_uprobes(struct funclatency_bpf *obj)
257 {
258 char *binary, *function;
259 char bin_path[PATH_MAX];
260 off_t func_off;
261 int ret = -1;
262 long err;
263
264 binary = strdup(env.funcname);
265 if (!binary) {
266 warn("strdup failed");
267 return -1;
268 }
269 function = strchr(binary, ':');
270 if (!function) {
271 warn("Binary should have contained ':' (internal bug!)\n");
272 return -1;
273 }
274 *function = '\0';
275 function++;
276
277 if (resolve_binary_path(binary, env.pid, bin_path, sizeof(bin_path)))
278 goto out_binary;
279
280 func_off = get_elf_func_offset(bin_path, function);
281 if (func_off < 0) {
282 warn("Could not find %s in %s\n", function, bin_path);
283 goto out_binary;
284 }
285
286 obj->links.dummy_kprobe =
287 bpf_program__attach_uprobe(obj->progs.dummy_kprobe, false,
288 env.pid ?: -1, bin_path, func_off);
289 if (!obj->links.dummy_kprobe) {
290 err = -errno;
291 warn("Failed to attach uprobe: %ld\n", err);
292 goto out_binary;
293 }
294
295 obj->links.dummy_kretprobe =
296 bpf_program__attach_uprobe(obj->progs.dummy_kretprobe, true,
297 env.pid ?: -1, bin_path, func_off);
298 if (!obj->links.dummy_kretprobe) {
299 err = -errno;
300 warn("Failed to attach uretprobe: %ld\n", err);
301 goto out_binary;
302 }
303
304 ret = 0;
305
306 out_binary:
307 free(binary);
308
309 return ret;
310 }
311
312 static volatile bool exiting;
313
sig_hand(int signr)314 static void sig_hand(int signr)
315 {
316 exiting = true;
317 }
318
319 static struct sigaction sigact = {.sa_handler = sig_hand};
320
main(int argc,char ** argv)321 int main(int argc, char **argv)
322 {
323 LIBBPF_OPTS(bpf_object_open_opts, open_opts);
324 static const struct argp argp = {
325 .options = opts,
326 .parser = parse_arg,
327 .args_doc = args_doc,
328 .doc = program_doc,
329 };
330 struct funclatency_bpf *obj;
331 int i, err;
332 struct tm *tm;
333 char ts[32];
334 time_t t;
335 int idx, cg_map_fd;
336 int cgfd = -1;
337 bool used_fentry = false;
338
339 err = argp_parse(&argp, argc, argv, 0, NULL, &env);
340 if (err)
341 return err;
342
343 env.is_kernel_func = !strchr(env.funcname, ':');
344
345 sigaction(SIGINT, &sigact, 0);
346
347 libbpf_set_print(libbpf_print_fn);
348
349 err = ensure_core_btf(&open_opts);
350 if (err) {
351 fprintf(stderr, "failed to fetch necessary BTF for CO-RE: %s\n", strerror(-err));
352 return 1;
353 }
354
355 obj = funclatency_bpf__open_opts(&open_opts);
356 if (!obj) {
357 warn("failed to open BPF object\n");
358 return 1;
359 }
360
361 obj->rodata->units = env.units;
362 obj->rodata->targ_tgid = env.pid;
363 obj->rodata->filter_cg = env.cg;
364
365 used_fentry = try_fentry(obj);
366
367 err = funclatency_bpf__load(obj);
368 if (err) {
369 warn("failed to load BPF object\n");
370 return 1;
371 }
372
373 /* update cgroup path fd to map */
374 if (env.cg) {
375 idx = 0;
376 cg_map_fd = bpf_map__fd(obj->maps.cgroup_map);
377 cgfd = open(env.cgroupspath, O_RDONLY);
378 if (cgfd < 0) {
379 fprintf(stderr, "Failed opening Cgroup path: %s", env.cgroupspath);
380 goto cleanup;
381 }
382 if (bpf_map_update_elem(cg_map_fd, &idx, &cgfd, BPF_ANY)) {
383 fprintf(stderr, "Failed adding target cgroup to map");
384 goto cleanup;
385 }
386 }
387
388 if (!obj->bss) {
389 warn("Memory-mapping BPF maps is supported starting from Linux 5.7, please upgrade.\n");
390 goto cleanup;
391 }
392
393 if (!used_fentry) {
394 if (env.is_kernel_func)
395 err = attach_kprobes(obj);
396 else
397 err = attach_uprobes(obj);
398 if (err)
399 goto cleanup;
400 }
401
402 err = funclatency_bpf__attach(obj);
403 if (err) {
404 fprintf(stderr, "failed to attach BPF programs: %s\n",
405 strerror(-err));
406 goto cleanup;
407 }
408
409 printf("Tracing %s. Hit Ctrl-C to exit\n", env.funcname);
410
411 for (i = 0; i < env.iterations && !exiting; i++) {
412 sleep(env.interval);
413
414 printf("\n");
415 if (env.timestamp) {
416 time(&t);
417 tm = localtime(&t);
418 strftime(ts, sizeof(ts), "%H:%M:%S", tm);
419 printf("%-8s\n", ts);
420 }
421
422 print_log2_hist(obj->bss->hist, MAX_SLOTS, unit_str());
423
424 /* Cleanup histograms for interval output */
425 memset(obj->bss->hist, 0, sizeof(obj->bss->hist));
426 }
427
428 printf("Exiting trace of %s\n", env.funcname);
429
430 cleanup:
431 funclatency_bpf__destroy(obj);
432 cleanup_core_btf(&open_opts);
433 if (cgfd > 0)
434 close(cgfd);
435
436 return err != 0;
437 }
438