[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [Qemu-devel] [PATCH 4/4] log: Add locking to large logging blocks
|
From: |
Paolo Bonzini |
|
Subject: |
Re: [Qemu-devel] [PATCH 4/4] log: Add locking to large logging blocks |
|
Date: |
Sat, 24 Sep 2016 15:12:08 +0200 |
|
User-agent: |
Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.3.0 |
On 23/09/2016 17:29, Richard Henderson wrote:
> 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 <address@hidden>
> Cc: Alex Bennee <address@hidden>
> Signed-off-by: Richard Henderson <address@hidden>
> ---
> 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
>
>
Reviewed-by: Paolo Bonzini <address@hidden>
- [Qemu-devel] [PATCH 1/4] target-cris: Do not dump cpu state with -d in_asm, Richard Henderson, 2016/09/23
- [Qemu-devel] [PATCH 3/4] target-openrisc: Do not dump cpu state with -d in_asm, Richard Henderson, 2016/09/23
- [Qemu-devel] [PATCH 2/4] target-microblaze: Do not dump cpu state with -d in_asm, Richard Henderson, 2016/09/23
- [Qemu-devel] [PATCH 4/4] log: Add locking to large logging blocks, Richard Henderson, 2016/09/23
- Re: [Qemu-devel] [PATCH 4/4] log: Add locking to large logging blocks,
Paolo Bonzini <=
- Re: [Qemu-devel] [PATCH 1/4] target-cris: Do not dump cpu state with -d in_asm, Edgar E. Iglesias, 2016/09/23
- Re: [Qemu-devel] [PATCH 1/4] target-cris: Do not dump cpu state with -d in_asm, Alex Bennée, 2016/09/26