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