diff options
| author | Richard Henderson <richard.henderson@linaro.org> | 2022-04-20 12:47:15 -0700 |
|---|---|---|
| committer | Richard Henderson <richard.henderson@linaro.org> | 2022-04-20 12:47:15 -0700 |
| commit | 27a985159a80430a0a43161797ca14ef946962b8 (patch) | |
| tree | 54708343e87dc25dd9abf5230f43482ab5662ad5 | |
| parent | 2d20a57453f6a206938cbbf77bed0b378c806c1f (diff) | |
| parent | 4e51069d679348d2617512e56e28cdc7bb34c833 (diff) | |
Merge tag 'pull-log-20220420' of https://gitlab.com/rth7680/qemu into staging
Clean up log locking.
Use the FILE* from qemu_log_trylock more often.
Support per-thread log files with -d tid.
# -----BEGIN PGP SIGNATURE-----
#
# iQFRBAABCgA7FiEEekgeeIaLTbaoWgXAZN846K9+IV8FAmJgStUdHHJpY2hhcmQu
# aGVuZGVyc29uQGxpbmFyby5vcmcACgkQZN846K9+IV+c9Af/ZXnKe6bz5yjXy1mS
# mNIBJUPKrz1RXFfJxuCfEDWrtNc/gvQyvc3weZG5X0cXpiczeWA5V/9xbE9hu5gV
# 4rePiIHWmOrais6GZlqEu2F8P3/XyqdPHtcdBfa1hDneixtpqMHCqnh36nQjHyiU
# ogFxEJ/M9tTwhuWZrXe/JSYAiALEDYMK9bk4RUMOP1c4v37rXqUNOAM1IPhfxLL/
# bK9DQMpz5oUNsWWaqBQ2wQWHkNTOpUEkKGQv0xcQF5SdpYwaxakW9B7/h4QSeOUn
# oY6MFTmkJ4BPrLnkcubn+3PICc9LW0OFuzNnUdMCbeqVbjAUQrdMDalKpy4uNFv9
# U1VqHg==
# =Mt5s
# -----END PGP SIGNATURE-----
# gpg: Signature made Wed 20 Apr 2022 11:03:01 AM PDT
# gpg: using RSA key 7A481E78868B4DB6A85A05C064DF38E8AF7E215F
# gpg: issuer "richard.henderson@linaro.org"
# gpg: Good signature from "Richard Henderson <richard.henderson@linaro.org>" [ultimate]
* tag 'pull-log-20220420' of https://gitlab.com/rth7680/qemu: (39 commits)
util/log: Support per-thread log files
util/log: Limit RCUCloseFILE to file closing
util/log: Rename QemuLogFile to RCUCloseFILE
util/log: Combine two logfile closes
util/log: Hoist the eval of is_daemonized in qemu_set_log_internal
util/log: Rename qemu_logfile_mutex to global_mutex
util/log: Rename qemu_logfile to global_file
util/log: Rename logfilename to global_filename
util/log: Remove qemu_log_close
softmmu: Use qemu_set_log_filename_flags
linux-user: Use qemu_set_log_filename_flags
bsd-user: Use qemu_set_log_filename_flags
util/log: Introduce qemu_set_log_filename_flags
sysemu/os-win32: Test for and use _lock_file/_unlock_file
include/qemu/log: Move entire implementation out-of-line
include/exec/log: Do not reference QemuLogFile directly
tests/unit: Do not reference QemuLogFile directly
linux-user: Expand log_page_dump inline
bsd-user: Expand log_page_dump inline
util/log: Drop call to setvbuf
...
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
49 files changed, 725 insertions, 660 deletions
diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c index 083ada76b1..635aeecc0a 100644 --- a/accel/tcg/cpu-exec.c +++ b/accel/tcg/cpu-exec.c @@ -214,17 +214,19 @@ static inline void log_cpu_exec(target_ulong pc, CPUState *cpu, #if defined(DEBUG_DISAS) if (qemu_loglevel_mask(CPU_LOG_TB_CPU)) { - FILE *logfile = qemu_log_lock(); - int flags = 0; + FILE *logfile = qemu_log_trylock(); + if (logfile) { + int flags = 0; - if (qemu_loglevel_mask(CPU_LOG_TB_FPU)) { - flags |= CPU_DUMP_FPU; - } + if (qemu_loglevel_mask(CPU_LOG_TB_FPU)) { + flags |= CPU_DUMP_FPU; + } #if defined(TARGET_I386) - flags |= CPU_DUMP_CCOP; + flags |= CPU_DUMP_CCOP; #endif - log_cpu_state(cpu, flags); - qemu_log_unlock(logfile); + cpu_dump_state(cpu, logfile, flags); + qemu_log_unlock(logfile); + } } #endif /* DEBUG_DISAS */ } diff --git a/accel/tcg/translate-all.c b/accel/tcg/translate-all.c index a6e03c1e50..291034cb09 100644 --- a/accel/tcg/translate-all.c +++ b/accel/tcg/translate-all.c @@ -1527,69 +1527,75 @@ TranslationBlock *tb_gen_code(CPUState *cpu, #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM) && qemu_log_in_addr_range(tb->pc)) { - FILE *logfile = qemu_log_lock(); - int code_size, data_size; - const tcg_target_ulong *rx_data_gen_ptr; - size_t chunk_start; - int insn = 0; - - if (tcg_ctx->data_gen_ptr) { - rx_data_gen_ptr = tcg_splitwx_to_rx(tcg_ctx->data_gen_ptr); - code_size = (const void *)rx_data_gen_ptr - tb->tc.ptr; - data_size = gen_code_size - code_size; - } else { - rx_data_gen_ptr = 0; - code_size = gen_code_size; - data_size = 0; - } + FILE *logfile = qemu_log_trylock(); + if (logfile) { + int code_size, data_size; + const tcg_target_ulong *rx_data_gen_ptr; + size_t chunk_start; + int insn = 0; + + if (tcg_ctx->data_gen_ptr) { + rx_data_gen_ptr = tcg_splitwx_to_rx(tcg_ctx->data_gen_ptr); + code_size = (const void *)rx_data_gen_ptr - tb->tc.ptr; + data_size = gen_code_size - code_size; + } else { + rx_data_gen_ptr = 0; + code_size = gen_code_size; + data_size = 0; + } - /* Dump header and the first instruction */ - qemu_log("OUT: [size=%d]\n", gen_code_size); - qemu_log(" -- guest addr 0x" TARGET_FMT_lx " + tb prologue\n", - tcg_ctx->gen_insn_data[insn][0]); - chunk_start = tcg_ctx->gen_insn_end_off[insn]; - log_disas(tb->tc.ptr, chunk_start); + /* Dump header and the first instruction */ + fprintf(logfile, "OUT: [size=%d]\n", gen_code_size); + fprintf(logfile, + " -- guest addr 0x" TARGET_FMT_lx " + tb prologue\n", + tcg_ctx->gen_insn_data[insn][0]); + chunk_start = tcg_ctx->gen_insn_end_off[insn]; + disas(logfile, tb->tc.ptr, chunk_start); - /* - * Dump each instruction chunk, wrapping up empty chunks into - * the next instruction. The whole array is offset so the - * first entry is the beginning of the 2nd instruction. - */ - while (insn < tb->icount) { - size_t chunk_end = tcg_ctx->gen_insn_end_off[insn]; - if (chunk_end > chunk_start) { - qemu_log(" -- guest addr 0x" TARGET_FMT_lx "\n", - tcg_ctx->gen_insn_data[insn][0]); - log_disas(tb->tc.ptr + chunk_start, chunk_end - chunk_start); - chunk_start = chunk_end; + /* + * Dump each instruction chunk, wrapping up empty chunks into + * the next instruction. The whole array is offset so the + * first entry is the beginning of the 2nd instruction. + */ + while (insn < tb->icount) { + size_t chunk_end = tcg_ctx->gen_insn_end_off[insn]; + if (chunk_end > chunk_start) { + fprintf(logfile, " -- guest addr 0x" TARGET_FMT_lx "\n", + tcg_ctx->gen_insn_data[insn][0]); + disas(logfile, tb->tc.ptr + chunk_start, + chunk_end - chunk_start); + chunk_start = chunk_end; + } + insn++; } - insn++; - } - if (chunk_start < code_size) { - qemu_log(" -- tb slow paths + alignment\n"); - log_disas(tb->tc.ptr + chunk_start, code_size - chunk_start); - } + if (chunk_start < code_size) { + fprintf(logfile, " -- tb slow paths + alignment\n"); + disas(logfile, tb->tc.ptr + chunk_start, + code_size - chunk_start); + } - /* Finally dump any data we may have after the block */ - if (data_size) { - int i; - qemu_log(" data: [size=%d]\n", data_size); - for (i = 0; i < data_size / sizeof(tcg_target_ulong); i++) { - if (sizeof(tcg_target_ulong) == 8) { - qemu_log("0x%08" PRIxPTR ": .quad 0x%016" TCG_PRIlx "\n", - (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]); - } else if (sizeof(tcg_target_ulong) == 4) { - qemu_log("0x%08" PRIxPTR ": .long 0x%08" TCG_PRIlx "\n", - (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]); - } else { - qemu_build_not_reached(); + /* Finally dump any data we may have after the block */ + if (data_size) { + int i; + fprintf(logfile, " data: [size=%d]\n", data_size); + for (i = 0; i < data_size / sizeof(tcg_target_ulong); i++) { + if (sizeof(tcg_target_ulong) == 8) { + fprintf(logfile, + "0x%08" PRIxPTR ": .quad 0x%016" TCG_PRIlx "\n", + (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]); + } else if (sizeof(tcg_target_ulong) == 4) { + fprintf(logfile, + "0x%08" PRIxPTR ": .long 0x%08" TCG_PRIlx "\n", + (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]); + } else { + qemu_build_not_reached(); + } } } + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); } - qemu_log("\n"); - qemu_log_flush(); - qemu_log_unlock(logfile); } #endif diff --git a/accel/tcg/translator.c b/accel/tcg/translator.c index f06c314266..fe7af9b943 100644 --- a/accel/tcg/translator.c +++ b/accel/tcg/translator.c @@ -139,11 +139,13 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db, #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(db->pc_first)) { - FILE *logfile = qemu_log_lock(); - qemu_log("----------------\n"); - ops->disas_log(db, cpu); - qemu_log("\n"); - qemu_log_unlock(logfile); + FILE *logfile = qemu_log_trylock(); + if (logfile) { + fprintf(logfile, "----------------\n"); + ops->disas_log(db, cpu, logfile); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif } diff --git a/bsd-user/main.c b/bsd-user/main.c index 88d347d05e..aa13eae7f3 100644 --- a/bsd-user/main.c +++ b/bsd-user/main.c @@ -405,17 +405,16 @@ int main(int argc, char **argv) } /* init debug */ - qemu_log_needs_buffers(); - qemu_set_log_filename(log_file, &error_fatal); - if (log_mask) { - int mask; - - mask = qemu_str_to_log_mask(log_mask); - if (!mask) { - qemu_print_log_usage(stdout); - exit(1); + { + int mask = 0; + if (log_mask) { + mask = qemu_str_to_log_mask(log_mask); + if (!mask) { + qemu_print_log_usage(stdout); + exit(1); + } } - qemu_set_log(mask); + qemu_set_log_filename_flags(log_file, mask, &error_fatal); } if (optind >= argc) { @@ -504,20 +503,29 @@ int main(int argc, char **argv) g_free(target_environ); if (qemu_loglevel_mask(CPU_LOG_PAGE)) { - qemu_log("guest_base %p\n", (void *)guest_base); - log_page_dump("binary load"); - - qemu_log("start_brk 0x" TARGET_ABI_FMT_lx "\n", info->start_brk); - qemu_log("end_code 0x" TARGET_ABI_FMT_lx "\n", info->end_code); - qemu_log("start_code 0x" TARGET_ABI_FMT_lx "\n", - info->start_code); - qemu_log("start_data 0x" TARGET_ABI_FMT_lx "\n", - info->start_data); - qemu_log("end_data 0x" TARGET_ABI_FMT_lx "\n", info->end_data); - qemu_log("start_stack 0x" TARGET_ABI_FMT_lx "\n", - info->start_stack); - qemu_log("brk 0x" TARGET_ABI_FMT_lx "\n", info->brk); - qemu_log("entry 0x" TARGET_ABI_FMT_lx "\n", info->entry); + FILE *f = qemu_log_trylock(); + if (f) { + fprintf(f, "guest_base %p\n", (void *)guest_base); + fprintf(f, "page layout changed following binary load\n"); + page_dump(f); + + fprintf(f, "start_brk 0x" TARGET_ABI_FMT_lx "\n", + info->start_brk); + fprintf(f, "end_code 0x" TARGET_ABI_FMT_lx "\n", + info->end_code); + fprintf(f, "start_code 0x" TARGET_ABI_FMT_lx "\n", + info->start_code); + fprintf(f, "start_data 0x" TARGET_ABI_FMT_lx "\n", + info->start_data); + fprintf(f, "end_data 0x" TARGET_ABI_FMT_lx "\n", + info->end_data); + fprintf(f, "start_stack 0x" TARGET_ABI_FMT_lx "\n", + info->start_stack); + fprintf(f, "brk 0x" TARGET_ABI_FMT_lx "\n", info->brk); + fprintf(f, "entry 0x" TARGET_ABI_FMT_lx "\n", info->entry); + + qemu_log_unlock(f); + } } /* build Task State */ @@ -399,14 +399,14 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...) fprintf(stderr, "\n"); cpu_dump_state(cpu, stderr, CPU_DUMP_FPU | CPU_DUMP_CCOP); if (qemu_log_separate()) { - FILE *logfile = qemu_log_lock(); - qemu_log("qemu: fatal: "); - qemu_log_vprintf(fmt, ap2); - qemu_log("\n"); - log_cpu_state(cpu, CPU_DUMP_FPU | CPU_DUMP_CCOP); - qemu_log_flush(); - qemu_log_unlock(logfile); - qemu_log_close(); + FILE *logfile = qemu_log_trylock(); + if (logfile) { + fprintf(logfile, "qemu: fatal: "); + vfprintf(logfile, fmt, ap2); + fprintf(logfile, "\n"); + cpu_dump_state(cpu, logfile, CPU_DUMP_FPU | CPU_DUMP_CCOP); + qemu_log_unlock(logfile); + } } va_end(ap2); va_end(ap); diff --git a/hw/net/can/can_sja1000.c b/hw/net/can/can_sja1000.c index 3ba803e947..e0f76d3eb3 100644 --- a/hw/net/can/can_sja1000.c +++ b/hw/net/can/can_sja1000.c @@ -247,21 +247,22 @@ int can_sja_accept_filter(CanSJA1000State *s, static void can_display_msg(const char *prefix, const qemu_can_frame *msg) { int i; - FILE *logfile = qemu_log_lock(); - - qemu_log("%s%03X [%01d] %s %s", - prefix, - msg->can_id & QEMU_CAN_EFF_MASK, - msg->can_dlc, - msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF", - msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT"); - - for (i = 0; i < msg->can_dlc; i++) { - qemu_log(" %02X", msg->data[i]); + FILE *logfile = qemu_log_trylock(); + + if (logfile) { + fprintf(logfile, "%s%03X [%01d] %s %s", + prefix, + msg->can_id & QEMU_CAN_EFF_MASK, + msg->can_dlc, + msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF", + msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT"); + + for (i = 0; i < msg->can_dlc; i++) { + fprintf(logfile, " %02X", msg->data[i]); + } + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); } - qemu_log("\n"); - qemu_log_flush(); - qemu_log_unlock(logfile); } static void buff2frame_pel(const uint8_t *buff, qemu_can_frame *frame) diff --git a/hw/xen/xen_pvdev.c b/hw/xen/xen_pvdev.c index 8ab458922a..037152f063 100644 --- a/hw/xen/xen_pvdev.c +++ b/hw/xen/xen_pvdev.c @@ -196,37 +196,40 @@ const char *xenbus_strstate(enum xenbus_state state) * 2 == noisy debug messages (logfile only). * 3 == will flood your log (logfile only). */ +static void xen_pv_output_msg(struct XenLegacyDevice *xendev, + FILE *f, const char *fmt, va_list args) +{ + if (xendev) { + fprintf(f, "xen be: %s: ", xendev->name); + } else { + fprintf(f, "xen be core: "); + } + vfprintf(f, fmt, args); +} + void xen_pv_printf(struct XenLegacyDevice *xendev, int msg_level, const char *fmt, ...) { + FILE *logfile; va_list args; - if (xendev) { - if (msg_level > xendev->debug) { - return; - } - qemu_log("xen be: %s: ", xendev->name); - if (msg_level == 0) { - fprintf(stderr, "xen be: %s: ", xendev->name); - } - } else { - if (msg_level > debug) { - return; - } - qemu_log("xen be core: "); - if (msg_level == 0) { - fprintf(stderr, "xen be core: "); - } + if (msg_level > (xendev ? xendev->debug : debug)) { + return; } - va_start(args, fmt); - qemu_log_vprintf(fmt, args); - va_end(args); + + logfile = qemu_log_trylock(); + if (logfile) { + va_start(args, fmt); + xen_pv_output_msg(xendev, logfile, fmt, args); + va_end(args); + qemu_log_unlock(logfile); + } + if (msg_level == 0) { va_start(args, fmt); - vfprintf(stderr, fmt, args); + xen_pv_output_msg(xendev, stderr, fmt, args); va_end(args); } - qemu_log_flush(); } void xen_pv_evtchn_event(void *opaque) diff --git a/include/exec/log.h b/include/exec/log.h index 3c7fa65ead..4a7375a45f 100644 --- a/include/exec/log.h +++ b/include/exec/log.h @@ -15,15 +15,10 @@ */ static inline void log_cpu_state(CPUState *cpu, int flags) { - QemuLogFile *logfile; - - if (qemu_log_enabled()) { - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - cpu_dump_state(cpu, logfile->fd, flags); - } - rcu_read_unlock(); + FILE *f = qemu_log_trylock(); + if (f) { + cpu_dump_state(cpu, f, flags); + qemu_log_unlock(f); } } @@ -42,43 +37,4 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags) } } -#ifdef NEED_CPU_H -/* disas() and target_disas() to qemu_logfile: */ -static inline void log_target_disas(CPUState *cpu, target_ulong start, - target_ulong len) -{ - QemuLogFile *logfile; - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - target_disas(logfile->fd, cpu, start, len); - } - rcu_read_unlock(); -} - -static inline void log_disas(const void *code, unsigned long size) -{ - QemuLogFile *logfile; - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - disas(logfile->fd, code, size); - } - rcu_read_unlock(); -} - -#if defined(CONFIG_USER_ONLY) -/* page_dump() output to the log file: */ -static inline void log_page_dump(const char *operation) -{ - FILE *logfile = qemu_log_lock(); - if (logfile) { - qemu_log("page layout changed following %s\n", operation); - page_dump(logfile); - } - qemu_log_unlock(logfile); -} -#endif -#endif - #endif diff --git a/include/exec/translator.h b/include/exec/translator.h index 9bc46eda59..31d3fa76ff 100644 --- a/include/exec/translator.h +++ b/include/exec/translator.h @@ -118,7 +118,7 @@ typedef struct TranslatorOps { void (*insn_start)(DisasContextBase *db, CPUState *cpu); void (*translate_insn)(DisasContextBase *db, CPUState *cpu); void (*tb_stop)(DisasContextBase *db, CPUState *cpu); - void (*disas_log)(const DisasContextBase *db, CPUState *cpu); + void (*disas_log)(const DisasContextBase *db, CPUState *cpu, FILE *f); } TranslatorOps; /** diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h index 5e41517227..d47c9cd446 100644 --- a/include/qemu/log-for-trace.h +++ b/include/qemu/log-for-trace.h @@ -30,6 +30,6 @@ static inline bool qemu_loglevel_mask(int mask) } /* main logging function */ -int G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...); +void G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...); #endif diff --git a/include/qemu/log.h b/include/qemu/log.h index 5739c7e6d8..c5643d8dd5 100644 --- a/include/qemu/log.h +++ b/include/qemu/log.h @@ -3,46 +3,16 @@ /* A small part of this API is split into its own header */ #include "qemu/log-for-trace.h" -#include "qemu/rcu.h" - -typedef struct QemuLogFile { - struct rcu_head rcu; - FILE *fd; -} QemuLogFile; - -/* Private global variable, don't use */ -extern QemuLogFile *qemu_logfile; - /* * The new API: - * */ -/* Log settings checking macros: */ - -/* Returns true if qemu_log() will really write somewhere - */ -static inline bool qemu_log_enabled(void) -{ - return qemu_logfile != NULL; -} +/* Returns true if qemu_log() will really write somewhere. */ +bool qemu_log_enabled(void); -/* Returns true if qemu_log() will write somewhere else than stderr - */ -static inline bool qemu_log_separate(void) -{ - QemuLogFile *logfile; - bool res = false; - - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile && logfile->fd != stderr) { - res = true; - } - rcu_read_unlock(); - return res; -} +/* Returns true if qemu_log() will write somewhere other than stderr. */ +bool qemu_log_separate(void); #define CPU_LOG_TB_OUT_ASM (1 << 0) #define CPU_LOG_TB_IN_ASM (1 << 1) @@ -64,51 +34,15 @@ static inline bool qemu_log_separate(void) #define CPU_LOG_PLUGIN (1 << 18) /* LOG_STRACE is used for user-mode strace logging. */ #define LOG_STRACE (1 << 19) +#define LOG_PER_THREAD (1 << 20) -/* Lock output for a series of related logs. Since this is not needed - * for a single qemu_log / qemu_log_mask / qemu_log_mask_and_addr, we - * assume that qemu_loglevel_mask has already been tested, and that - * qemu_loglevel is never set when qemu_logfile is unset. - */ +/* Lock/unlock output. */ -static inline FILE *qemu_log_lock(void) -{ - QemuLogFile *logfile; - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - qemu_flockfile(logfile->fd); - return logfile->fd; - } else { - return NULL; - } -} - -static inline void qemu_log_unlock(FILE *fd) -{ - if (fd) { - qemu_funlockfile(fd); - } - rcu_read_unlock(); -} +FILE *qemu_log_trylock(void) G_GNUC_WARN_UNUSED_RESULT; +void qemu_log_unlock(FILE *fd); /* Logging functions: */ -/* vfprintf-like logging function - */ -static inline void G_GNUC_PRINTF(1, 0) -qemu_log_vprintf(const char *fmt, va_list va) -{ - QemuLogFile *logfile; - - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - vfprintf(logfile->fd, fmt, va); - } - rcu_read_unlock(); -} - /* log only if a bit is set on the current loglevel mask: * @mask: bit to check in the mask * @fmt: printf-style format string @@ -147,9 +81,9 @@ typedef struct QEMULogItem { extern const QEMULogItem qemu_log_items[]; -void qemu_set_log(int log_flags); -void qemu_log_needs_buffers(void); -void qemu_set_log_filename(const char *filename, Error **errp); +bool qemu_set_log(int log_flags, Error **errp); +bool qemu_set_log_filename(const char *filename, Error **errp); +bool qemu_set_log_filename_flags(const char *name, int flags, Error **errp); void qemu_set_dfilter_ranges(const char *ranges, Error **errp); bool qemu_log_in_addr_range(uint64_t addr); int qemu_str_to_log_mask(const char *str); @@ -159,9 +93,4 @@ int qemu_str_to_log_mask(const char *str); */ void qemu_print_log_usage(FILE *f); -/* fflush() the log file */ -void qemu_log_flush(void); -/* Close the log file */ -void qemu_log_close(void); - #endif diff --git a/include/sysemu/os-win32.h b/include/sysemu/os-win32.h index 3c74a78e33..edc3b38a57 100644 --- a/include/sysemu/os-win32.h +++ b/include/sysemu/os-win32.h @@ -109,20 +109,22 @@ static inline char *realpath(const char *path, char *resolved_path) return resolved_path; } -/* ??? Mingw appears to export _lock_file and _unlock_file as the functions - * with which to lock a stdio handle. But something is wrong in the markup, - * either in the header or the library, such that we get undefined references - * to "_imp___lock_file" etc when linking. Since we seem to have no other - * alternative, and the usage within the logging functions isn't critical, - * ignore FILE locking. +/* + * Older versions of MinGW do not import _lock_file and _unlock_file properly. + * This was fixed for v6.0.0 with commit b48e3ac8969d. */ - static inline void qemu_flockfile(FILE *f) { +#ifdef HAVE__LOCK_FILE + _lock_file(f); +#endif } static inline void qemu_funlockfile(FILE *f) { +#ifdef HAVE__LOCK_FILE + _unlock_file(f); +#endif } /* We wrap all the sockets functions so that we can diff --git a/linux-user/main.c b/linux-user/main.c index fbc9bcfd5f..0297ae8321 100644 --- a/linux-user/main.c +++ b/linux-user/main.c @@ -85,6 +85,7 @@ static bool enable_strace; * Used to support command line arguments overriding environment variables. */ static int last_log_mask; +static const char *last_log_filename; /* * When running 32-on-64 we should make sure we can fit all of the possible @@ -257,7 +258,7 @@ static void handle_arg_dfilter(const char *arg) static void handle_arg_log_filename(const char *arg) { - qemu_set_log_filename(arg, &error_fatal); + last_log_filename = arg; } static void handle_arg_set_env(const char *arg) @@ -643,7 +644,6 @@ int main(int argc, char **argv, char **envp) int i; int ret; int execfd; - int log_mask; unsigned long max_reserved_va; bool preserve_argv0; @@ -677,11 +677,9 @@ int main(int argc, char **argv, char **envp) optind = parse_args(argc, argv); - log_mask = last_log_mask | (enable_strace ? LOG_STRACE : 0); - if (log_mask) { - qemu_log_needs_buffers(); - qemu_set_log(log_mask); - } + qemu_set_log_filename_flags(last_log_filename, + last_log_mask | (enable_strace * LOG_STRACE), + &error_fatal); if (!trace_init_backends()) { exit(1); @@ -858,21 +856,36 @@ int main(int argc, char **argv, char **envp) g_free(target_environ); if (qemu_loglevel_mask(CPU_LOG_PAGE)) { - qemu_log("guest_base %p\n", (void *)guest_base); - log_page_dump("binary load"); - - qemu_log("start_brk 0x" TARGET_ABI_FMT_lx "\n", info->start_brk); - qemu_log("end_code 0x" TARGET_ABI_FMT_lx "\n", info->end_code); - qemu_log("start_code 0x" TARGET_ABI_FMT_lx "\n", info->start_code); - qemu_log("start_data 0x" TARGET_ABI_FMT_lx "\n", info->start_data); - qemu_log("end_data 0x" TARGET_ABI_FMT_lx "\n", info->end_data); - qemu_log("start_stack 0x" TARGET_ABI_FMT_lx "\n", info->start_stack); - qemu_log("brk 0x" TARGET_ABI_FMT_lx "\n", info->brk); - qemu_log("entry 0x" TARGET_ABI_FMT_lx "\n", info->entry); - qemu_log("argv_start 0x" TARGET_ABI_FMT_lx "\n", info->arg_start); - qemu_log("env_start 0x" TARGET_ABI_FMT_lx "\n", - info->arg_end + (abi_ulong)sizeof(abi_ulong)); - qemu_log("auxv_start 0x" TARGET_ABI_FMT_lx "\n", info->saved_auxv); + FILE *f = qemu_log_trylock(); + if (f) { + fprintf(f, "guest_base %p\n", (void *)guest_base); + fprintf(f, "page layout changed following binary load\n"); + page_dump(f); + + fprintf(f, "start_brk 0x" TARGET_ABI_FMT_lx "\n", + info->start_brk); + fprintf(f, "end_code 0x" TARGET_ABI_FMT_lx "\n", + info->end_code); + fprintf(f, "start_code 0x" TARGET_ABI_FMT_lx "\n", + info->start_code); + fprintf(f, "start_data 0x" TARGET_ABI_FMT_lx "\n", + info->start_data); + fprintf(f, "end_data 0x" TARGET_ABI_FMT_lx "\n", + info->end_data); + fprintf(f, "start_stack 0x" TARGET_ABI_FMT_lx "\n", + info->start_stack); + fprintf(f, "brk 0x" TARGET_ABI_FMT_lx "\n", + info->brk); + fprintf(f, "entry 0x" TARGET_ABI_FMT_lx "\n", + info->entry); + fprintf(f, "argv_start 0x" TARGET_ABI_FMT_lx "\n", + info->arg_start); + fprintf(f, "env_start 0x" TARGET_ABI_FMT_lx "\n", + info->arg_end + (abi_ulong)sizeof(abi_ulong)); + fprintf(f, "auxv_start 0x" TARGET_ABI_FMT_lx "\n", + info->saved_auxv); + qemu_log_unlock(f); + } } target_set_brk(info->brk); diff --git a/linux-user/mmap.c b/linux-user/mmap.c index a861f1e1d1..48e1373796 100644 --- a/linux-user/mmap.c +++ b/linux-user/mmap.c @@ -630,7 +630,12 @@ abi_long target_mmap(abi_ulong start, abi_ulong len, int target_prot, the_end: trace_target_mmap_complete(start); if (qemu_loglevel_mask(CPU_LOG_PAGE)) { - log_page_dump(__func__); + FILE *f = qemu_log_trylock(); + if (f) { + fprintf(f, "page layout changed following mmap\n"); + page_dump(f); + qemu_log_unlock(f); + } } tb_invalidate_phys_range(start, start + len); mmap_unlock(); diff --git a/meson.build b/meson.build index 6ba60950c8..d083c6b7bf 100644 --- a/meson.build +++ b/meson.build @@ -2030,6 +2030,18 @@ foreach k, v: config_host endif endforeach +# Older versions of MinGW do not import _lock_file and _unlock_file properly. +# This was fixed for v6.0.0 with commit b48e3ac8969d. +if targetos == 'windows' + config_host_data.set('HAVE__LOCK_FILE', cc.links(''' + #include <stdio.h> + int main(void) { + _lock_file(NULL); + _unlock_file(NULL); + return 0; + }''', name: '_lock_file and _unlock_file')) +endif + ######################## # Target configuration # ######################## diff --git a/monitor/misc.c b/monitor/misc.c index b0fc0e5843..33372b93cc 100644 --- a/monitor/misc.c +++ b/monitor/misc.c @@ -419,8 +419,7 @@ static void hmp_logfile(Monitor *mon, const QDict *qdict) { Error *err = NULL; - qemu_set_log_filename(qdict_get_str(qdict, "filename"), &err); - if (err) { + if (!qemu_set_log_filename(qdict_get_str(qdict, "filename"), &err)) { error_report_err(err); } } @@ -429,6 +428,7 @@ static void hmp_log(Monitor *mon, const QDict *qdict) { int mask; const char *items = qdict_get_str(qdict, "items"); + Error *err = NULL; if (!strcmp(items, "none")) { mask = 0; @@ -439,7 +439,10 @@ static void hmp_log(Monitor *mon, const QDict *qdict) return; } } - qemu_set_log(mask); + + if (!qemu_set_log(mask, &err)) { + error_report_err(err); + } } static void hmp_singlestep(Monitor *mon, const QDict *qdict) diff --git a/net/can/can_socketcan.c b/net/can/can_socketcan.c index 4b68f60c6b..c1a1ad0563 100644 --- a/net/can/can_socketcan.c +++ b/net/can/can_socketcan.c @@ -76,19 +76,21 @@ QEMU_BUILD_BUG_ON(offsetof(qemu_can_frame, data) static void can_host_socketcan_display_msg(struct qemu_can_frame *msg) { int i; - FILE *logfile = qemu_log_lock(); - qemu_log("[cansocketcan]: %03X [%01d] %s %s", - msg->can_id & QEMU_CAN_EFF_MASK, - msg->can_dlc, - msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF", - msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT"); - - for (i = 0; i < msg->can_dlc; i++) { - qemu_log(" %02X", msg->data[i]); + FILE *logfile = qemu_log_trylock(); + + if (logfile) { + fprintf(logfile, "[cansocketcan]: %03X [%01d] %s %s", + msg->can_id & QEMU_CAN_EFF_MASK, + msg->can_dlc, + msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF", + msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT"); + + for (i = 0; i < msg->can_dlc; i++) { + fprintf(logfile, " %02X", msg->data[i]); + } + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); } - qemu_log("\n"); - qemu_log_flush(); - qemu_log_unlock(logfile); } static void can_host_socketcan_read(void *opaque) diff --git a/os-posix.c b/os-posix.c index ee765f047d..faf6e6978b 100644 --- a/os-posix.c +++ b/os-posix.c @@ -291,7 +291,7 @@ void os_setup_post(void) dup2(fd, 0); dup2(fd, 1); /* In case -D is given do not redirect stderr to /dev/null */ - if (!qemu_logfile) { + if (!qemu_log_enabled()) { dup2(fd, 2); } diff --git a/qemu-img.c b/qemu-img.c index 116e058675..ef3224a9d4 100644 --- a/qemu-img.c +++ b/qemu-img.c @@ -5443,7 +5443,7 @@ int main(int argc, char **argv) exit(1); } trace_init_file(); - qemu_set_log(LOG_TRACE); + qemu_set_log(LOG_TRACE, &error_fatal); /* find the command */ for (cmd = img_cmds; cmd->name != NULL; cmd++) { @@ -634,7 +634,7 @@ int main(int argc, char **argv) exit(1); } trace_init_file(); - qemu_set_log(LOG_TRACE); + qemu_set_log(LOG_TRACE, &error_fatal); /* initialize commands */ qemuio_add_command(&quit_cmd); diff --git a/qemu-nbd.c b/qemu-nbd.c index 713e7557a9..bf9c5fedce 100644 --- a/qemu-nbd.c +++ b/qemu-nbd.c @@ -804,7 +804,7 @@ int main(int argc, char **argv) exit(1); } trace_init_file(); - qemu_set_log(LOG_TRACE); + qemu_set_log(LOG_TRACE, &error_fatal); socket_activation = check_socket_activation(); if (socket_activation == 0) { diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c index f281daeced..1f2a84c534 100644 --- a/scsi/qemu-pr-helper.c +++ b/scsi/qemu-pr-helper.c @@ -1001,7 +1001,7 @@ int main(int argc, char **argv) exit(EXIT_FAILURE); } trace_init_file(); - qemu_set_log(LOG_TRACE); + qemu_set_log(LOG_TRACE, &error_fatal); #ifdef CONFIG_MPATH dm_init(); diff --git a/softmmu/vl.c b/softmmu/vl.c index 46aba6a039..f679d48d74 100644 --- a/softmmu/vl.c +++ b/softmmu/vl.c @@ -2560,19 +2560,16 @@ static void qemu_process_early_options(void) #endif /* Open the logfile at this point and set the log mask if necessary. */ - if (log_file) { - qemu_set_log_filename(log_file, &error_fatal); - } - if (log_mask) { - int mask; - mask = qemu_str_to_log_mask(log_mask); - if (!mask) { - qemu_print_log_usage(stdout); - exit(1); + { + int mask = 0; + if (log_mask) { + mask = qemu_str_to_log_mask(log_mask); + if (!mask) { + qemu_print_log_usage(stdout); + exit(1); + } } - qemu_set_log(mask); - } else { - qemu_set_log(0); + qemu_set_log_filename_flags(log_file, mask, &error_fatal); } qemu_add_default_firmwarepath(); diff --git a/storage-daemon/qemu-storage-daemon.c b/storage-daemon/qemu-storage-daemon.c index eb72407257..1398f0443d 100644 --- a/storage-daemon/qemu-storage-daemon.c +++ b/storage-daemon/qemu-storage-daemon.c @@ -392,7 +392,7 @@ int main(int argc, char *argv[]) if (!trace_init_backends()) { return EXIT_FAILURE; } - qemu_set_log(LOG_TRACE); + qemu_set_log(LOG_TRACE, &error_fatal); qemu_init_main_loop(&error_fatal); process_options(argc, argv, false); diff --git a/target/alpha/translate.c b/target/alpha/translate.c index 4e887311ab..9af1627079 100644 --- a/target/alpha/translate.c +++ b/target/alpha/translate.c @@ -3027,10 +3027,11 @@ static void alpha_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void alpha_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void alpha_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps alpha_tr_ops = { diff --git a/target/arm/translate-a64.c b/target/arm/translate-a64.c index 9333d7be41..19c09c3b53 100644 --- a/target/arm/translate-a64.c +++ b/target/arm/translate-a64.c @@ -14967,12 +14967,12 @@ static void aarch64_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } static void aarch64_tr_disas_log(const DisasContextBase *dcbase, - CPUState *cpu) + CPUState *cpu, FILE *logfile) { DisasContext *dc = container_of(dcbase, DisasContext, base); - qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first)); - log_target_disas(cpu, dc->base.pc_first, dc->base.tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first)); + target_disas(logfile, cpu, dc->base.pc_first, dc->base.tb->size); } const TranslatorOps aarch64_translator_ops = { diff --git a/target/arm/translate.c b/target/arm/translate.c index e8dfa71364..38e7a38f28 100644 --- a/target/arm/translate.c +++ b/target/arm/translate.c @@ -9891,12 +9891,13 @@ static void arm_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void arm_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void arm_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { DisasContext *dc = container_of(dcbase, DisasContext, base); - qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first)); - log_target_disas(cpu, dc->base.pc_first, dc->base.tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first)); + target_disas(logfile, cpu, dc->base.pc_first, dc->base.tb->size); } static const TranslatorOps arm_translator_ops = { diff --git a/target/avr/translate.c b/target/avr/translate.c index af8a3e0f9c..dc9c3d6bcc 100644 --- a/target/avr/translate.c +++ b/target/avr/translate.c @@ -3015,10 +3015,11 @@ static void avr_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void avr_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void avr_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cs, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps avr_tr_ops = { diff --git a/target/cris/translate.c b/target/cris/translate.c index 3656cd6db1..ac101344a3 100644 --- a/target/cris/translate.c +++ b/target/cris/translate.c @@ -3268,11 +3268,12 @@ static void cris_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void cris_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void cris_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { if (!DISAS_CRIS) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } } diff --git a/target/hexagon/translate.c b/target/hexagon/translate.c index b6f541ecb2..d4fc92f7e9 100644 --- a/target/hexagon/translate.c +++ b/target/hexagon/translate.c @@ -833,10 +833,11 @@ static void hexagon_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void hexagon_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void hexagon_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } @@ -874,12 +875,6 @@ void hexagon_translate_init(void) opcode_init(); - if (HEX_DEBUG) { - if (!qemu_logfile) { - qemu_set_log(qemu_loglevel); - } - } - for (i = 0; i < TOTAL_PER_THREAD_REGS; i++) { hex_gpr[i] = tcg_global_mem_new(cpu_env, offsetof(CPUHexagonState, gpr[i]), diff --git a/target/hppa/translate.c b/target/hppa/translate.c index 0b83ee4d98..b8dbfee5e9 100644 --- a/target/hppa/translate.c +++ b/target/hppa/translate.c @@ -4305,29 +4305,30 @@ static void hppa_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void hppa_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void hppa_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { target_ulong pc = dcbase->pc_first; #ifdef CONFIG_USER_ONLY switch (pc) { case 0x00: - qemu_log("IN:\n0x00000000: (null)\n"); + fprintf(logfile, "IN:\n0x00000000: (null)\n"); return; case 0xb0: - qemu_log("IN:\n0x000000b0: light-weight-syscall\n"); + fprintf(logfile, "IN:\n0x000000b0: light-weight-syscall\n"); return; case 0xe0: - qemu_log("IN:\n0x000000e0: set-thread-pointer-syscall\n"); + fprintf(logfile, "IN:\n0x000000e0: set-thread-pointer-syscall\n"); return; case 0x100: - qemu_log("IN:\n0x00000100: syscall\n"); + fprintf(logfile, "IN:\n0x00000100: syscall\n"); return; } #endif - qemu_log("IN: %s\n", lookup_symbol(pc)); - log_target_disas(cs, pc, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(pc)); + target_disas(logfile, cs, pc, dcbase->tb->size); } static const TranslatorOps hppa_tr_ops = { diff --git a/target/i386/tcg/translate.c b/target/i386/tcg/translate.c index 3ba1c99fff..b7972f0ff5 100644 --- a/target/i386/tcg/translate.c +++ b/target/i386/tcg/translate.c @@ -2580,15 +2580,17 @@ static void gen_unknown_opcode(CPUX86State *env, DisasContext *s) gen_illegal_opcode(s); if (qemu_loglevel_mask(LOG_UNIMP)) { - FILE *logfile = qemu_log_lock(); - target_ulong pc = s->pc_start, end = s->pc; + FILE *logfile = qemu_log_trylock(); + if (logfile) { + target_ulong pc = s->pc_start, end = s->pc; - qemu_log("ILLOPC: " TARGET_FMT_lx ":", pc); - for (; pc < end; ++pc) { - qemu_log(" %02x", cpu_ldub_code(env, pc)); + fprintf(logfile, "ILLOPC: " TARGET_FMT_lx ":", pc); + for (; pc < end; ++pc) { + fprintf(logfile, " %02x", cpu_ldub_code(env, pc)); + } + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); } - qemu_log("\n"); - qemu_log_unlock(logfile); } } @@ -8688,12 +8690,12 @@ static void i386_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } static void i386_tr_disas_log(const DisasContextBase *dcbase, - CPUState *cpu) + CPUState *cpu, FILE *logfile) { DisasContext *dc = container_of(dcbase, DisasContext, base); - qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first)); - log_target_disas(cpu, dc->base.pc_first, dc->base.tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first)); + target_disas(logfile, cpu, dc->base.pc_first, dc->base.tb->size); } static const TranslatorOps i386_tr_ops = { diff --git a/target/m68k/translate.c b/target/m68k/translate.c index af43c8eab8..4026572ed8 100644 --- a/target/m68k/translate.c +++ b/target/m68k/translate.c @@ -6257,10 +6257,11 @@ static void m68k_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void m68k_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void m68k_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps m68k_tr_ops = { diff --git a/target/microblaze/translate.c b/target/microblaze/translate.c index 2561b904b9..bf01384d33 100644 --- a/target/microblaze/translate.c +++ b/target/microblaze/translate.c @@ -1833,10 +1833,11 @@ static void mb_tr_tb_stop(DisasContextBase *dcb, CPUState *cs) } } -static void mb_tr_disas_log(const DisasContextBase *dcb, CPUState *cs) +static void mb_tr_disas_log(const DisasContextBase *dcb, + CPUState *cs, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcb->pc_first)); - log_target_disas(cs, dcb->pc_first, dcb->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcb->pc_first)); + target_disas(logfile, cs, dcb->pc_first, dcb->tb->size); } static const TranslatorOps mb_tr_ops = { diff --git a/target/mips/tcg/translate.c b/target/mips/tcg/translate.c index b82a7ec6ad..6de5b66650 100644 --- a/target/mips/tcg/translate.c +++ b/target/mips/tcg/translate.c @@ -16141,10 +16141,11 @@ static void mips_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void mips_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void mips_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cs, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps mips_tr_ops = { diff --git a/target/nios2/cpu.c b/target/nios2/cpu.c index 6975ae4bdb..b0877cb39e 100644 --- a/target/nios2/cpu.c +++ b/target/nios2/cpu.c @@ -46,11 +46,6 @@ static void nios2_cpu_reset(DeviceState *dev) Nios2CPUClass *ncc = NIOS2_CPU_GET_CLASS(cpu); CPUNios2State *env = &cpu->env; - if (qemu_loglevel_mask(CPU_LOG_RESET)) { - qemu_log("CPU Reset (CPU %d)\n", cs->cpu_index); - log_cpu_state(cs, 0); - } - ncc->parent_reset(dev); memset(env->regs, 0, sizeof(uint32_t) * NUM_CORE_REGS); diff --git a/target/nios2/translate.c b/target/nios2/translate.c index f89271dbed..89b97ef520 100644 --- a/target/nios2/translate.c +++ b/target/nios2/translate.c @@ -833,10 +833,11 @@ static void nios2_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void nios2_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void nios2_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps nios2_tr_ops = { diff --git a/target/openrisc/translate.c b/target/openrisc/translate.c index ca79e609da..7b8ad43d5f 100644 --- a/target/openrisc/translate.c +++ b/target/openrisc/translate.c @@ -1687,12 +1687,13 @@ static void openrisc_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void openrisc_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void openrisc_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { DisasContext *s = container_of(dcbase, DisasContext, base); - qemu_log("IN: %s\n", lookup_symbol(s->base.pc_first)); - log_target_disas(cs, s->base.pc_first, s->base.tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(s->base.pc_first)); + target_disas(logfile, cs, s->base.pc_first, s->base.tb->size); } static const TranslatorOps openrisc_tr_ops = { diff --git a/target/ppc/translate.c b/target/ppc/translate.c index f14f8d7309..fa34f81c30 100644 --- a/target/ppc/translate.c +++ b/target/ppc/translate.c @@ -7769,10 +7769,11 @@ static void ppc_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void ppc_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void ppc_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cs, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps ppc_tr_ops = { diff --git a/target/riscv/translate.c b/target/riscv/translate.c index fac998a6b5..6495726302 100644 --- a/target/riscv/translate.c +++ b/target/riscv/translate.c @@ -1155,18 +1155,20 @@ static void riscv_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void riscv_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void riscv_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { #ifndef CONFIG_USER_ONLY RISCVCPU *rvcpu = RISCV_CPU(cpu); CPURISCVState *env = &rvcpu->env; #endif - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); #ifndef CONFIG_USER_ONLY - qemu_log("Priv: "TARGET_FMT_ld"; Virt: "TARGET_FMT_ld"\n", env->priv, env->virt); + fprintf(logfile, "Priv: "TARGET_FMT_ld"; Virt: "TARGET_FMT_ld"\n", + env->priv, env->virt); #endif - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps riscv_tr_ops = { diff --git a/target/rx/translate.c b/target/rx/translate.c index 5db8f79a82..c8a8991a63 100644 --- a/target/rx/translate.c +++ b/target/rx/translate.c @@ -2342,10 +2342,11 @@ static void rx_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void rx_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void rx_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { - qemu_log("IN:\n"); /* , lookup_symbol(dcbase->pc_first)); */ - log_target_disas(cs, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps rx_tr_ops = { diff --git a/target/s390x/tcg/translate.c b/target/s390x/tcg/translate.c index 80f1f0be9a..ae70368966 100644 --- a/target/s390x/tcg/translate.c +++ b/target/s390x/tcg/translate.c @@ -6660,16 +6660,17 @@ static void s390x_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void s390x_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void s390x_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { DisasContext *dc = container_of(dcbase, DisasContext, base); if (unlikely(dc->ex_value)) { - /* ??? Unfortunately log_target_disas can't use host memory. */ - qemu_log("IN: EXECUTE %016" PRIx64, dc->ex_value); + /* ??? Unfortunately target_disas can't use host memory. */ + fprintf(logfile, "IN: EXECUTE %016" PRIx64, dc->ex_value); } else { - qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first)); - log_target_disas(cs, dc->base.pc_first, dc->base.tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first)); + target_disas(logfile, cs, dc->base.pc_first, dc->base.tb->size); } } diff --git a/target/sh4/translate.c b/target/sh4/translate.c index 43bc88b7b3..f1b190e7cf 100644 --- a/target/sh4/translate.c +++ b/target/sh4/translate.c @@ -2352,10 +2352,11 @@ static void sh4_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void sh4_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs) +static void sh4_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cs, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cs, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps sh4_tr_ops = { diff --git a/target/sparc/translate.c b/target/sparc/translate.c index 4c7c7b5347..2e28222d31 100644 --- a/target/sparc/translate.c +++ b/target/sparc/translate.c @@ -5901,10 +5901,11 @@ static void sparc_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs) } } -static void sparc_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void sparc_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps sparc_tr_ops = { diff --git a/target/tricore/translate.c b/target/tricore/translate.c index 417edbd3f0..d170500fa5 100644 --- a/target/tricore/translate.c +++ b/target/tricore/translate.c @@ -8861,10 +8861,11 @@ static void tricore_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void tricore_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void tricore_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps tricore_tr_ops = { diff --git a/target/xtensa/translate.c b/target/xtensa/translate.c index fc4e9d2c9a..1485df2f22 100644 --- a/target/xtensa/translate.c +++ b/target/xtensa/translate.c @@ -1296,10 +1296,11 @@ static void xtensa_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu) } } -static void xtensa_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu) +static void xtensa_tr_disas_log(const DisasContextBase *dcbase, + CPUState *cpu, FILE *logfile) { - qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first)); - log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size); + fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first)); + target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size); } static const TranslatorOps xtensa_translator_ops = { @@ -756,32 +756,35 @@ void tcg_prologue_init(TCGContext *s) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) { - FILE *logfile = qemu_log_lock(); - qemu_log("PROLOGUE: [size=%zu]\n", prologue_size); - if (s->data_gen_ptr) { - size_t code_size = s->data_gen_ptr - s->code_gen_ptr; - size_t data_size = prologue_size - code_size; - size_t i; - - log_disas(s->code_gen_ptr, code_size); - - for (i = 0; i < data_size; i += sizeof(tcg_target_ulong)) { - if (sizeof(tcg_target_ulong) == 8) { - qemu_log("0x%08" PRIxPTR ": .quad 0x%016" PRIx64 "\n", - (uintptr_t)s->data_gen_ptr + i, - *(uint64_t *)(s->data_gen_ptr + i)); - } else { - qemu_log("0x%08" PRIxPTR ": .long 0x%08x\n", - (uintptr_t)s->data_gen_ptr + i, - *(uint32_t *)(s->data_gen_ptr + i)); + FILE *logfile = qemu_log_trylock(); + if (logfile) { + fprintf(logfile, "PROLOGUE: [size=%zu]\n", prologue_size); + if (s->data_gen_ptr) { + size_t code_size = s->data_gen_ptr - s->code_gen_ptr; + size_t data_size = prologue_size - code_size; + size_t i; + + disas(logfile, s->code_gen_ptr, code_size); + + for (i = 0; i < data_size; i += sizeof(tcg_target_ulong)) { + if (sizeof(tcg_target_ulong) == 8) { + fprintf(logfile, + "0x%08" PRIxPTR ": .quad 0x%016" PRIx64 "\n", + (uintptr_t)s->data_gen_ptr + i, + *(uint64_t *)(s->data_gen_ptr + i)); + } else { + fprintf(logfile, + "0x%08" PRIxPTR ": .long 0x%08x\n", + (uintptr_t)s->data_gen_ptr + i, + *(uint32_t *)(s->data_gen_ptr + i)); + } } + } else { + disas(logfile, s->code_gen_ptr, prologue_size); } - } else { - log_disas(s->code_gen_ptr, prologue_size); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); } - qemu_log("\n"); - qemu_log_flush(); - qemu_log_unlock(logfile); } #endif @@ -1804,7 +1807,11 @@ static inline TCGReg tcg_regset_first(TCGRegSet d) } } -static void tcg_dump_ops(TCGContext *s, bool have_prefs) +/* Return only the number of characters output -- no error return. */ +#define ne_fprintf(...) \ + ({ int ret_ = fprintf(__VA_ARGS__); ret_ >= 0 ? ret_ : 0; }) + +static void tcg_dump_ops(TCGContext *s, FILE *f, bool have_prefs) { char buf[128]; TCGOp *op; @@ -1820,7 +1827,7 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) if (c == INDEX_op_insn_start) { nb_oargs = 0; - col += qemu_log("\n ----"); + col += ne_fprintf(f, "\n ----"); for (i = 0; i < TARGET_INSN_START_WORDS; ++i) { target_ulong a; @@ -1829,7 +1836,7 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) #else a = op->args[i]; #endif - col += qemu_log(" " TARGET_FMT_lx, a); + col += ne_fprintf(f, " " TARGET_FMT_lx, a); } } else if (c == INDEX_op_call) { const TCGHelperInfo *info = tcg_call_info(op); @@ -1840,7 +1847,7 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) nb_iargs = TCGOP_CALLI(op); nb_cargs = def->nb_cargs; - col += qemu_log(" %s ", def->name); + col += ne_fprintf(f, " %s ", def->name); /* * Print the function name from TCGHelperInfo, if available. @@ -1848,15 +1855,15 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) * but the actual function pointer comes from the plugin. */ if (func == info->func) { - col += qemu_log("%s", info->name); + col += ne_fprintf(f, "%s", info->name); } else { - col += qemu_log("plugin(%p)", func); + col += ne_fprintf(f, "plugin(%p)", func); } - col += qemu_log(",$0x%x,$%d", info->flags, nb_oargs); + col += ne_fprintf(f, ",$0x%x,$%d", info->flags, nb_oargs); for (i = 0; i < nb_oargs; i++) { - col += qemu_log(",%s", tcg_get_arg_str(s, buf, sizeof(buf), - op->args[i])); + col += ne_fprintf(f, ",%s", tcg_get_arg_str(s, buf, sizeof(buf), + op->args[i])); } for (i = 0; i < nb_iargs; i++) { TCGArg arg = op->args[nb_oargs + i]; @@ -1864,34 +1871,32 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) if (arg != TCG_CALL_DUMMY_ARG) { t = tcg_get_arg_str(s, buf, sizeof(buf), arg); } - col += qemu_log(",%s", t); + col += ne_fprintf(f, ",%s", t); } } else { - col += qemu_log(" %s ", def->name); + col += ne_fprintf(f, " %s ", def->name); nb_oargs = def->nb_oargs; nb_iargs = def->nb_iargs; nb_cargs = def->nb_cargs; if (def->flags & TCG_OPF_VECTOR) { - col += qemu_log("v%d,e%d,", 64 << TCGOP_VECL(op), - 8 << TCGOP_VECE(op)); + col += ne_fprintf(f, "v%d,e%d,", 64 << TCGOP_VECL(op), + 8 << TCGOP_VECE(op)); } k = 0; for (i = 0; i < nb_oargs; i++) { - if (k != 0) { - col += qemu_log(","); - } - col += qemu_log("%s", tcg_get_arg_str(s, buf, sizeof(buf), - op->args[k++])); + const char *sep = k ? "," : ""; + col += ne_fprintf(f, "%s%s", sep, + tcg_get_arg_str(s, buf, sizeof(buf), + op->args[k++])); } for (i = 0; i < nb_iargs; i++) { - if (k != 0) { - col += qemu_log(","); - } - col += qemu_log("%s", tcg_get_arg_str(s, buf, sizeof(buf), - op->args[k++])); + const char *sep = k ? "," : ""; + col += ne_fprintf(f, "%s%s", sep, + tcg_get_arg_str(s, buf, sizeof(buf), + op->args[k++])); } switch (c) { case INDEX_op_brcond_i32: @@ -1906,9 +1911,9 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) case INDEX_op_cmpsel_vec: if (op->args[k] < ARRAY_SIZE(cond_name) && cond_name[op->args[k]]) { - col += qemu_log(",%s", cond_name[op->args[k++]]); + col += ne_fprintf(f, ",%s", cond_name[op->args[k++]]); } else { - col += qemu_log(",$0x%" TCG_PRIlx, op->args[k++]); + col += ne_fprintf(f, ",$0x%" TCG_PRIlx, op->args[k++]); } i = 1; break; @@ -1923,12 +1928,12 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) unsigned ix = get_mmuidx(oi); if (op & ~(MO_AMASK | MO_BSWAP | MO_SSIZE)) { - col += qemu_log(",$0x%x,%u", op, ix); + col += ne_fprintf(f, ",$0x%x,%u", op, ix); } else { const char *s_al, *s_op; s_al = alignment_name[(op & MO_AMASK) >> MO_ASHIFT]; s_op = ldst_name[op & (MO_BSWAP | MO_SSIZE)]; - col += qemu_log(",%s%s,%u", s_al, s_op, ix); + col += ne_fprintf(f, ",%s%s,%u", s_al, s_op, ix); } i = 1; } @@ -1946,9 +1951,9 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) name = bswap_flag_name[flags]; } if (name) { - col += qemu_log(",%s", name); + col += ne_fprintf(f, ",%s", name); } else { - col += qemu_log(",$0x%" TCG_PRIlx, flags); + col += ne_fprintf(f, ",$0x%" TCG_PRIlx, flags); } i = k = 1; } @@ -1963,49 +1968,42 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) case INDEX_op_brcond_i32: case INDEX_op_brcond_i64: case INDEX_op_brcond2_i32: - col += qemu_log("%s$L%d", k ? "," : "", - arg_label(op->args[k])->id); + col += ne_fprintf(f, "%s$L%d", k ? "," : "", + arg_label(op->args[k])->id); i++, k++; break; default: break; } for (; i < nb_cargs; i++, k++) { - col += qemu_log("%s$0x%" TCG_PRIlx, k ? "," : "", op->args[k]); + col += ne_fprintf(f, "%s$0x%" TCG_PRIlx, k ? "," : "", + op->args[k]); } } if (have_prefs || op->life) { - - QemuLogFile *logfile; - - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - for (; col < 40; ++col) { - putc(' ', logfile->fd); - } + for (; col < 40; ++col) { + putc(' ', f); } - rcu_read_unlock(); } if (op->life) { unsigned life = op->life; if (life & (SYNC_ARG * 3)) { - qemu_log(" sync:"); + ne_fprintf(f, " sync:"); for (i = 0; i < 2; ++i) { if (life & (SYNC_ARG << i)) { - qemu_log(" %d", i); + ne_fprintf(f, " %d", i); } } } life /= DEAD_ARG; if (life) { - qemu_log(" dead:"); + ne_fprintf(f, " dead:"); for (i = 0; life; ++i, life >>= 1) { if (life & 1) { - qemu_log(" %d", i); + ne_fprintf(f, " %d", i); } } } @@ -2016,28 +2014,28 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs) TCGRegSet set = op->output_pref[i]; if (i == 0) { - qemu_log(" pref="); + ne_fprintf(f, " pref="); } else { - qemu_log(","); + ne_fprintf(f, ","); } if (set == 0) { - qemu_log("none"); + ne_fprintf(f, "none"); } else if (set == MAKE_64BIT_MASK(0, TCG_TARGET_NB_REGS)) { - qemu_log("all"); + ne_fprintf(f, "all"); #ifdef CONFIG_DEBUG_TCG } else if (tcg_regset_single(set)) { TCGReg reg = tcg_regset_first(set); - qemu_log("%s", tcg_target_reg_names[reg]); + ne_fprintf(f, "%s", tcg_target_reg_names[reg]); #endif } else if (TCG_TARGET_NB_REGS <= 32) { - qemu_log("%#x", (uint32_t)set); + ne_fprintf(f, "0x%x", (uint32_t)set); } else { - qemu_log("%#" PRIx64, (uint64_t)set); + ne_fprintf(f, "0x%" PRIx64, (uint64_t)set); } } } - qemu_log("\n"); + putc('\n', f); } } @@ -4200,11 +4198,13 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb) #ifdef DEBUG_DISAS if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP) && qemu_log_in_addr_range(tb->pc))) { - FILE *logfile = qemu_log_lock(); - qemu_log("OP:\n"); - tcg_dump_ops(s, false); - qemu_log("\n"); - qemu_log_unlock(logfile); + FILE *logfile = qemu_log_trylock(); + if (logfile) { + fprintf(logfile, "OP:\n"); + tcg_dump_ops(s, logfile, false); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif @@ -4245,11 +4245,13 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb) #ifdef DEBUG_DISAS if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_IND) && qemu_log_in_addr_range(tb->pc))) { - FILE *logfile = qemu_log_lock(); - qemu_log("OP before indirect lowering:\n"); - tcg_dump_ops(s, false); - qemu_log("\n"); - qemu_log_unlock(logfile); + FILE *logfile = qemu_log_trylock(); + if (logfile) { + fprintf(logfile, "OP before indirect lowering:\n"); + tcg_dump_ops(s, logfile, false); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif /* Replace indirect temps with direct temps. */ @@ -4266,11 +4268,13 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb) #ifdef DEBUG_DISAS if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_OPT) && qemu_log_in_addr_range(tb->pc))) { - FILE *logfile = qemu_log_lock(); - qemu_log("OP after optimization and liveness analysis:\n"); - tcg_dump_ops(s, true); - qemu_log("\n"); - qemu_log_unlock(logfile); + FILE *logfile = qemu_log_trylock(); + if (logfile) { + fprintf(logfile, "OP after optimization and liveness analysis:\n"); + tcg_dump_ops(s, logfile, true); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif diff --git a/tests/unit/test-logging.c b/tests/unit/test-logging.c index 05703a4e51..66dbc82a56 100644 --- a/tests/unit/test-logging.c +++ b/tests/unit/test-logging.c @@ -29,6 +29,7 @@ #include "qapi/error.h" #include "qemu/log.h" +#include "qemu/rcu.h" static void test_parse_range(void) { @@ -109,12 +110,10 @@ static void test_parse_path(gconstpointer data) static void test_logfile_write(gconstpointer data) { - QemuLogFile *logfile; - QemuLogFile *logfile2; + FILE *logfile0, *logfile1; gchar const *dir = data; - g_autofree gchar *file_path = NULL; + g_autofree gchar *file_path0 = NULL; g_autofree gchar *file_path1 = NULL; - FILE *orig_fd; /* * Before starting test, set log flags, to ensure the file gets @@ -122,30 +121,29 @@ static void test_logfile_write(gconstpointer data) * In cases where a logging backend other than log is used, * this is needed. */ - qemu_set_log(CPU_LOG_TB_OUT_ASM); - file_path = g_build_filename(dir, "qemu_test_log_write0.log", NULL); + qemu_set_log(CPU_LOG_TB_OUT_ASM, &error_abort); + file_path0 = g_build_filename(dir, "qemu_test_log_write0.log", NULL); file_path1 = g_build_filename(dir, "qemu_test_log_write1.log", NULL); /* * Test that even if an open file handle is changed, * our handle remains valid due to RCU. */ - qemu_set_log_filename(file_path, &error_abort); - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - orig_fd = logfile->fd; - g_assert(logfile && logfile->fd); - fprintf(logfile->fd, "%s 1st write to file\n", __func__); - fflush(logfile->fd); + qemu_set_log_filename(file_path0, &error_abort); + logfile0 = qemu_log_trylock(); + g_assert(logfile0); + fprintf(logfile0, "%s 1st write to file\n", __func__); + fflush(logfile0); /* Change the logfile and ensure that the handle is still valid. */ qemu_set_log_filename(file_path1, &error_abort); - logfile2 = qatomic_rcu_read(&qemu_logfile); - g_assert(logfile->fd == orig_fd); - g_assert(logfile2->fd != logfile->fd); - fprintf(logfile->fd, "%s 2nd write to file\n", __func__); - fflush(logfile->fd); - rcu_read_unlock(); + logfile1 = qemu_log_trylock(); + g_assert(logfile1); + g_assert(logfile0 != logfile1); + fprintf(logfile0, "%s 2nd write to file\n", __func__); + fflush(logfile0); + qemu_log_unlock(logfile0); + qemu_log_unlock(logfile1); } static void test_logfile_lock(gconstpointer data) @@ -162,7 +160,7 @@ static void test_logfile_lock(gconstpointer data) * our handle remains valid for use due to RCU. */ qemu_set_log_filename(file_path, &error_abort); - logfile = qemu_log_lock(); + logfile = qemu_log_trylock(); g_assert(logfile); fprintf(logfile, "%s 1st write to file\n", __func__); fflush(logfile); @@ -171,7 +169,7 @@ static void test_logfile_lock(gconstpointer data) * Initiate a close file and make sure our handle remains * valid since we still have the logfile lock. */ - qemu_log_close(); + qemu_set_log_filename_flags(NULL, 0, &error_abort); fprintf(logfile, "%s 2nd write to file\n", __func__); fflush(logfile); qemu_log_unlock(logfile); @@ -209,7 +207,7 @@ int main(int argc, char **argv) tmp_path, test_logfile_lock); rc = g_test_run(); - qemu_log_close(); + qemu_set_log_filename_flags(NULL, 0, &error_abort); drain_call_rcu(); rmdir_full(tmp_path); diff --git a/util/log.c b/util/log.c index 2ee1500bee..d6eb0378c3 100644 --- a/util/log.c +++ b/util/log.c @@ -26,153 +26,290 @@ #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 char *logfilename; -static QemuMutex qemu_logfile_mutex; -QemuLogFile *qemu_logfile; int qemu_loglevel; -static int log_append = 0; +static bool log_append; +static bool log_per_thread; static GArray *debug_regions; -/* Return the number of characters emitted. */ -int qemu_log(const char *fmt, ...) +/* 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) { - int ret = 0; - QemuLogFile *logfile; + 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 +} + +/* Lock/unlock output. */ + +FILE *qemu_log_trylock(void) +{ + 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) { + return NULL; + } + thread_file = logfile; + } 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; +} - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); +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); - ret = vfprintf(logfile->fd, fmt, ap); + vfprintf(f, fmt, ap); va_end(ap); - - /* Don't pass back error results. */ - if (ret < 0) { - ret = 0; - } + qemu_log_unlock(f); } - rcu_read_unlock(); - return ret; } -static void __attribute__((__constructor__)) qemu_logfile_init(void) +static void __attribute__((__constructor__)) startup(void) { - qemu_mutex_init(&qemu_logfile_mutex); + qemu_mutex_init(&global_mutex); } -static void qemu_logfile_free(QemuLogFile *logfile) +static void rcu_close_file(RCUCloseFILE *r) { - g_assert(logfile); + 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; - if (logfile->fd != stderr) { - fclose(logfile->fd); +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; } - g_free(logfile); + return filename ? vft_strdup : vft_stderr; } -static bool log_uses_own_buffers; - /* enable or disable low levels log */ -void qemu_set_log(int log_flags) +static bool qemu_set_log_internal(const char *filename, bool changed_name, + int log_flags, Error **errp) { - bool need_to_open_file = false; - QemuLogFile *logfile; + bool need_to_open_file; + bool daemonized; + bool per_thread; + FILE *logfile; + + QEMU_LOCK_GUARD(&global_mutex); + logfile = global_file; + + 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; + } - qemu_loglevel = log_flags; + 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 - qemu_loglevel |= LOG_TRACE; + log_flags |= LOG_TRACE; #endif + qemu_loglevel = log_flags; + /* * In all cases we only log if qemu_loglevel is set. * Also: + * If per-thread, open the file for each thread in qemu_log_lock. * If not daemonized we will always log either to stderr - * or to a file (if there is a logfilename). - * If we are daemonized, - * we will only log if there is a logfilename. + * or to a file (if there is a filename). + * If we are daemonized, we will only log if there is a filename. */ - if (qemu_loglevel && (!is_daemonized() || logfilename)) { - need_to_open_file = true; + daemonized = is_daemonized(); + need_to_open_file = log_flags && !per_thread && (!daemonized || filename); + + if (logfile && (!need_to_open_file || changed_name)) { + qatomic_rcu_set(&global_file, NULL); + if (logfile != stderr) { + RCUCloseFILE *r = g_new0(RCUCloseFILE, 1); + r->fd = logfile; + call_rcu(r, rcu_close_file, rcu); + } + logfile = NULL; } - QEMU_LOCK_GUARD(&qemu_logfile_mutex); - if (qemu_logfile && !need_to_open_file) { - logfile = qemu_logfile; - qatomic_rcu_set(&qemu_logfile, NULL); - call_rcu(logfile, qemu_logfile_free, rcu); - } else if (!qemu_logfile && need_to_open_file) { - logfile = g_new0(QemuLogFile, 1); - if (logfilename) { - logfile->fd = fopen(logfilename, log_append ? "a" : "w"); - if (!logfile->fd) { - g_free(logfile); - perror(logfilename); - _exit(1); + + if (!logfile && need_to_open_file) { + if (filename) { + logfile = fopen(filename, log_append ? "a" : "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 (is_daemonized()) { - dup2(fileno(logfile->fd), STDERR_FILENO); - fclose(logfile->fd); - /* This will skip closing logfile in qemu_log_close() */ - logfile->fd = stderr; + if (daemonized) { + dup2(fileno(logfile), STDERR_FILENO); + fclose(logfile); + /* This will skip closing logfile in rcu_close_file. */ + logfile = stderr; } } else { /* Default to stderr if no log file specified */ - assert(!is_daemonized()); - logfile->fd = stderr; + assert(!daemonized); + logfile = stderr; } - /* must avoid mmap() usage of glibc by setting a buffer "by hand" */ - if (log_uses_own_buffers) { - static char logfile_buf[4096]; - setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf)); - } else { -#if defined(_WIN32) - /* Win32 doesn't support line-buffering, so use unbuffered output. */ - setvbuf(logfile->fd, NULL, _IONBF, 0); -#else - setvbuf(logfile->fd, NULL, _IOLBF, 0); -#endif - log_append = 1; - } - qatomic_rcu_set(&qemu_logfile, logfile); + log_append = 1; + + qatomic_rcu_set(&global_file, logfile); } + return true; } -void qemu_log_needs_buffers(void) +bool qemu_set_log(int log_flags, Error **errp) { - log_uses_own_buffers = true; + return qemu_set_log_internal(NULL, false, log_flags, errp); } -/* - * Allow the user to include %d in their logfile which will be - * substituted with the current PID. This is useful for debugging many - * nested linux-user tasks but will result in lots of logs. - * - * filename may be NULL. In that case, log output is sent to stderr - */ -void qemu_set_log_filename(const char *filename, Error **errp) +bool qemu_set_log_filename(const char *filename, Error **errp) { - g_free(logfilename); - logfilename = NULL; - - 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 format: %s", filename); - return; - } else { - logfilename = g_strdup_printf(filename, getpid()); - } - } else { - logfilename = g_strdup(filename); - } - } + return qemu_set_log_internal(filename, true, qemu_loglevel, errp); +} - qemu_log_close(); - qemu_set_log(qemu_loglevel); +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 @@ -266,34 +403,6 @@ out: g_strfreev(ranges); } -/* fflush() the log file */ -void qemu_log_flush(void) -{ - QemuLogFile *logfile; - - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - fflush(logfile->fd); - } - rcu_read_unlock(); -} - -/* Close the log file */ -void qemu_log_close(void) -{ - QemuLogFile *logfile; - - qemu_mutex_lock(&qemu_logfile_mutex); - logfile = qemu_logfile; - - if (logfile) { - qatomic_rcu_set(&qemu_logfile, NULL); - call_rcu(logfile, qemu_logfile_free, rcu); - } - qemu_mutex_unlock(&qemu_logfile_mutex); -} - const QEMULogItem qemu_log_items[] = { { CPU_LOG_TB_OUT_ASM, "out_asm", "show generated host assembly code for each compiled TB" }, @@ -334,6 +443,8 @@ const QEMULogItem qemu_log_items[] = { #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'" }, { 0, NULL, NULL }, }; |