|  | /* | 
|  | * Logging support | 
|  | * | 
|  | *  Copyright (c) 2003 Fabrice Bellard | 
|  | * | 
|  | * This library is free software; you can redistribute it and/or | 
|  | * modify it under the terms of the GNU Lesser General Public | 
|  | * License as published by the Free Software Foundation; either | 
|  | * version 2.1 of the License, or (at your option) any later version. | 
|  | * | 
|  | * This library is distributed in the hope that it will be useful, | 
|  | * but WITHOUT ANY WARRANTY; without even the implied warranty of | 
|  | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU | 
|  | * Lesser General Public License for more details. | 
|  | * | 
|  | * You should have received a copy of the GNU Lesser General Public | 
|  | * License along with this library; if not, see <http://www.gnu.org/licenses/>. | 
|  | */ | 
|  |  | 
|  | #include "qemu/osdep.h" | 
|  | #include "qemu/log.h" | 
|  | #include "qemu/range.h" | 
|  | #include "qemu/error-report.h" | 
|  | #include "qapi/error.h" | 
|  | #include "qemu/cutils.h" | 
|  | #include "trace/control.h" | 
|  | #include "qemu/thread.h" | 
|  | #include "qemu/lockable.h" | 
|  | #include "qemu/rcu.h" | 
|  | #ifdef CONFIG_LINUX | 
|  | #include <sys/syscall.h> | 
|  | #endif | 
|  |  | 
|  |  | 
|  | typedef struct RCUCloseFILE { | 
|  | struct rcu_head rcu; | 
|  | FILE *fd; | 
|  | } RCUCloseFILE; | 
|  |  | 
|  | /* Mutex covering the other global_* variables. */ | 
|  | static QemuMutex global_mutex; | 
|  | static char *global_filename; | 
|  | static FILE *global_file; | 
|  | static __thread FILE *thread_file; | 
|  | static __thread Notifier qemu_log_thread_cleanup_notifier; | 
|  |  | 
|  | int qemu_loglevel; | 
|  | static bool log_per_thread; | 
|  | static GArray *debug_regions; | 
|  |  | 
|  | /* Returns true if qemu_log() will really write somewhere. */ | 
|  | bool qemu_log_enabled(void) | 
|  | { | 
|  | return log_per_thread || qatomic_read(&global_file) != NULL; | 
|  | } | 
|  |  | 
|  | /* Returns true if qemu_log() will write somewhere other than stderr. */ | 
|  | bool qemu_log_separate(void) | 
|  | { | 
|  | if (log_per_thread) { | 
|  | return true; | 
|  | } else { | 
|  | FILE *logfile = qatomic_read(&global_file); | 
|  | return logfile && logfile != stderr; | 
|  | } | 
|  | } | 
|  |  | 
|  | static int log_thread_id(void) | 
|  | { | 
|  | #ifdef CONFIG_GETTID | 
|  | return gettid(); | 
|  | #elif defined(SYS_gettid) | 
|  | return syscall(SYS_gettid); | 
|  | #else | 
|  | static int counter; | 
|  | return qatomic_fetch_inc(&counter); | 
|  | #endif | 
|  | } | 
|  |  | 
|  | static void qemu_log_thread_cleanup(Notifier *n, void *unused) | 
|  | { | 
|  | if (thread_file != stderr) { | 
|  | fclose(thread_file); | 
|  | thread_file = NULL; | 
|  | } | 
|  | } | 
|  |  | 
|  | /* Lock/unlock output. */ | 
|  |  | 
|  | static FILE *qemu_log_trylock_with_err(Error **errp) | 
|  | { | 
|  | FILE *logfile; | 
|  |  | 
|  | logfile = thread_file; | 
|  | if (!logfile) { | 
|  | if (log_per_thread) { | 
|  | g_autofree char *filename | 
|  | = g_strdup_printf(global_filename, log_thread_id()); | 
|  | logfile = fopen(filename, "w"); | 
|  | if (!logfile) { | 
|  | error_setg_errno(errp, errno, | 
|  | "Error opening logfile %s for thread %d", | 
|  | filename, log_thread_id()); | 
|  | return NULL; | 
|  | } | 
|  | thread_file = logfile; | 
|  | qemu_log_thread_cleanup_notifier.notify = qemu_log_thread_cleanup; | 
|  | qemu_thread_atexit_add(&qemu_log_thread_cleanup_notifier); | 
|  | } else { | 
|  | rcu_read_lock(); | 
|  | /* | 
|  | * FIXME: typeof_strip_qual, as used by qatomic_rcu_read, | 
|  | * does not work with pointers to undefined structures, | 
|  | * such as we have with struct _IO_FILE and musl libc. | 
|  | * Since all we want is a read of a pointer, cast to void**, | 
|  | * which does work with typeof_strip_qual. | 
|  | */ | 
|  | logfile = qatomic_rcu_read((void **)&global_file); | 
|  | if (!logfile) { | 
|  | rcu_read_unlock(); | 
|  | return NULL; | 
|  | } | 
|  | } | 
|  | } | 
|  |  | 
|  | qemu_flockfile(logfile); | 
|  | return logfile; | 
|  | } | 
|  |  | 
|  | FILE *qemu_log_trylock(void) | 
|  | { | 
|  | return qemu_log_trylock_with_err(NULL); | 
|  | } | 
|  |  | 
|  | void qemu_log_unlock(FILE *logfile) | 
|  | { | 
|  | if (logfile) { | 
|  | fflush(logfile); | 
|  | qemu_funlockfile(logfile); | 
|  | if (!log_per_thread) { | 
|  | rcu_read_unlock(); | 
|  | } | 
|  | } | 
|  | } | 
|  |  | 
|  | void qemu_log(const char *fmt, ...) | 
|  | { | 
|  | FILE *f = qemu_log_trylock(); | 
|  | if (f) { | 
|  | va_list ap; | 
|  |  | 
|  | va_start(ap, fmt); | 
|  | vfprintf(f, fmt, ap); | 
|  | va_end(ap); | 
|  | qemu_log_unlock(f); | 
|  | } | 
|  | } | 
|  |  | 
|  | static void __attribute__((__constructor__)) startup(void) | 
|  | { | 
|  | qemu_mutex_init(&global_mutex); | 
|  | } | 
|  |  | 
|  | static void rcu_close_file(RCUCloseFILE *r) | 
|  | { | 
|  | fclose(r->fd); | 
|  | g_free(r); | 
|  | } | 
|  |  | 
|  | /** | 
|  | * valid_filename_template: | 
|  | * | 
|  | * Validate the filename template.  Require %d if per_thread, allow it | 
|  | * otherwise; require no other % within the template. | 
|  | */ | 
|  |  | 
|  | typedef enum { | 
|  | vft_error, | 
|  | vft_stderr, | 
|  | vft_strdup, | 
|  | vft_pid_printf, | 
|  | } ValidFilenameTemplateResult; | 
|  |  | 
|  | static ValidFilenameTemplateResult | 
|  | valid_filename_template(const char *filename, bool per_thread, Error **errp) | 
|  | { | 
|  | if (filename) { | 
|  | char *pidstr = strstr(filename, "%"); | 
|  |  | 
|  | if (pidstr) { | 
|  | /* We only accept one %d, no other format strings */ | 
|  | if (pidstr[1] != 'd' || strchr(pidstr + 2, '%')) { | 
|  | error_setg(errp, "Bad logfile template: %s", filename); | 
|  | return 0; | 
|  | } | 
|  | return per_thread ? vft_strdup : vft_pid_printf; | 
|  | } | 
|  | } | 
|  | if (per_thread) { | 
|  | error_setg(errp, "Filename template with '%%d' required for 'tid'"); | 
|  | return vft_error; | 
|  | } | 
|  | return filename ? vft_strdup : vft_stderr; | 
|  | } | 
|  |  | 
|  | /* enable or disable low levels log */ | 
|  | static bool qemu_set_log_internal(const char *filename, bool changed_name, | 
|  | int log_flags, Error **errp) | 
|  | { | 
|  | bool need_to_open_file; | 
|  | bool daemonized; | 
|  | bool per_thread; | 
|  | FILE *logfile; | 
|  |  | 
|  | QEMU_LOCK_GUARD(&global_mutex); | 
|  | logfile = global_file; | 
|  |  | 
|  | /* The per-thread flag is immutable. */ | 
|  | if (log_per_thread) { | 
|  | log_flags |= LOG_PER_THREAD; | 
|  | } else { | 
|  | if (global_filename) { | 
|  | log_flags &= ~LOG_PER_THREAD; | 
|  | } | 
|  | } | 
|  |  | 
|  | per_thread = log_flags & LOG_PER_THREAD; | 
|  |  | 
|  | if (changed_name) { | 
|  | char *newname = NULL; | 
|  |  | 
|  | /* | 
|  | * Once threads start opening their own log files, we have no | 
|  | * easy mechanism to tell them all to close and re-open. | 
|  | * There seems little cause to do so either -- this option | 
|  | * will most often be used at user-only startup. | 
|  | */ | 
|  | if (log_per_thread) { | 
|  | error_setg(errp, "Cannot change log filename after setting 'tid'"); | 
|  | return false; | 
|  | } | 
|  |  | 
|  | switch (valid_filename_template(filename, per_thread, errp)) { | 
|  | case vft_error: | 
|  | return false; | 
|  | case vft_stderr: | 
|  | break; | 
|  | case vft_strdup: | 
|  | newname = g_strdup(filename); | 
|  | break; | 
|  | case vft_pid_printf: | 
|  | newname = g_strdup_printf(filename, getpid()); | 
|  | break; | 
|  | } | 
|  |  | 
|  | g_free(global_filename); | 
|  | global_filename = newname; | 
|  | filename = newname; | 
|  | } else { | 
|  | filename = global_filename; | 
|  | if (per_thread && | 
|  | valid_filename_template(filename, true, errp) == vft_error) { | 
|  | return false; | 
|  | } | 
|  | } | 
|  |  | 
|  | /* Once the per-thread flag is set, it cannot be unset. */ | 
|  | if (per_thread) { | 
|  | log_per_thread = true; | 
|  | } | 
|  | /* The flag itself is not relevant for need_to_open_file. */ | 
|  | log_flags &= ~LOG_PER_THREAD; | 
|  | #ifdef CONFIG_TRACE_LOG | 
|  | log_flags |= LOG_TRACE; | 
|  | #endif | 
|  | qemu_loglevel = log_flags; | 
|  |  | 
|  | daemonized = is_daemonized(); | 
|  | need_to_open_file = false; | 
|  | if (!daemonized) { | 
|  | /* | 
|  | * If not daemonized we only log if qemu_loglevel is set, either to | 
|  | * stderr or to a file (if there is a filename). | 
|  | * If per-thread, open the file for each thread in qemu_log_trylock(). | 
|  | */ | 
|  | need_to_open_file = qemu_loglevel && !log_per_thread; | 
|  | } else { | 
|  | /* | 
|  | * If we are daemonized, we will only log if there is a filename. | 
|  | */ | 
|  | need_to_open_file = filename != NULL; | 
|  | } | 
|  |  | 
|  | if (logfile) { | 
|  | fflush(logfile); | 
|  | if (changed_name && logfile != stderr) { | 
|  | RCUCloseFILE *r = g_new0(RCUCloseFILE, 1); | 
|  | r->fd = logfile; | 
|  | qatomic_rcu_set(&global_file, NULL); | 
|  | call_rcu(r, rcu_close_file, rcu); | 
|  | } | 
|  | if (changed_name) { | 
|  | logfile = NULL; | 
|  | } | 
|  | } | 
|  |  | 
|  | if (log_per_thread && daemonized) { | 
|  | logfile = thread_file; | 
|  | } | 
|  |  | 
|  | if (!logfile && need_to_open_file) { | 
|  | if (filename) { | 
|  | if (log_per_thread) { | 
|  | logfile = qemu_log_trylock_with_err(errp); | 
|  | if (!logfile) { | 
|  | return false; | 
|  | } | 
|  | qemu_log_unlock(logfile); | 
|  | } else { | 
|  | logfile = fopen(filename, "w"); | 
|  | if (!logfile) { | 
|  | error_setg_errno(errp, errno, "Error opening logfile %s", | 
|  | filename); | 
|  | return false; | 
|  | } | 
|  | } | 
|  | /* In case we are a daemon redirect stderr to logfile */ | 
|  | if (daemonized) { | 
|  | dup2(fileno(logfile), STDERR_FILENO); | 
|  | fclose(logfile); | 
|  | /* | 
|  | * This will skip closing logfile in rcu_close_file() | 
|  | * or qemu_log_thread_cleanup(). | 
|  | */ | 
|  | logfile = stderr; | 
|  | } | 
|  | } else { | 
|  | /* Default to stderr if no log file specified */ | 
|  | assert(!daemonized); | 
|  | logfile = stderr; | 
|  | } | 
|  |  | 
|  | if (log_per_thread && daemonized) { | 
|  | thread_file = logfile; | 
|  | } else { | 
|  | qatomic_rcu_set(&global_file, logfile); | 
|  | } | 
|  | } | 
|  | return true; | 
|  | } | 
|  |  | 
|  | bool qemu_set_log(int log_flags, Error **errp) | 
|  | { | 
|  | return qemu_set_log_internal(NULL, false, log_flags, errp); | 
|  | } | 
|  |  | 
|  | bool qemu_set_log_filename(const char *filename, Error **errp) | 
|  | { | 
|  | return qemu_set_log_internal(filename, true, qemu_loglevel, errp); | 
|  | } | 
|  |  | 
|  | bool qemu_set_log_filename_flags(const char *name, int flags, Error **errp) | 
|  | { | 
|  | return qemu_set_log_internal(name, true, flags, errp); | 
|  | } | 
|  |  | 
|  | /* Returns true if addr is in our debug filter or no filter defined | 
|  | */ | 
|  | bool qemu_log_in_addr_range(uint64_t addr) | 
|  | { | 
|  | if (debug_regions) { | 
|  | int i = 0; | 
|  | for (i = 0; i < debug_regions->len; i++) { | 
|  | Range *range = &g_array_index(debug_regions, Range, i); | 
|  | if (range_contains(range, addr)) { | 
|  | return true; | 
|  | } | 
|  | } | 
|  | return false; | 
|  | } else { | 
|  | return true; | 
|  | } | 
|  | } | 
|  |  | 
|  |  | 
|  | void qemu_set_dfilter_ranges(const char *filter_spec, Error **errp) | 
|  | { | 
|  | gchar **ranges = g_strsplit(filter_spec, ",", 0); | 
|  | int i; | 
|  |  | 
|  | if (debug_regions) { | 
|  | g_array_unref(debug_regions); | 
|  | debug_regions = NULL; | 
|  | } | 
|  |  | 
|  | debug_regions = g_array_sized_new(FALSE, FALSE, | 
|  | sizeof(Range), g_strv_length(ranges)); | 
|  | for (i = 0; ranges[i]; i++) { | 
|  | const char *r = ranges[i]; | 
|  | const char *range_op, *r2, *e; | 
|  | uint64_t r1val, r2val, lob, upb; | 
|  | struct Range range; | 
|  |  | 
|  | range_op = strstr(r, "-"); | 
|  | r2 = range_op ? range_op + 1 : NULL; | 
|  | if (!range_op) { | 
|  | range_op = strstr(r, "+"); | 
|  | r2 = range_op ? range_op + 1 : NULL; | 
|  | } | 
|  | if (!range_op) { | 
|  | range_op = strstr(r, ".."); | 
|  | r2 = range_op ? range_op + 2 : NULL; | 
|  | } | 
|  | if (!range_op) { | 
|  | error_setg(errp, "Bad range specifier"); | 
|  | goto out; | 
|  | } | 
|  |  | 
|  | if (qemu_strtou64(r, &e, 0, &r1val) | 
|  | || e != range_op) { | 
|  | error_setg(errp, "Invalid number to the left of %.*s", | 
|  | (int)(r2 - range_op), range_op); | 
|  | goto out; | 
|  | } | 
|  | if (qemu_strtou64(r2, NULL, 0, &r2val)) { | 
|  | error_setg(errp, "Invalid number to the right of %.*s", | 
|  | (int)(r2 - range_op), range_op); | 
|  | goto out; | 
|  | } | 
|  |  | 
|  | switch (*range_op) { | 
|  | case '+': | 
|  | lob = r1val; | 
|  | upb = r1val + r2val - 1; | 
|  | break; | 
|  | case '-': | 
|  | upb = r1val; | 
|  | lob = r1val - (r2val - 1); | 
|  | break; | 
|  | case '.': | 
|  | lob = r1val; | 
|  | upb = r2val; | 
|  | break; | 
|  | default: | 
|  | g_assert_not_reached(); | 
|  | } | 
|  | if (lob > upb) { | 
|  | error_setg(errp, "Invalid range"); | 
|  | goto out; | 
|  | } | 
|  | range_set_bounds(&range, lob, upb); | 
|  | g_array_append_val(debug_regions, range); | 
|  | } | 
|  | out: | 
|  | g_strfreev(ranges); | 
|  | } | 
|  |  | 
|  | const QEMULogItem qemu_log_items[] = { | 
|  | { CPU_LOG_TB_OUT_ASM, "out_asm", | 
|  | "show generated host assembly code for each compiled TB" }, | 
|  | { CPU_LOG_TB_IN_ASM, "in_asm", | 
|  | "show target assembly code for each compiled TB" }, | 
|  | { CPU_LOG_TB_OP, "op", | 
|  | "show micro ops for each compiled TB" }, | 
|  | { CPU_LOG_TB_OP_OPT, "op_opt", | 
|  | "show micro ops after optimization" }, | 
|  | { CPU_LOG_TB_OP_IND, "op_ind", | 
|  | "show micro ops before indirect lowering" }, | 
|  | { CPU_LOG_INT, "int", | 
|  | "show interrupts/exceptions in short format" }, | 
|  | { CPU_LOG_EXEC, "exec", | 
|  | "show trace before each executed TB (lots of logs)" }, | 
|  | { CPU_LOG_TB_CPU, "cpu", | 
|  | "show CPU registers before entering a TB (lots of logs)" }, | 
|  | { CPU_LOG_TB_FPU, "fpu", | 
|  | "include FPU registers in the 'cpu' logging" }, | 
|  | { CPU_LOG_MMU, "mmu", | 
|  | "log MMU-related activities" }, | 
|  | { CPU_LOG_PCALL, "pcall", | 
|  | "x86 only: show protected mode far calls/returns/exceptions" }, | 
|  | { CPU_LOG_RESET, "cpu_reset", | 
|  | "show CPU state before CPU resets" }, | 
|  | { LOG_UNIMP, "unimp", | 
|  | "log unimplemented functionality" }, | 
|  | { LOG_GUEST_ERROR, "guest_errors", | 
|  | "log when the guest OS does something invalid (eg accessing a\n" | 
|  | "non-existent register)" }, | 
|  | { CPU_LOG_PAGE, "page", | 
|  | "dump pages at beginning of user mode emulation" }, | 
|  | { CPU_LOG_TB_NOCHAIN, "nochain", | 
|  | "do not chain compiled TBs so that \"exec\" and \"cpu\" show\n" | 
|  | "complete traces" }, | 
|  | #ifdef CONFIG_PLUGIN | 
|  | { CPU_LOG_PLUGIN, "plugin", "output from TCG plugins"}, | 
|  | #endif | 
|  | { LOG_STRACE, "strace", | 
|  | "log every user-mode syscall, its input, and its result" }, | 
|  | { LOG_PER_THREAD, "tid", | 
|  | "open a separate log file per thread; filename must contain '%d'" }, | 
|  | { CPU_LOG_TB_VPU, "vpu", | 
|  | "include VPU registers in the 'cpu' logging" }, | 
|  | { 0, NULL, NULL }, | 
|  | }; | 
|  |  | 
|  | /* takes a comma separated list of log masks. Return 0 if error. */ | 
|  | int qemu_str_to_log_mask(const char *str) | 
|  | { | 
|  | const QEMULogItem *item; | 
|  | int mask = 0; | 
|  | char **parts = g_strsplit(str, ",", 0); | 
|  | char **tmp; | 
|  |  | 
|  | for (tmp = parts; tmp && *tmp; tmp++) { | 
|  | if (g_str_equal(*tmp, "all")) { | 
|  | for (item = qemu_log_items; item->mask != 0; item++) { | 
|  | mask |= item->mask; | 
|  | } | 
|  | #ifdef CONFIG_TRACE_LOG | 
|  | } else if (g_str_has_prefix(*tmp, "trace:") && (*tmp)[6] != '\0') { | 
|  | trace_enable_events((*tmp) + 6); | 
|  | mask |= LOG_TRACE; | 
|  | #endif | 
|  | } else { | 
|  | for (item = qemu_log_items; item->mask != 0; item++) { | 
|  | if (g_str_equal(*tmp, item->name)) { | 
|  | goto found; | 
|  | } | 
|  | } | 
|  | goto error; | 
|  | found: | 
|  | mask |= item->mask; | 
|  | } | 
|  | } | 
|  |  | 
|  | g_strfreev(parts); | 
|  | return mask; | 
|  |  | 
|  | error: | 
|  | g_strfreev(parts); | 
|  | return 0; | 
|  | } | 
|  |  | 
|  | void qemu_print_log_usage(FILE *f) | 
|  | { | 
|  | const QEMULogItem *item; | 
|  | fprintf(f, "Log items (comma separated):\n"); | 
|  | for (item = qemu_log_items; item->mask != 0; item++) { | 
|  | fprintf(f, "%-15s %s\n", item->name, item->help); | 
|  | } | 
|  | #ifdef CONFIG_TRACE_LOG | 
|  | fprintf(f, "trace:PATTERN   enable trace events\n"); | 
|  | fprintf(f, "\nUse \"-d trace:help\" to get a list of trace events.\n\n"); | 
|  | #endif | 
|  | } |