*: Use fprintf between qemu_log_trylock/unlock

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 <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
Message-Id: <20220417183019.755276-10-richard.henderson@linaro.org>
This commit is contained in:
Richard Henderson 2022-04-17 11:29:49 -07:00
parent 6fef222971
commit 78b548583e
9 changed files with 162 additions and 132 deletions

View File

@ -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 */
}

View File

@ -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 (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 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;
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;
}
insn++;
}
if (chunk_start < code_size) {
qemu_log(" -- tb slow paths + alignment\n");
log_disas(tb->tc.ptr + chunk_start, code_size - 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);
/* 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();
/*
* 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++;
}
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;
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

View File

@ -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
}

14
cpu.c
View File

@ -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);

View File

@ -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");
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++) {
qemu_log(" %02X", msg->data[i]);
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 buff2frame_pel(const uint8_t *buff, qemu_can_frame *frame)

View File

@ -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);

View File

@ -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)

View File

@ -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);
}
}

View File

@ -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;
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;
log_disas(s->code_gen_ptr, code_size);
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) {
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));
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