From 78b548583e0725bb7054162a31dac552b01c02a8 Mon Sep 17 00:00:00 2001 From: Richard Henderson Date: Sun, 17 Apr 2022 11:29:49 -0700 Subject: *: Use fprintf between qemu_log_trylock/unlock MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Inside qemu_log, we perform qemu_log_trylock/unlock, which need not be done if we have already performed the lock beforehand. Always check the result of qemu_log_trylock -- only checking qemu_loglevel_mask races with the acquisition of the lock on the logfile. Reviewed-by: Alex Bennée Signed-off-by: Richard Henderson Message-Id: <20220417183019.755276-10-richard.henderson@linaro.org> --- accel/tcg/cpu-exec.c | 16 +++--- accel/tcg/translate-all.c | 115 +++++++++++++++++++++++--------------------- accel/tcg/translator.c | 10 ++-- cpu.c | 14 +++--- hw/net/can/can_sja1000.c | 28 ++++++----- include/exec/log.h | 2 +- net/can/can_socketcan.c | 25 +++++----- target/i386/tcg/translate.c | 14 +++--- tcg/tcg.c | 78 +++++++++++++++++------------- 9 files changed, 166 insertions(+), 136 deletions(-) diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c index f61b056..8b7f9a3 100644 --- a/accel/tcg/cpu-exec.c +++ b/accel/tcg/cpu-exec.c @@ -215,16 +215,18 @@ 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_trylock(); - int flags = 0; + 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); + log_cpu_state(cpu, flags); + qemu_log_unlock(logfile); + } } #endif /* DEBUG_DISAS */ } diff --git a/accel/tcg/translate-all.c b/accel/tcg/translate-all.c index 5937d6b..6230f3c 100644 --- a/accel/tcg/translate-all.c +++ b/accel/tcg/translate-all.c @@ -1528,68 +1528,75 @@ TranslationBlock *tb_gen_code(CPUState *cpu, if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM) && qemu_log_in_addr_range(tb->pc)) { FILE *logfile = qemu_log_trylock(); - 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; - } + 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_flush(); + 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 1506755..af8798f 100644 --- a/accel/tcg/translator.c +++ b/accel/tcg/translator.c @@ -140,10 +140,12 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db, if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(db->pc_first)) { FILE *logfile = qemu_log_trylock(); - qemu_log("----------------\n"); - ops->disas_log(db, cpu); - qemu_log("\n"); - qemu_log_unlock(logfile); + if (logfile) { + fprintf(logfile, "----------------\n"); + ops->disas_log(db, cpu); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif } diff --git a/cpu.c b/cpu.c index 9db1447..ded4173 100644 --- a/cpu.c +++ b/cpu.c @@ -400,12 +400,14 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...) cpu_dump_state(cpu, stderr, CPU_DUMP_FPU | CPU_DUMP_CCOP); if (qemu_log_separate()) { FILE *logfile = qemu_log_trylock(); - 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); + 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_flush(); + qemu_log_unlock(logfile); + } qemu_log_close(); } va_end(ap2); diff --git a/hw/net/can/can_sja1000.c b/hw/net/can/can_sja1000.c index 300313d..23d634a 100644 --- a/hw/net/can/can_sja1000.c +++ b/hw/net/can/can_sja1000.c @@ -249,19 +249,21 @@ static void can_display_msg(const char *prefix, const qemu_can_frame *msg) int i; FILE *logfile = qemu_log_trylock(); - 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]); - } - qemu_log("\n"); - qemu_log_flush(); - qemu_log_unlock(logfile); + 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_flush(); + qemu_log_unlock(logfile); + } } static void buff2frame_pel(const uint8_t *buff, qemu_can_frame *frame) diff --git a/include/exec/log.h b/include/exec/log.h index fb595d1..648f4d2 100644 --- a/include/exec/log.h +++ b/include/exec/log.h @@ -73,7 +73,7 @@ static inline void log_page_dump(const char *operation) { FILE *logfile = qemu_log_trylock(); if (logfile) { - qemu_log("page layout changed following %s\n", operation); + fprintf(logfile, "page layout changed following %s\n", operation); page_dump(logfile); } qemu_log_unlock(logfile); diff --git a/net/can/can_socketcan.c b/net/can/can_socketcan.c index 4a50564..a638856 100644 --- a/net/can/can_socketcan.c +++ b/net/can/can_socketcan.c @@ -77,18 +77,21 @@ static void can_host_socketcan_display_msg(struct qemu_can_frame *msg) { int i; FILE *logfile = qemu_log_trylock(); - 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]); + + 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_flush(); + 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/target/i386/tcg/translate.c b/target/i386/tcg/translate.c index f3cffee..bfd0f5b 100644 --- a/target/i386/tcg/translate.c +++ b/target/i386/tcg/translate.c @@ -2581,14 +2581,16 @@ static void gen_unknown_opcode(CPUX86State *env, DisasContext *s) if (qemu_loglevel_mask(LOG_UNIMP)) { FILE *logfile = qemu_log_trylock(); - target_ulong pc = s->pc_start, end = s->pc; + 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); } } diff --git a/tcg/tcg.c b/tcg/tcg.c index abe4ef7..d0e47e5 100644 --- a/tcg/tcg.c +++ b/tcg/tcg.c @@ -757,31 +757,35 @@ void tcg_prologue_init(TCGContext *s) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) { FILE *logfile = qemu_log_trylock(); - 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)); + 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_flush(); + qemu_log_unlock(logfile); } - qemu_log("\n"); - qemu_log_flush(); - qemu_log_unlock(logfile); } #endif @@ -4201,10 +4205,12 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb) if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP) && qemu_log_in_addr_range(tb->pc))) { FILE *logfile = qemu_log_trylock(); - qemu_log("OP:\n"); - tcg_dump_ops(s, false); - qemu_log("\n"); - qemu_log_unlock(logfile); + if (logfile) { + fprintf(logfile, "OP:\n"); + tcg_dump_ops(s, false); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif @@ -4246,10 +4252,12 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb) if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_IND) && qemu_log_in_addr_range(tb->pc))) { FILE *logfile = qemu_log_trylock(); - qemu_log("OP before indirect lowering:\n"); - tcg_dump_ops(s, false); - qemu_log("\n"); - qemu_log_unlock(logfile); + if (logfile) { + fprintf(logfile, "OP before indirect lowering:\n"); + tcg_dump_ops(s, false); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif /* Replace indirect temps with direct temps. */ @@ -4267,10 +4275,12 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb) if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_OPT) && qemu_log_in_addr_range(tb->pc))) { FILE *logfile = qemu_log_trylock(); - qemu_log("OP after optimization and liveness analysis:\n"); - tcg_dump_ops(s, true); - qemu_log("\n"); - qemu_log_unlock(logfile); + if (logfile) { + fprintf(logfile, "OP after optimization and liveness analysis:\n"); + tcg_dump_ops(s, true); + fprintf(logfile, "\n"); + qemu_log_unlock(logfile); + } } #endif -- cgit v1.1