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
20 #include <bpf/libbpf.h>
21 #include <bpf/bpf.h>
22 #include "funclatency.h"
23 #include "funclatency.skel.h"
24 #include "trace_helpers.h"
25 #include "map_helpers.h"
26 #include "uprobe_helpers.h"
27
28 #define warn(...) fprintf(stderr, __VA_ARGS__)
29
30 static struct prog_env {
31 int units;
32 pid_t pid;
33 unsigned int duration;
34 unsigned int interval;
35 unsigned int iterations;
36 bool timestamp;
37 char *funcname;
38 bool verbose;
39 } env = {
40 .interval = 99999999,
41 .iterations = 99999999,
42 };
43
44 const char *argp_program_version = "funclatency 0.1";
45 const char *argp_program_bug_address =
46 "https://github.com/iovisor/bcc/tree/master/libbpf-tools";
47 static const char args_doc[] = "FUNCTION";
48 static const char program_doc[] =
49 "Time functions and print latency as a histogram\n"
50 "\n"
51 "Usage: funclatency [-h] [-m|-u] [-p PID] [-d DURATION] [ -i INTERVAL ]\n"
52 " [-T] FUNCTION\n"
53 " Choices for FUNCTION: FUNCTION (kprobe)\n"
54 " LIBRARY:FUNCTION (uprobe a library in -p PID)\n"
55 " :FUNCTION (uprobe the binary of -p PID)\n"
56 " PROGRAM:FUNCTION (uprobe the binary PROGRAM)\n"
57 "\v"
58 "Examples:\n"
59 " ./funclatency do_sys_open # time the do_sys_open() kernel function\n"
60 " ./funclatency -m do_nanosleep # time do_nanosleep(), in milliseconds\n"
61 " ./funclatency -u vfs_read # time vfs_read(), in microseconds\n"
62 " ./funclatency -p 181 vfs_read # time process 181 only\n"
63 " ./funclatency -p 181 c:read # time the read() C library function\n"
64 " ./funclatency -p 181 :foo # time foo() from pid 181's userspace\n"
65 " ./funclatency -i 2 -d 10 vfs_read # output every 2 seconds, for 10s\n"
66 " ./funclatency -mTi 5 vfs_read # output every 5 seconds, with timestamps\n"
67 ;
68
69 static const struct argp_option opts[] = {
70 { "milliseconds", 'm', NULL, 0, "Output in milliseconds"},
71 { "microseconds", 'u', NULL, 0, "Output in microseconds"},
72 {0, 0, 0, 0, ""},
73 { "pid", 'p', "PID", 0, "Process ID to trace"},
74 {0, 0, 0, 0, ""},
75 { "interval", 'i', "INTERVAL", 0, "Summary interval in seconds"},
76 { "duration", 'd', "DURATION", 0, "Duration to trace"},
77 { "timestamp", 'T', NULL, 0, "Print timestamp"},
78 { "verbose", 'v', NULL, 0, "Verbose debug output" },
79 { NULL, 'h', NULL, OPTION_HIDDEN, "Show the full help"},
80 {},
81 };
82
parse_arg(int key,char * arg,struct argp_state * state)83 static error_t parse_arg(int key, char *arg, struct argp_state *state)
84 {
85 struct prog_env *env = state->input;
86 long duration, interval, pid;
87
88 switch (key) {
89 case 'p':
90 errno = 0;
91 pid = strtol(arg, NULL, 10);
92 if (errno || pid <= 0) {
93 warn("Invalid PID: %s\n", arg);
94 argp_usage(state);
95 }
96 env->pid = pid;
97 break;
98 case 'm':
99 if (env->units != NSEC) {
100 warn("only set one of -m or -u\n");
101 argp_usage(state);
102 }
103 env->units = MSEC;
104 break;
105 case 'u':
106 if (env->units != NSEC) {
107 warn("only set one of -m or -u\n");
108 argp_usage(state);
109 }
110 env->units = USEC;
111 break;
112 case 'd':
113 errno = 0;
114 duration = strtol(arg, NULL, 10);
115 if (errno || duration <= 0) {
116 warn("Invalid duration: %s\n", arg);
117 argp_usage(state);
118 }
119 env->duration = duration;
120 break;
121 case 'i':
122 errno = 0;
123 interval = strtol(arg, NULL, 10);
124 if (errno || interval <= 0) {
125 warn("Invalid interval: %s\n", arg);
126 argp_usage(state);
127 }
128 env->interval = interval;
129 break;
130 case 'T':
131 env->timestamp = true;
132 break;
133 case 'v':
134 env->verbose = true;
135 break;
136 case 'h':
137 argp_state_help(state, stderr, ARGP_HELP_STD_HELP);
138 break;
139 case ARGP_KEY_ARG:
140 if (env->funcname) {
141 warn("Too many function names: %s\n", arg);
142 argp_usage(state);
143 }
144 env->funcname = arg;
145 break;
146 case ARGP_KEY_END:
147 if (!env->funcname) {
148 warn("Need a function to trace\n");
149 argp_usage(state);
150 }
151 if (env->duration) {
152 if (env->interval > env->duration)
153 env->interval = env->duration;
154 env->iterations = env->duration / env->interval;
155 }
156 break;
157 default:
158 return ARGP_ERR_UNKNOWN;
159 }
160 return 0;
161 }
162
libbpf_print_fn(enum libbpf_print_level level,const char * format,va_list args)163 static int libbpf_print_fn(enum libbpf_print_level level, const char *format, va_list args)
164 {
165 if (level == LIBBPF_DEBUG && !env.verbose)
166 return 0;
167 return vfprintf(stderr, format, args);
168 }
169
unit_str(void)170 static const char *unit_str(void)
171 {
172 switch (env.units) {
173 case NSEC:
174 return "nsec";
175 case USEC:
176 return "usec";
177 case MSEC:
178 return "msec";
179 };
180
181 return "bad units";
182 }
183
attach_kprobes(struct funclatency_bpf * obj)184 static int attach_kprobes(struct funclatency_bpf *obj)
185 {
186 long err;
187
188 obj->links.dummy_kprobe = bpf_program__attach_kprobe(obj->progs.dummy_kprobe, false,
189 env.funcname);
190 if (!obj->links.dummy_kprobe) {
191 err = -errno;
192 warn("failed to attach kprobe: %ld\n", err);
193 return -1;
194 }
195
196 obj->links.dummy_kretprobe = bpf_program__attach_kprobe(obj->progs.dummy_kretprobe, true,
197 env.funcname);
198 if (!obj->links.dummy_kretprobe) {
199 err = -errno;
200 warn("failed to attach kretprobe: %ld\n", err);
201 return -1;
202 }
203
204 return 0;
205 }
206
attach_uprobes(struct funclatency_bpf * obj)207 static int attach_uprobes(struct funclatency_bpf *obj)
208 {
209 char *binary, *function;
210 char bin_path[PATH_MAX];
211 off_t func_off;
212 int ret = -1;
213 long err;
214
215 binary = strdup(env.funcname);
216 if (!binary) {
217 warn("strdup failed");
218 return -1;
219 }
220 function = strchr(binary, ':');
221 if (!function) {
222 warn("Binary should have contained ':' (internal bug!)\n");
223 return -1;
224 }
225 *function = '\0';
226 function++;
227
228 if (resolve_binary_path(binary, env.pid, bin_path, sizeof(bin_path)))
229 goto out_binary;
230
231 func_off = get_elf_func_offset(bin_path, function);
232 if (func_off < 0) {
233 warn("Could not find %s in %s\n", function, bin_path);
234 goto out_binary;
235 }
236
237 obj->links.dummy_kprobe =
238 bpf_program__attach_uprobe(obj->progs.dummy_kprobe, false,
239 env.pid ?: -1, bin_path, func_off);
240 if (!obj->links.dummy_kprobe) {
241 err = -errno;
242 warn("Failed to attach uprobe: %ld\n", err);
243 goto out_binary;
244 }
245
246 obj->links.dummy_kretprobe =
247 bpf_program__attach_uprobe(obj->progs.dummy_kretprobe, true,
248 env.pid ?: -1, bin_path, func_off);
249 if (!obj->links.dummy_kretprobe) {
250 err = -errno;
251 warn("Failed to attach uretprobe: %ld\n", err);
252 goto out_binary;
253 }
254
255 ret = 0;
256
257 out_binary:
258 free(binary);
259
260 return ret;
261 }
262
attach_probes(struct funclatency_bpf * obj)263 static int attach_probes(struct funclatency_bpf *obj)
264 {
265 if (strchr(env.funcname, ':'))
266 return attach_uprobes(obj);
267 return attach_kprobes(obj);
268 }
269
270 static volatile bool exiting;
271
sig_hand(int signr)272 static void sig_hand(int signr)
273 {
274 exiting = true;
275 }
276
277 static struct sigaction sigact = {.sa_handler = sig_hand};
278
main(int argc,char ** argv)279 int main(int argc, char **argv)
280 {
281 static const struct argp argp = {
282 .options = opts,
283 .parser = parse_arg,
284 .args_doc = args_doc,
285 .doc = program_doc,
286 };
287 struct funclatency_bpf *obj;
288 int i, err;
289 struct tm *tm;
290 char ts[32];
291 time_t t;
292
293 err = argp_parse(&argp, argc, argv, 0, NULL, &env);
294 if (err)
295 return err;
296
297 sigaction(SIGINT, &sigact, 0);
298
299 libbpf_set_strict_mode(LIBBPF_STRICT_ALL);
300 libbpf_set_print(libbpf_print_fn);
301
302 obj = funclatency_bpf__open();
303 if (!obj) {
304 warn("failed to open BPF object\n");
305 return 1;
306 }
307
308 obj->rodata->units = env.units;
309 obj->rodata->targ_tgid = env.pid;
310
311 err = funclatency_bpf__load(obj);
312 if (err) {
313 warn("failed to load BPF object\n");
314 return 1;
315 }
316
317 if (!obj->bss) {
318 warn("Memory-mapping BPF maps is supported starting from Linux 5.7, please upgrade.\n");
319 goto cleanup;
320 }
321
322 err = attach_probes(obj);
323 if (err)
324 goto cleanup;
325
326 printf("Tracing %s. Hit Ctrl-C to exit\n", env.funcname);
327
328 for (i = 0; i < env.iterations && !exiting; i++) {
329 sleep(env.interval);
330
331 printf("\n");
332 if (env.timestamp) {
333 time(&t);
334 tm = localtime(&t);
335 strftime(ts, sizeof(ts), "%H:%M:%S", tm);
336 printf("%-8s\n", ts);
337 }
338
339 print_log2_hist(obj->bss->hist, MAX_SLOTS, unit_str());
340 }
341
342 printf("Exiting trace of %s\n", env.funcname);
343
344 cleanup:
345 funclatency_bpf__destroy(obj);
346
347 return err != 0;
348 }
349