Merge tag 'pull-target-arm-20220922' of https://git.linaro.org/people/pmaydell/qemu...
[qemu.git] / util / log.c
1 /*
2 * Logging support
3 *
4 * Copyright (c) 2003 Fabrice Bellard
5 *
6 * This library is free software; you can redistribute it and/or
7 * modify it under the terms of the GNU Lesser General Public
8 * License as published by the Free Software Foundation; either
9 * version 2.1 of the License, or (at your option) any later version.
10 *
11 * This library is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
14 * Lesser General Public License for more details.
15 *
16 * You should have received a copy of the GNU Lesser General Public
17 * License along with this library; if not, see <http://www.gnu.org/licenses/>.
18 */
19
20 #include "qemu/osdep.h"
21 #include "qemu/log.h"
22 #include "qemu/range.h"
23 #include "qemu/error-report.h"
24 #include "qapi/error.h"
25 #include "qemu/cutils.h"
26 #include "trace/control.h"
27 #include "qemu/thread.h"
28 #include "qemu/lockable.h"
29 #include "qemu/rcu.h"
30 #ifdef CONFIG_LINUX
31 #include <sys/syscall.h>
32 #endif
33
34
35 typedef struct RCUCloseFILE {
36 struct rcu_head rcu;
37 FILE *fd;
38 } RCUCloseFILE;
39
40 /* Mutex covering the other global_* variables. */
41 static QemuMutex global_mutex;
42 static char *global_filename;
43 static FILE *global_file;
44 static __thread FILE *thread_file;
45
46 int qemu_loglevel;
47 static bool log_append;
48 static bool log_per_thread;
49 static GArray *debug_regions;
50
51 /* Returns true if qemu_log() will really write somewhere. */
52 bool qemu_log_enabled(void)
53 {
54 return log_per_thread || qatomic_read(&global_file) != NULL;
55 }
56
57 /* Returns true if qemu_log() will write somewhere other than stderr. */
58 bool qemu_log_separate(void)
59 {
60 if (log_per_thread) {
61 return true;
62 } else {
63 FILE *logfile = qatomic_read(&global_file);
64 return logfile && logfile != stderr;
65 }
66 }
67
68 static int log_thread_id(void)
69 {
70 #ifdef CONFIG_GETTID
71 return gettid();
72 #elif defined(SYS_gettid)
73 return syscall(SYS_gettid);
74 #else
75 static int counter;
76 return qatomic_fetch_inc(&counter);
77 #endif
78 }
79
80 /* Lock/unlock output. */
81
82 FILE *qemu_log_trylock(void)
83 {
84 FILE *logfile;
85
86 logfile = thread_file;
87 if (!logfile) {
88 if (log_per_thread) {
89 g_autofree char *filename
90 = g_strdup_printf(global_filename, log_thread_id());
91 logfile = fopen(filename, "w");
92 if (!logfile) {
93 return NULL;
94 }
95 thread_file = logfile;
96 } else {
97 rcu_read_lock();
98 /*
99 * FIXME: typeof_strip_qual, as used by qatomic_rcu_read,
100 * does not work with pointers to undefined structures,
101 * such as we have with struct _IO_FILE and musl libc.
102 * Since all we want is a read of a pointer, cast to void**,
103 * which does work with typeof_strip_qual.
104 */
105 logfile = qatomic_rcu_read((void **)&global_file);
106 if (!logfile) {
107 rcu_read_unlock();
108 return NULL;
109 }
110 }
111 }
112
113 qemu_flockfile(logfile);
114 return logfile;
115 }
116
117 void qemu_log_unlock(FILE *logfile)
118 {
119 if (logfile) {
120 fflush(logfile);
121 qemu_funlockfile(logfile);
122 if (!log_per_thread) {
123 rcu_read_unlock();
124 }
125 }
126 }
127
128 void qemu_log(const char *fmt, ...)
129 {
130 FILE *f = qemu_log_trylock();
131 if (f) {
132 va_list ap;
133
134 va_start(ap, fmt);
135 vfprintf(f, fmt, ap);
136 va_end(ap);
137 qemu_log_unlock(f);
138 }
139 }
140
141 static void __attribute__((__constructor__)) startup(void)
142 {
143 qemu_mutex_init(&global_mutex);
144 }
145
146 static void rcu_close_file(RCUCloseFILE *r)
147 {
148 fclose(r->fd);
149 g_free(r);
150 }
151
152 /**
153 * valid_filename_template:
154 *
155 * Validate the filename template. Require %d if per_thread, allow it
156 * otherwise; require no other % within the template.
157 */
158
159 typedef enum {
160 vft_error,
161 vft_stderr,
162 vft_strdup,
163 vft_pid_printf,
164 } ValidFilenameTemplateResult;
165
166 static ValidFilenameTemplateResult
167 valid_filename_template(const char *filename, bool per_thread, Error **errp)
168 {
169 if (filename) {
170 char *pidstr = strstr(filename, "%");
171
172 if (pidstr) {
173 /* We only accept one %d, no other format strings */
174 if (pidstr[1] != 'd' || strchr(pidstr + 2, '%')) {
175 error_setg(errp, "Bad logfile template: %s", filename);
176 return 0;
177 }
178 return per_thread ? vft_strdup : vft_pid_printf;
179 }
180 }
181 if (per_thread) {
182 error_setg(errp, "Filename template with '%%d' required for 'tid'");
183 return vft_error;
184 }
185 return filename ? vft_strdup : vft_stderr;
186 }
187
188 /* enable or disable low levels log */
189 static bool qemu_set_log_internal(const char *filename, bool changed_name,
190 int log_flags, Error **errp)
191 {
192 bool need_to_open_file;
193 bool daemonized;
194 bool per_thread;
195 FILE *logfile;
196
197 QEMU_LOCK_GUARD(&global_mutex);
198 logfile = global_file;
199
200 per_thread = log_flags & LOG_PER_THREAD;
201
202 if (changed_name) {
203 char *newname = NULL;
204
205 /*
206 * Once threads start opening their own log files, we have no
207 * easy mechanism to tell them all to close and re-open.
208 * There seems little cause to do so either -- this option
209 * will most often be used at user-only startup.
210 */
211 if (log_per_thread) {
212 error_setg(errp, "Cannot change log filename after setting 'tid'");
213 return false;
214 }
215
216 switch (valid_filename_template(filename, per_thread, errp)) {
217 case vft_error:
218 return false;
219 case vft_stderr:
220 break;
221 case vft_strdup:
222 newname = g_strdup(filename);
223 break;
224 case vft_pid_printf:
225 newname = g_strdup_printf(filename, getpid());
226 break;
227 }
228
229 g_free(global_filename);
230 global_filename = newname;
231 filename = newname;
232 } else {
233 filename = global_filename;
234 if (per_thread &&
235 valid_filename_template(filename, true, errp) == vft_error) {
236 return false;
237 }
238 }
239
240 /* Once the per-thread flag is set, it cannot be unset. */
241 if (per_thread) {
242 log_per_thread = true;
243 }
244 /* The flag itself is not relevant for need_to_open_file. */
245 log_flags &= ~LOG_PER_THREAD;
246 #ifdef CONFIG_TRACE_LOG
247 log_flags |= LOG_TRACE;
248 #endif
249 qemu_loglevel = log_flags;
250
251 /*
252 * In all cases we only log if qemu_loglevel is set.
253 * Also:
254 * If per-thread, open the file for each thread in qemu_log_lock.
255 * If not daemonized we will always log either to stderr
256 * or to a file (if there is a filename).
257 * If we are daemonized, we will only log if there is a filename.
258 */
259 daemonized = is_daemonized();
260 need_to_open_file = log_flags && !per_thread && (!daemonized || filename);
261
262 if (logfile && (!need_to_open_file || changed_name)) {
263 qatomic_rcu_set(&global_file, NULL);
264 if (logfile != stderr) {
265 RCUCloseFILE *r = g_new0(RCUCloseFILE, 1);
266 r->fd = logfile;
267 call_rcu(r, rcu_close_file, rcu);
268 }
269 logfile = NULL;
270 }
271
272 if (!logfile && need_to_open_file) {
273 if (filename) {
274 logfile = fopen(filename, log_append ? "a" : "w");
275 if (!logfile) {
276 error_setg_errno(errp, errno, "Error opening logfile %s",
277 filename);
278 return false;
279 }
280 /* In case we are a daemon redirect stderr to logfile */
281 if (daemonized) {
282 dup2(fileno(logfile), STDERR_FILENO);
283 fclose(logfile);
284 /* This will skip closing logfile in rcu_close_file. */
285 logfile = stderr;
286 }
287 } else {
288 /* Default to stderr if no log file specified */
289 assert(!daemonized);
290 logfile = stderr;
291 }
292
293 log_append = 1;
294
295 qatomic_rcu_set(&global_file, logfile);
296 }
297 return true;
298 }
299
300 bool qemu_set_log(int log_flags, Error **errp)
301 {
302 return qemu_set_log_internal(NULL, false, log_flags, errp);
303 }
304
305 bool qemu_set_log_filename(const char *filename, Error **errp)
306 {
307 return qemu_set_log_internal(filename, true, qemu_loglevel, errp);
308 }
309
310 bool qemu_set_log_filename_flags(const char *name, int flags, Error **errp)
311 {
312 return qemu_set_log_internal(name, true, flags, errp);
313 }
314
315 /* Returns true if addr is in our debug filter or no filter defined
316 */
317 bool qemu_log_in_addr_range(uint64_t addr)
318 {
319 if (debug_regions) {
320 int i = 0;
321 for (i = 0; i < debug_regions->len; i++) {
322 Range *range = &g_array_index(debug_regions, Range, i);
323 if (range_contains(range, addr)) {
324 return true;
325 }
326 }
327 return false;
328 } else {
329 return true;
330 }
331 }
332
333
334 void qemu_set_dfilter_ranges(const char *filter_spec, Error **errp)
335 {
336 gchar **ranges = g_strsplit(filter_spec, ",", 0);
337 int i;
338
339 if (debug_regions) {
340 g_array_unref(debug_regions);
341 debug_regions = NULL;
342 }
343
344 debug_regions = g_array_sized_new(FALSE, FALSE,
345 sizeof(Range), g_strv_length(ranges));
346 for (i = 0; ranges[i]; i++) {
347 const char *r = ranges[i];
348 const char *range_op, *r2, *e;
349 uint64_t r1val, r2val, lob, upb;
350 struct Range range;
351
352 range_op = strstr(r, "-");
353 r2 = range_op ? range_op + 1 : NULL;
354 if (!range_op) {
355 range_op = strstr(r, "+");
356 r2 = range_op ? range_op + 1 : NULL;
357 }
358 if (!range_op) {
359 range_op = strstr(r, "..");
360 r2 = range_op ? range_op + 2 : NULL;
361 }
362 if (!range_op) {
363 error_setg(errp, "Bad range specifier");
364 goto out;
365 }
366
367 if (qemu_strtou64(r, &e, 0, &r1val)
368 || e != range_op) {
369 error_setg(errp, "Invalid number to the left of %.*s",
370 (int)(r2 - range_op), range_op);
371 goto out;
372 }
373 if (qemu_strtou64(r2, NULL, 0, &r2val)) {
374 error_setg(errp, "Invalid number to the right of %.*s",
375 (int)(r2 - range_op), range_op);
376 goto out;
377 }
378
379 switch (*range_op) {
380 case '+':
381 lob = r1val;
382 upb = r1val + r2val - 1;
383 break;
384 case '-':
385 upb = r1val;
386 lob = r1val - (r2val - 1);
387 break;
388 case '.':
389 lob = r1val;
390 upb = r2val;
391 break;
392 default:
393 g_assert_not_reached();
394 }
395 if (lob > upb) {
396 error_setg(errp, "Invalid range");
397 goto out;
398 }
399 range_set_bounds(&range, lob, upb);
400 g_array_append_val(debug_regions, range);
401 }
402 out:
403 g_strfreev(ranges);
404 }
405
406 const QEMULogItem qemu_log_items[] = {
407 { CPU_LOG_TB_OUT_ASM, "out_asm",
408 "show generated host assembly code for each compiled TB" },
409 { CPU_LOG_TB_IN_ASM, "in_asm",
410 "show target assembly code for each compiled TB" },
411 { CPU_LOG_TB_OP, "op",
412 "show micro ops for each compiled TB" },
413 { CPU_LOG_TB_OP_OPT, "op_opt",
414 "show micro ops after optimization" },
415 { CPU_LOG_TB_OP_IND, "op_ind",
416 "show micro ops before indirect lowering" },
417 { CPU_LOG_INT, "int",
418 "show interrupts/exceptions in short format" },
419 { CPU_LOG_EXEC, "exec",
420 "show trace before each executed TB (lots of logs)" },
421 { CPU_LOG_TB_CPU, "cpu",
422 "show CPU registers before entering a TB (lots of logs)" },
423 { CPU_LOG_TB_FPU, "fpu",
424 "include FPU registers in the 'cpu' logging" },
425 { CPU_LOG_MMU, "mmu",
426 "log MMU-related activities" },
427 { CPU_LOG_PCALL, "pcall",
428 "x86 only: show protected mode far calls/returns/exceptions" },
429 { CPU_LOG_RESET, "cpu_reset",
430 "show CPU state before CPU resets" },
431 { LOG_UNIMP, "unimp",
432 "log unimplemented functionality" },
433 { LOG_GUEST_ERROR, "guest_errors",
434 "log when the guest OS does something invalid (eg accessing a\n"
435 "non-existent register)" },
436 { CPU_LOG_PAGE, "page",
437 "dump pages at beginning of user mode emulation" },
438 { CPU_LOG_TB_NOCHAIN, "nochain",
439 "do not chain compiled TBs so that \"exec\" and \"cpu\" show\n"
440 "complete traces" },
441 #ifdef CONFIG_PLUGIN
442 { CPU_LOG_PLUGIN, "plugin", "output from TCG plugins\n"},
443 #endif
444 { LOG_STRACE, "strace",
445 "log every user-mode syscall, its input, and its result" },
446 { LOG_PER_THREAD, "tid",
447 "open a separate log file per thread; filename must contain '%d'" },
448 { 0, NULL, NULL },
449 };
450
451 /* takes a comma separated list of log masks. Return 0 if error. */
452 int qemu_str_to_log_mask(const char *str)
453 {
454 const QEMULogItem *item;
455 int mask = 0;
456 char **parts = g_strsplit(str, ",", 0);
457 char **tmp;
458
459 for (tmp = parts; tmp && *tmp; tmp++) {
460 if (g_str_equal(*tmp, "all")) {
461 for (item = qemu_log_items; item->mask != 0; item++) {
462 mask |= item->mask;
463 }
464 #ifdef CONFIG_TRACE_LOG
465 } else if (g_str_has_prefix(*tmp, "trace:") && (*tmp)[6] != '\0') {
466 trace_enable_events((*tmp) + 6);
467 mask |= LOG_TRACE;
468 #endif
469 } else {
470 for (item = qemu_log_items; item->mask != 0; item++) {
471 if (g_str_equal(*tmp, item->name)) {
472 goto found;
473 }
474 }
475 goto error;
476 found:
477 mask |= item->mask;
478 }
479 }
480
481 g_strfreev(parts);
482 return mask;
483
484 error:
485 g_strfreev(parts);
486 return 0;
487 }
488
489 void qemu_print_log_usage(FILE *f)
490 {
491 const QEMULogItem *item;
492 fprintf(f, "Log items (comma separated):\n");
493 for (item = qemu_log_items; item->mask != 0; item++) {
494 fprintf(f, "%-15s %s\n", item->name, item->help);
495 }
496 #ifdef CONFIG_TRACE_LOG
497 fprintf(f, "trace:PATTERN enable trace events\n");
498 fprintf(f, "\nUse \"-d trace:help\" to get a list of trace events.\n\n");
499 #endif
500 }