Re: [Qemu-devel] [RFC PATCH] accel/tcg/translator: add tb_enter TCG trace

["Alex Bennée" <alex.bennee@linaro.org>]

Luc Michel <luc.michel@greensocs.com> writes:

> Add a TCG trace at the begining of a translation block recording the
> first and last (past-the-end) PC values.
>
> Signed-off-by: Luc Michel <luc.michel@greensocs.com>
> ---
> This can be used to trace the execution of the guest quite efficiently.
> It will report each time a TB is entered (using the tb_enter_exec
> trace). The traces arguments give the PC start and past-the-end values.
> It has very little to no performance impact since the trace is actually
> emitted in the generated code only when it is enabled at run time.
>
> It works already quite well on its own to trace guest execution.

You could just remove the disable from:

disable exec_tb(void *tb, uintptr_t pc) "tb:%p pc=0x%"PRIxPTR

And call qemu with -d nochain,trace:exec_tb

> However
> it does not handle the case where a TB is exited in the middle of
> execution. I'm not sure how to properly trace that. A trace could be
> added when `cpu_loop_exit()' is called to report the current PC, but in
> most cases the interesting value (the PC of the instruction that
> caused the exit) is already lost at this stage.
>
> I'm not sure there is a generic (i.e. not target specific) way of
> recovering the last PC executed when cpu_loop_exit() is called. Do you
> think of a better way?
>
> Thanks to the Xilinx's QEMU team who sponsored this work.
> ---
>  accel/tcg/translator.c | 24 ++++++++++++++++++++++++
>  trace-events           |  3 +++
>  2 files changed, 27 insertions(+)
>
> diff --git a/accel/tcg/translator.c b/accel/tcg/translator.c
> index 9226a348a3..c55377aa18 100644
> --- a/accel/tcg/translator.c
> +++ b/accel/tcg/translator.c
> @@ -14,10 +14,11 @@
>  #include "tcg/tcg-op.h"
>  #include "exec/exec-all.h"
>  #include "exec/gen-icount.h"
>  #include "exec/log.h"
>  #include "exec/translator.h"
> +#include "trace-tcg.h"
>
>  /* Pairs with tcg_clear_temp_count.
>     To be called by #TranslatorOps.{translate_insn,tb_stop} if
>     (1) the target is sufficiently clean to support reporting,
>     (2) as and when all temporaries are known to be consumed.
> @@ -28,14 +29,31 @@ void translator_loop_temp_check(DisasContextBase *db)
>          qemu_log("warning: TCG temporary leaks before "
>                   TARGET_FMT_lx "\n", db->pc_next);
>      }
>  }
>
> +static TCGOp *gen_trace_tb_enter(TranslationBlock *tb)
> +{
> +    TCGOp *last_pc_op;
> +
> +    TCGv pc_end = tcg_temp_new();
> +
> +    /* The last PC value is not known yet */
> +    tcg_gen_movi_tl(pc_end, 0xdeadbeef);
> +    last_pc_op = tcg_last_op();
> +
> +    trace_tb_enter_tcg(tcg_ctx->cpu, cpu_env, tb->pc, pc_end);
> +    tcg_temp_free(pc_end);
> +
> +    return last_pc_op;
> +}
> +
>  void translator_loop(const TranslatorOps *ops, DisasContextBase *db,
>                       CPUState *cpu, TranslationBlock *tb, int max_insns)
>  {
>      int bp_insn = 0;
> +    TCGOp *trace_pc_end;
>
>      /* Initialize DisasContext */
>      db->tb = tb;
>      db->pc_first = tb->pc;
>      db->pc_next = db->pc_first;
> @@ -50,10 +68,13 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db,
>      /* Reset the temp count so that we can identify leaks */
>      tcg_clear_temp_count();
>
>      /* Start translating.  */
>      gen_tb_start(db->tb);
> +
> +    trace_pc_end = gen_trace_tb_enter(tb);
> +
>      ops->tb_start(db, cpu);
>      tcg_debug_assert(db->is_jmp == DISAS_NEXT);  /* no early exit */
>
>      while (true) {
>          db->num_insns++;
> @@ -110,10 +131,13 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db,
>
>      /* Emit code to exit the TB, as indicated by db->is_jmp.  */
>      ops->tb_stop(db, cpu);
>      gen_tb_end(db->tb, db->num_insns - bp_insn);
>
> +    /* Fixup the last PC value in the tb_enter trace now that we know it */
> +    tcg_set_insn_param(trace_pc_end, 1, db->pc_next);
> +
>      /* The disas_log hook may use these values rather than recompute.  */
>      db->tb->size = db->pc_next - db->pc_first;
>      db->tb->icount = db->num_insns;
>
>  #ifdef DEBUG_DISAS
> diff --git a/trace-events b/trace-events
> index aeea3c2bdb..e37fa12ef0 100644
> --- a/trace-events
> +++ b/trace-events
> @@ -157,10 +157,13 @@ vcpu guest_cpu_reset(void)
>  #
>  # Mode: user, softmmu
>  # Targets: TCG(all)
>  vcpu tcg guest_mem_before(TCGv vaddr, uint8_t info) "info=%d", "vaddr=0x%016"PRIx64" info=%d"
>
> +# translator.c
> +vcpu tcg tb_enter(uint64_t pc_start, TCGv pc_end) "pc_start:0x%"PRIx64, "pc:0x%"PRIx64" pc_end:0x%"PRIx64
> +
>  # linux-user/syscall.c
>  # bsd-user/syscall.c
>
>  # @num: System call number.
>  # @arg*: System call argument value.


--
Alex Bennée