xref: /linux/tools/perf/util/debug.c (revision 6d765f5f7ec669f2a16b44afd23cd877efa640de)
1 // SPDX-License-Identifier: GPL-2.0
2 /* For general debugging purposes */
3 
4 #include <inttypes.h>
5 #include <string.h>
6 #include <stdarg.h>
7 #include <stdio.h>
8 #include <stdlib.h>
9 #include <sys/wait.h>
10 #include <api/debug.h>
11 #include <linux/kernel.h>
12 #include <linux/time64.h>
13 #include <sys/time.h>
14 #ifdef HAVE_BACKTRACE_SUPPORT
15 #include <execinfo.h>
16 #endif
17 #include "addr_location.h"
18 #include "color.h"
19 #include "debug.h"
20 #include "event.h"
21 #include "machine.h"
22 #include "map.h"
23 #include "print_binary.h"
24 #include "srcline.h"
25 #include "symbol.h"
26 #include "synthetic-events.h"
27 #include "target.h"
28 #include "thread.h"
29 #include "trace-event.h"
30 #include "ui/helpline.h"
31 #include "ui/ui.h"
32 #include "util/parse-sublevel-options.h"
33 
34 #include <linux/ctype.h>
35 
36 #ifdef HAVE_LIBTRACEEVENT
37 #include <event-parse.h>
38 #else
39 #define LIBTRACEEVENT_VERSION 0
40 #endif
41 
42 int verbose;
43 int debug_kmaps;
44 int debug_peo_args;
45 bool dump_trace = false, quiet = false;
46 int debug_ordered_events;
47 static int redirect_to_stderr;
48 int debug_data_convert;
49 static FILE *_debug_file;
50 bool debug_display_time;
51 int debug_type_profile;
52 
53 FILE *debug_file(void)
54 {
55 	if (!_debug_file) {
56 		debug_set_file(stderr);
57 		pr_warning_once("debug_file not set");
58 	}
59 	return _debug_file;
60 }
61 
62 void debug_set_file(FILE *file)
63 {
64 	_debug_file = file;
65 }
66 
67 void debug_set_display_time(bool set)
68 {
69 	debug_display_time = set;
70 }
71 
72 static int fprintf_time(FILE *file)
73 {
74 	struct timeval tod;
75 	struct tm ltime;
76 	char date[64];
77 
78 	if (!debug_display_time)
79 		return 0;
80 
81 	if (gettimeofday(&tod, NULL) != 0)
82 		return 0;
83 
84 	if (localtime_r(&tod.tv_sec, &ltime) == NULL)
85 		return 0;
86 
87 	strftime(date, sizeof(date),  "%F %H:%M:%S", &ltime);
88 	return fprintf(file, "[%s.%06lu] ", date, (long)tod.tv_usec);
89 }
90 
91 int veprintf(int level, int var, const char *fmt, va_list args)
92 {
93 	int ret = 0;
94 
95 	if (var >= level) {
96 		if (use_browser >= 1 && !redirect_to_stderr) {
97 			ui_helpline__vshow(fmt, args);
98 		} else {
99 			ret = fprintf_time(debug_file());
100 			ret += vfprintf(debug_file(), fmt, args);
101 		}
102 	}
103 
104 	return ret;
105 }
106 
107 int eprintf(int level, int var, const char *fmt, ...)
108 {
109 	va_list args;
110 	int ret;
111 
112 	va_start(args, fmt);
113 	ret = veprintf(level, var, fmt, args);
114 	va_end(args);
115 
116 	return ret;
117 }
118 
119 static int veprintf_time(u64 t, const char *fmt, va_list args)
120 {
121 	int ret = 0;
122 	u64 secs, usecs, nsecs = t;
123 
124 	secs   = nsecs / NSEC_PER_SEC;
125 	nsecs -= secs  * NSEC_PER_SEC;
126 	usecs  = nsecs / NSEC_PER_USEC;
127 
128 	ret = fprintf(debug_file(), "[%13" PRIu64 ".%06" PRIu64 "] ", secs, usecs);
129 	ret += vfprintf(debug_file(), fmt, args);
130 	return ret;
131 }
132 
133 int eprintf_time(int level, int var, u64 t, const char *fmt, ...)
134 {
135 	int ret = 0;
136 	va_list args;
137 
138 	if (var >= level) {
139 		va_start(args, fmt);
140 		ret = veprintf_time(t, fmt, args);
141 		va_end(args);
142 	}
143 
144 	return ret;
145 }
146 
147 /*
148  * Overloading libtraceevent standard info print
149  * function, display with -v in perf.
150  */
151 void pr_stat(const char *fmt, ...)
152 {
153 	va_list args;
154 
155 	va_start(args, fmt);
156 	veprintf(1, verbose, fmt, args);
157 	va_end(args);
158 	eprintf(1, verbose, "\n");
159 }
160 
161 int dump_printf(const char *fmt, ...)
162 {
163 	va_list args;
164 	int ret = 0;
165 
166 	if (dump_trace) {
167 		va_start(args, fmt);
168 		ret = vprintf(fmt, args);
169 		va_end(args);
170 	}
171 
172 	return ret;
173 }
174 
175 static int trace_event_printer(enum binary_printer_ops op,
176 			       unsigned int val, void *extra, FILE *fp)
177 {
178 	const char *color = PERF_COLOR_BLUE;
179 	union perf_event *event = (union perf_event *)extra;
180 	unsigned char ch = (unsigned char)val;
181 	int printed = 0;
182 
183 	switch (op) {
184 	case BINARY_PRINT_DATA_BEGIN:
185 		printed += fprintf(fp, ".");
186 		printed += color_fprintf(fp, color, "\n. ... raw event: size %d bytes\n",
187 					 event->header.size);
188 		break;
189 	case BINARY_PRINT_LINE_BEGIN:
190 		printed += fprintf(fp, ".");
191 		break;
192 	case BINARY_PRINT_ADDR:
193 		printed += color_fprintf(fp, color, "  %04x: ", val);
194 		break;
195 	case BINARY_PRINT_NUM_DATA:
196 		printed += color_fprintf(fp, color, " %02x", val);
197 		break;
198 	case BINARY_PRINT_NUM_PAD:
199 		printed += color_fprintf(fp, color, "   ");
200 		break;
201 	case BINARY_PRINT_SEP:
202 		printed += color_fprintf(fp, color, "  ");
203 		break;
204 	case BINARY_PRINT_CHAR_DATA:
205 		printed += color_fprintf(fp, color, "%c",
206 			      isprint(ch) && isascii(ch) ? ch : '.');
207 		break;
208 	case BINARY_PRINT_CHAR_PAD:
209 		printed += color_fprintf(fp, color, " ");
210 		break;
211 	case BINARY_PRINT_LINE_END:
212 		printed += color_fprintf(fp, color, "\n");
213 		break;
214 	case BINARY_PRINT_DATA_END:
215 		printed += fprintf(fp, "\n");
216 		break;
217 	default:
218 		break;
219 	}
220 
221 	return printed;
222 }
223 
224 void trace_event(union perf_event *event)
225 {
226 	unsigned char *raw_event = (void *)event;
227 
228 	if (!dump_trace)
229 		return;
230 
231 	print_binary(raw_event, event->header.size, 16,
232 		     trace_event_printer, event);
233 }
234 
235 static struct sublevel_option debug_opts[] = {
236 	{ .name = "verbose",		.value_ptr = &verbose },
237 	{ .name = "ordered-events",	.value_ptr = &debug_ordered_events},
238 	{ .name = "stderr",		.value_ptr = &redirect_to_stderr},
239 	{ .name = "data-convert",	.value_ptr = &debug_data_convert },
240 	{ .name = "perf-event-open",	.value_ptr = &debug_peo_args },
241 	{ .name = "kmaps",		.value_ptr = &debug_kmaps },
242 	{ .name = "type-profile",	.value_ptr = &debug_type_profile },
243 	{ .name = NULL, }
244 };
245 
246 int perf_debug_option(const char *str)
247 {
248 	int ret;
249 
250 	ret = perf_parse_sublevel_options(str, debug_opts);
251 	if (ret)
252 		return ret;
253 
254 	/* Allow only verbose value in range (0, 10), otherwise set 0. */
255 	verbose = (verbose < 0) || (verbose > 10) ? 0 : verbose;
256 
257 #if LIBTRACEEVENT_VERSION >= MAKE_LIBTRACEEVENT_VERSION(1, 3, 0)
258 	if (verbose == 1)
259 		tep_set_loglevel(TEP_LOG_INFO);
260 	else if (verbose == 2)
261 		tep_set_loglevel(TEP_LOG_DEBUG);
262 	else if (verbose >= 3)
263 		tep_set_loglevel(TEP_LOG_ALL);
264 #endif
265 	return 0;
266 }
267 
268 int perf_quiet_option(void)
269 {
270 	struct sublevel_option *opt = &debug_opts[0];
271 
272 	/* disable all debug messages */
273 	while (opt->name) {
274 		*opt->value_ptr = -1;
275 		opt++;
276 	}
277 
278 	/* For debug variables that are used as bool types, set to 0. */
279 	redirect_to_stderr = 0;
280 	debug_peo_args = 0;
281 	debug_kmaps = 0;
282 	debug_type_profile = 0;
283 
284 	return 0;
285 }
286 
287 #define DEBUG_WRAPPER(__n, __l)				\
288 static int pr_ ## __n ## _wrapper(const char *fmt, ...)	\
289 {							\
290 	va_list args;					\
291 	int ret;					\
292 							\
293 	va_start(args, fmt);				\
294 	ret = veprintf(__l, verbose, fmt, args);	\
295 	va_end(args);					\
296 	return ret;					\
297 }
298 
299 DEBUG_WRAPPER(warning, 0);
300 DEBUG_WRAPPER(debug, 1);
301 
302 void perf_debug_setup(void)
303 {
304 	debug_set_file(stderr);
305 	libapi_set_print(pr_warning_wrapper, pr_warning_wrapper, pr_debug_wrapper);
306 }
307 
308 void __dump_stack(FILE *file, void **stackdump, size_t stackdump_size)
309 {
310 	/* TODO: async safety. printf, malloc, etc. aren't safe inside a signal handler. */
311 	pid_t pid = getpid();
312 	struct machine *machine = machine__new_live(/*kernel_maps=*/false, pid);
313 	struct thread *thread = NULL;
314 
315 	if (machine)
316 		thread = machine__find_thread(machine, pid, pid);
317 
318 #ifdef HAVE_BACKTRACE_SUPPORT
319 	if (!machine || !thread) {
320 		/*
321 		 * Backtrace functions are async signal safe. Fall back on them
322 		 * if machine/thread creation fails.
323 		 */
324 		backtrace_symbols_fd(stackdump, stackdump_size, fileno(file));
325 		machine__delete(machine);
326 		return;
327 	}
328 #endif
329 
330 	for (size_t i = 0; i < stackdump_size; i++) {
331 		struct addr_location al;
332 		u64 addr = (u64)(uintptr_t)stackdump[i];
333 		bool printed = false;
334 
335 		addr_location__init(&al);
336 		if (thread && thread__find_map(thread, PERF_RECORD_MISC_USER, addr, &al)) {
337 			al.sym = map__find_symbol(al.map, al.addr);
338 			if (al.sym) {
339 				fprintf(file, "    #%zd %p in %s ", i, stackdump[i], al.sym->name);
340 				printed = true;
341 			}
342 		}
343 		if (!printed)
344 			fprintf(file, "    #%zd %p ", i, stackdump[i]);
345 
346 		map__fprintf_srcline(al.map, al.addr, "", file);
347 		fprintf(file, "\n");
348 		addr_location__exit(&al);
349 	}
350 	thread__put(thread);
351 	machine__delete(machine);
352 }
353 
354 /* Obtain a backtrace and print it to stdout. */
355 #ifdef HAVE_BACKTRACE_SUPPORT
356 void dump_stack(void)
357 {
358 	void *stackdump[32];
359 	size_t size = backtrace(stackdump, ARRAY_SIZE(stackdump));
360 
361 	__dump_stack(stdout, stackdump, size);
362 }
363 #else
364 void dump_stack(void) {}
365 #endif
366 
367 void sighandler_dump_stack(int sig)
368 {
369 	psignal(sig, "perf");
370 	dump_stack();
371 	signal(sig, SIG_DFL);
372 	raise(sig);
373 }
374