From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:44772) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1bnSQ9-0007BP-9y for qemu-devel@nongnu.org; Fri, 23 Sep 2016 11:29:51 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1bnSQ6-0001xj-UA for qemu-devel@nongnu.org; Fri, 23 Sep 2016 11:29:49 -0400 Received: from mail-io0-x241.google.com ([2607:f8b0:4001:c06::241]:35656) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1bnSQ6-0001xQ-N7 for qemu-devel@nongnu.org; Fri, 23 Sep 2016 11:29:46 -0400 Received: by mail-io0-x241.google.com with SMTP id 92so1952180iom.2 for ; Fri, 23 Sep 2016 08:29:46 -0700 (PDT) Sender: Richard Henderson From: Richard Henderson Date: Fri, 23 Sep 2016 08:29:11 -0700 Message-Id: <1474644551-5819-4-git-send-email-rth@twiddle.net> In-Reply-To: <1474644551-5819-1-git-send-email-rth@twiddle.net> References: <1474644551-5819-1-git-send-email-rth@twiddle.net> Subject: [Qemu-devel] [PATCH 4/4] log: Add locking to large logging blocks List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: qemu-devel@nongnu.org Cc: Paolo Bonzini , Alex Bennee Reuse the existing locking provided by stdio to keep in_asm, cpu, op, op_opt, op_ind, and out_asm as contiguous blocks. While it isn't possible to interleave e.g. in_asm or op_opt logs because of the TB lock protecting all code generation, it is possible to interleave cpu logs, or to interleave a cpu dump with an out_asm dump. Cc: Paolo Bonzini Cc: Alex Bennee Signed-off-by: Richard Henderson --- cpu-exec.c | 2 ++ exec.c | 2 ++ include/qemu/log.h | 16 ++++++++++++++++ target-alpha/translate.c | 2 ++ target-arm/translate-a64.c | 2 ++ target-arm/translate.c | 2 ++ target-cris/translate.c | 2 ++ target-i386/translate.c | 4 ++++ target-lm32/translate.c | 2 ++ target-m68k/translate.c | 2 ++ target-microblaze/translate.c | 2 ++ target-mips/translate.c | 2 ++ target-openrisc/translate.c | 2 ++ target-ppc/translate.c | 2 ++ target-s390x/translate.c | 2 ++ target-sh4/translate.c | 2 ++ target-sparc/translate.c | 2 ++ target-tilegx/translate.c | 6 +++++- target-tricore/translate.c | 2 ++ target-unicore32/translate.c | 2 ++ target-xtensa/translate.c | 2 ++ tcg/tcg.c | 8 ++++++++ translate-all.c | 2 ++ 23 files changed, 71 insertions(+), 1 deletion(-) diff --git a/cpu-exec.c b/cpu-exec.c index 9f4bd0b..7423049 100644 --- a/cpu-exec.c +++ b/cpu-exec.c @@ -149,6 +149,7 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb) #if defined(DEBUG_DISAS) if (qemu_loglevel_mask(CPU_LOG_TB_CPU) && qemu_log_in_addr_range(itb->pc)) { + qemu_log_lock(); #if defined(TARGET_I386) log_cpu_state(cpu, CPU_DUMP_CCOP); #elif defined(TARGET_M68K) @@ -160,6 +161,7 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb) #else log_cpu_state(cpu, 0); #endif + qemu_log_unlock(); } #endif /* DEBUG_DISAS */ diff --git a/exec.c b/exec.c index c81d5ab..f8ed786 100644 --- a/exec.c +++ b/exec.c @@ -905,11 +905,13 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...) fprintf(stderr, "\n"); cpu_dump_state(cpu, stderr, fprintf, CPU_DUMP_FPU | CPU_DUMP_CCOP); if (qemu_log_separate()) { + 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(); qemu_log_close(); } va_end(ap2); diff --git a/include/qemu/log.h b/include/qemu/log.h index 00bf37f..aba3301 100644 --- a/include/qemu/log.h +++ b/include/qemu/log.h @@ -51,6 +51,22 @@ static inline bool qemu_loglevel_mask(int mask) return (qemu_loglevel & mask) != 0; } +/* 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. + */ + +static inline void qemu_log_lock(void) +{ + flockfile(qemu_logfile); +} + +static inline void qemu_log_unlock(void) +{ + funlockfile(qemu_logfile); +} + /* Logging functions: */ /* main logging function diff --git a/target-alpha/translate.c b/target-alpha/translate.c index c27c7b9..af717ca 100644 --- a/target-alpha/translate.c +++ b/target-alpha/translate.c @@ -3000,9 +3000,11 @@ void gen_intermediate_code(CPUAlphaState *env, struct TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, ctx.pc - pc_start, 1); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-arm/translate-a64.c b/target-arm/translate-a64.c index ddf52f5..60e8cf1 100644 --- a/target-arm/translate-a64.c +++ b/target-arm/translate-a64.c @@ -11356,11 +11356,13 @@ done_generating: #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc->pc - pc_start, 4 | (bswap_code(dc->sctlr_b) ? 2 : 0)); qemu_log("\n"); + qemu_log_unlock(); } #endif tb->size = dc->pc - pc_start; diff --git a/target-arm/translate.c b/target-arm/translate.c index 693d4bc..f550b00 100644 --- a/target-arm/translate.c +++ b/target-arm/translate.c @@ -11998,11 +11998,13 @@ done_generating: #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc->pc - pc_start, dc->thumb | (dc->sctlr_b << 1)); qemu_log("\n"); + qemu_log_unlock(); } #endif tb->size = dc->pc - pc_start; diff --git a/target-cris/translate.c b/target-cris/translate.c index 9de26af..81147bb 100644 --- a/target-cris/translate.c +++ b/target-cris/translate.c @@ -3290,12 +3290,14 @@ void gen_intermediate_code(CPUCRISState *env, struct TranslationBlock *tb) #if !DISAS_CRIS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("--------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc->pc - pc_start, env->pregs[PR_VR]); qemu_log("\nisize=%d osize=%d\n", dc->pc - pc_start, tcg_op_buf_count()); + qemu_log_unlock(); } #endif #endif diff --git a/target-i386/translate.c b/target-i386/translate.c index 9447557..2f60e9c 100644 --- a/target-i386/translate.c +++ b/target-i386/translate.c @@ -2391,11 +2391,13 @@ static void gen_unknown_opcode(CPUX86State *env, DisasContext *s) if (qemu_loglevel_mask(LOG_UNIMP)) { target_ulong pc = s->pc_start, end = s->pc; + qemu_log_lock(); qemu_log("ILLOPC: " TARGET_FMT_lx ":", pc); for (; pc < end; ++pc) { qemu_log(" %02x", cpu_ldub_code(env, pc)); } qemu_log("\n"); + qemu_log_unlock(); } } @@ -8362,6 +8364,7 @@ done_generating: if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { int disas_flags; + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); #ifdef TARGET_X86_64 @@ -8372,6 +8375,7 @@ done_generating: disas_flags = !dc->code32; log_target_disas(cs, pc_start, pc_ptr - pc_start, disas_flags); qemu_log("\n"); + qemu_log_unlock(); } #endif diff --git a/target-lm32/translate.c b/target-lm32/translate.c index 2d8caeb..3d2cecb 100644 --- a/target-lm32/translate.c +++ b/target-lm32/translate.c @@ -1149,10 +1149,12 @@ void gen_intermediate_code(CPULM32State *env, struct TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("\n"); log_target_disas(cs, pc_start, dc->pc - pc_start, 0); qemu_log("\nisize=%d osize=%d\n", dc->pc - pc_start, tcg_op_buf_count()); + qemu_log_unlock(); } #endif } diff --git a/target-m68k/translate.c b/target-m68k/translate.c index ecd5e5c..43b9ea1 100644 --- a/target-m68k/translate.c +++ b/target-m68k/translate.c @@ -3070,10 +3070,12 @@ void gen_intermediate_code(CPUM68KState *env, TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc->pc - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif tb->size = dc->pc - pc_start; diff --git a/target-microblaze/translate.c b/target-microblaze/translate.c index 5a4a8b9..5274191 100644 --- a/target-microblaze/translate.c +++ b/target-microblaze/translate.c @@ -1813,12 +1813,14 @@ void gen_intermediate_code(CPUMBState *env, struct TranslationBlock *tb) #if !SIM_COMPAT if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("--------------\n"); #if DISAS_GNU log_target_disas(cs, pc_start, dc->pc - pc_start, 0); #endif qemu_log("\nisize=%d osize=%d\n", dc->pc - pc_start, tcg_op_buf_count()); + qemu_log_unlock(); } #endif #endif diff --git a/target-mips/translate.c b/target-mips/translate.c index bab52cb..3172f12 100644 --- a/target-mips/translate.c +++ b/target-mips/translate.c @@ -20015,9 +20015,11 @@ done_generating: LOG_DISAS("\n"); if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, ctx.pc - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-openrisc/translate.c b/target-openrisc/translate.c index a4625f9..229361a 100644 --- a/target-openrisc/translate.c +++ b/target-openrisc/translate.c @@ -1750,11 +1750,13 @@ void gen_intermediate_code(CPUOpenRISCState *env, struct TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc->pc - pc_start, 0); qemu_log("\nisize=%d osize=%d\n", dc->pc - pc_start, tcg_op_buf_count()); + qemu_log_unlock(); } #endif } diff --git a/target-ppc/translate.c b/target-ppc/translate.c index 618334a..6614094 100644 --- a/target-ppc/translate.c +++ b/target-ppc/translate.c @@ -7174,9 +7174,11 @@ void gen_intermediate_code(CPUPPCState *env, struct TranslationBlock *tb) int flags; flags = env->bfd_mach; flags |= ctx.le_mode << 16; + qemu_log_lock(); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, ctx.nip - pc_start, flags); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-s390x/translate.c b/target-s390x/translate.c index 1a07d70..02bc705 100644 --- a/target-s390x/translate.c +++ b/target-s390x/translate.c @@ -5432,9 +5432,11 @@ void gen_intermediate_code(CPUS390XState *env, struct TranslationBlock *tb) #if defined(S390X_DEBUG_DISAS) if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc.pc - pc_start, 1); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-sh4/translate.c b/target-sh4/translate.c index ca80cf7..c89a147 100644 --- a/target-sh4/translate.c +++ b/target-sh4/translate.c @@ -1927,9 +1927,11 @@ void gen_intermediate_code(CPUSH4State * env, struct TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("IN:\n"); /* , lookup_symbol(pc_start)); */ log_target_disas(cs, pc_start, ctx.pc - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-sparc/translate.c b/target-sparc/translate.c index e7691e4..dc505f7 100644 --- a/target-sparc/translate.c +++ b/target-sparc/translate.c @@ -5672,10 +5672,12 @@ void gen_intermediate_code(CPUSPARCState * env, TranslationBlock * tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("--------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, last_pc + 4 - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-tilegx/translate.c b/target-tilegx/translate.c index 11c9732..9c734ee 100644 --- a/target-tilegx/translate.c +++ b/target-tilegx/translate.c @@ -2391,6 +2391,7 @@ void gen_intermediate_code(CPUTLGState *env, struct TranslationBlock *tb) TCGV_UNUSED_I64(dc->zero); if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)) { + qemu_log_lock(); qemu_log("IN: %s\n", lookup_symbol(pc_start)); } if (!max_insns) { @@ -2429,7 +2430,10 @@ void gen_intermediate_code(CPUTLGState *env, struct TranslationBlock *tb) tb->size = dc->pc - pc_start; tb->icount = num_insns; - qemu_log_mask(CPU_LOG_TB_IN_ASM, "\n"); + if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)) { + qemu_log("\n"); + qemu_log_unlock(); + } } void restore_state_to_opc(CPUTLGState *env, TranslationBlock *tb, diff --git a/target-tricore/translate.c b/target-tricore/translate.c index 9a50df9..36f734a 100644 --- a/target-tricore/translate.c +++ b/target-tricore/translate.c @@ -8789,9 +8789,11 @@ void gen_intermediate_code(CPUTriCoreState *env, struct TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, ctx.pc - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif } diff --git a/target-unicore32/translate.c b/target-unicore32/translate.c index 09354f9..514d460 100644 --- a/target-unicore32/translate.c +++ b/target-unicore32/translate.c @@ -2024,10 +2024,12 @@ done_generating: #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc->pc - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif tb->size = dc->pc - pc_start; diff --git a/target-xtensa/translate.c b/target-xtensa/translate.c index 4c1e487..afbfa57 100644 --- a/target-xtensa/translate.c +++ b/target-xtensa/translate.c @@ -3156,10 +3156,12 @@ void gen_intermediate_code(CPUXtensaState *env, TranslationBlock *tb) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) && qemu_log_in_addr_range(pc_start)) { + qemu_log_lock(); qemu_log("----------------\n"); qemu_log("IN: %s\n", lookup_symbol(pc_start)); log_target_disas(cs, pc_start, dc.pc - pc_start, 0); qemu_log("\n"); + qemu_log_unlock(); } #endif tb->size = dc.pc - pc_start; diff --git a/tcg/tcg.c b/tcg/tcg.c index 2d3e498..aabf94f 100644 --- a/tcg/tcg.c +++ b/tcg/tcg.c @@ -412,10 +412,12 @@ void tcg_prologue_init(TCGContext *s) #ifdef DEBUG_DISAS if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) { + qemu_log_lock(); qemu_log("PROLOGUE: [size=%zu]\n", prologue_size); log_disas(buf0, prologue_size); qemu_log("\n"); qemu_log_flush(); + qemu_log_unlock(); } #endif } @@ -2542,9 +2544,11 @@ 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))) { + qemu_log_lock(); qemu_log("OP:\n"); tcg_dump_ops(s); qemu_log("\n"); + qemu_log_unlock(); } #endif @@ -2570,9 +2574,11 @@ 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))) { + qemu_log_lock(); qemu_log("OP before indirect lowering:\n"); tcg_dump_ops(s); qemu_log("\n"); + qemu_log_unlock(); } #endif /* Replace indirect temps with direct temps. */ @@ -2590,9 +2596,11 @@ 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))) { + qemu_log_lock(); qemu_log("OP after optimization and liveness analysis:\n"); tcg_dump_ops(s); qemu_log("\n"); + qemu_log_unlock(); } #endif diff --git a/translate-all.c b/translate-all.c index e9bc90c..68f984d 100644 --- a/translate-all.c +++ b/translate-all.c @@ -1242,10 +1242,12 @@ 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)) { + qemu_log_lock(); qemu_log("OUT: [size=%d]\n", gen_code_size); log_disas(tb->tc_ptr, gen_code_size); qemu_log("\n"); qemu_log_flush(); + qemu_log_unlock(); } #endif -- 2.7.4