]> git.proxmox.com Git - mirror_qemu.git/commitdiff
log: Add locking to large logging blocks
authorRichard Henderson <rth@twiddle.net>
Thu, 22 Sep 2016 22:17:10 +0000 (15:17 -0700)
committerRichard Henderson <rth@twiddle.net>
Tue, 1 Nov 2016 16:29:03 +0000 (10:29 -0600)
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.

For mingw32, we appear to have no viable solution for this.  The locking
functions are not properly exported from the system runtime library.

Reviewed-by: Paolo Bonzini <pbonzini@redhat.com>
Signed-off-by: Richard Henderson <rth@twiddle.net>
25 files changed:
cpu-exec.c
exec.c
include/qemu/log.h
include/sysemu/os-posix.h
include/sysemu/os-win32.h
target-alpha/translate.c
target-arm/translate-a64.c
target-arm/translate.c
target-cris/translate.c
target-i386/translate.c
target-lm32/translate.c
target-m68k/translate.c
target-microblaze/translate.c
target-mips/translate.c
target-openrisc/translate.c
target-ppc/translate.c
target-s390x/translate.c
target-sh4/translate.c
target-sparc/translate.c
target-tilegx/translate.c
target-tricore/translate.c
target-unicore32/translate.c
target-xtensa/translate.c
tcg/tcg.c
translate-all.c

index 3e408865a85f5d618de47331c76531d101fab437..4188fed3c62c66545f515cb41401441360164588 100644 (file)
@@ -150,11 +150,13 @@ 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);
 #else
         log_cpu_state(cpu, 0);
 #endif
+        qemu_log_unlock();
     }
 #endif /* DEBUG_DISAS */
 
diff --git a/exec.c b/exec.c
index 4d085812cac63c2356ce39560a67cb86f58070dc..b1094c0cd2d68d885dda3bd8587800c5ec182219 100644 (file)
--- a/exec.c
+++ b/exec.c
@@ -911,11 +911,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);
index 00bf37fc0f9a7036f5b242ac2c780178e34ef987..a50e994c21fba2f7119b7501ca949d2e9caff7ea 100644 (file)
@@ -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)
+{
+    qemu_flockfile(qemu_logfile);
+}
+
+static inline void qemu_log_unlock(void)
+{
+    qemu_funlockfile(qemu_logfile);
+}
+
 /* Logging functions: */
 
 /* main logging function
index 3cfedbc28baaf2feee0dbbb958d506e674a61ae1..b0a6c0695b17c4d7015fb68bfda905af03fc6d71 100644 (file)
@@ -87,4 +87,16 @@ void *qemu_alloc_stack(size_t *sz);
  */
 void qemu_free_stack(void *stack, size_t sz);
 
+/* POSIX and Mingw32 differ in the name of the stdio lock functions.  */
+
+static inline void qemu_flockfile(FILE *f)
+{
+    flockfile(f);
+}
+
+static inline void qemu_funlockfile(FILE *f)
+{
+    funlockfile(f);
+}
+
 #endif
index 17aad3b20f012df47a552cd86fc1178151e747d9..ff18b23db148fbb74bd370d83aae8aaefe6b2227 100644 (file)
@@ -103,6 +103,21 @@ 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.
+ */
+
+static inline void qemu_flockfile(FILE *f)
+{
+}
+
+static inline void qemu_funlockfile(FILE *f)
+{
+}
 
 /* We wrap all the sockets functions so that we can
  * set errno based on WSAGetLastError()
index 03e47765edc6c5e55b15de9d87552fd81c2a92f0..114927b751c2e3efc543575ba268d3f0d91d4cdb 100644 (file)
@@ -2994,9 +2994,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
 }
index ded924a0a90382bedb2509bce96503d9dc5faf62..de48747376b5960e995a29610bb440f7325ee27b 100644 (file)
@@ -11420,11 +11420,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;
index 718f7d06f384b762e401ad32baca3fc39c61580d..0ad9070b45aa85fa2235939b35893762e150b711 100644 (file)
@@ -11963,11 +11963,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;
index 8d4c864526531048cb91ff0e88b8040b78334b35..b91042743fea95d815d1246b32aa1615b01849b7 100644 (file)
@@ -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
index 927b3665341f9b6f43ec4752596715512e393ff8..324103c88521a43aa42bf3d3f6b23ef6e6b94eb6 100644 (file)
@@ -2432,11 +2432,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();
     }
 }
 
@@ -8470,6 +8472,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
@@ -8480,6 +8483,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
 
index 842af63a989b61d88195c8e5b062f178dd83548c..692882f4474ab66fe9c7691af5e7c78909f5b86a 100644 (file)
@@ -1148,10 +1148,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
 }
index ee0ffe3e07e2290d72cd574d712249003b02bf8d..9ad974f86a587edf81a4eb119d275a20e88c3609 100644 (file)
@@ -3549,10 +3549,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;
index 5a4a8b9a81c8e4e6b058690db03db236792b72c6..5274191ce38069d20bde7f9fb925cf306ade2165 100644 (file)
@@ -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
index 55c2ca0c7b4e8c95c0cde15cbe26b491a4154368..d8dde7a2f575a564f0ac6b8dbe7db14a7cb33b85 100644 (file)
@@ -20043,9 +20043,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
 }
index a4625f9b6f682f3bf891bcbdd4511654e5681941..229361aed18ed7979f1c4033b38411513668f8fd 100644 (file)
@@ -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
 }
index 43505a936c14688c0604c692118982a3e05f6015..54f35e9904e9ebf7486d72b69a4b7ba57013e356 100644 (file)
@@ -7211,9 +7211,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
 }
index 1a07d70b211a29345e218864e37649c62ff0bdea..02bc7058fdb423c8f11cf8a99b47a8fb11e34f54 100644 (file)
@@ -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
 }
index ca80cf70ca84bf48ff669e13e80d4983626dac1c..c89a14733f00969bd3765432f1b6b17f0b462b72 100644 (file)
@@ -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
 }
index a13b76ebd99e102dba92c2a2163ed1b8a4b36009..2205f898378a86aa047f44b30bf70a4172885199 100644 (file)
@@ -5796,10 +5796,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
 }
index 11c97323898f98be10aa945ea6969830763713ce..9c734eeba3b7a1959d18336f808b60ff19d0b7a0 100644 (file)
@@ -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,
index 9a50df9a88fbc7ccb6e56408eab6a51e2a6ce372..36f734a662f4123ac44d2f911fdb1c72e8ec6643 100644 (file)
@@ -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
 }
index 09354f92d24a01bbde16f6bb781330604d9f0a4e..514d460408be587e14ce69959eca9ce48878be6f 100644 (file)
@@ -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;
index fb0fa56f1eee0f1f10549070d08e48953dffc73b..0858c296ea05d30d9163478a0413baa0539e68c9 100644 (file)
@@ -3155,10 +3155,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;
index 2d3e498bc2f42027d6071a2974b2fb031f10b68c..aabf94f365b961129f10589521cbe5f6ca733096 100644 (file)
--- 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
 
index e6a8b07363000b4af7c9ac1f1c5c1ce31ce86b17..3dd9214904d201f726317bad9357b35c3bd104d2 100644 (file)
@@ -1355,10 +1355,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