Re: [PATCH v1 20/22] tests/plugins: add instruction matching to libinsn.so

[Philippe Mathieu-Daudé]

On 1/24/22 21:16, Alex Bennée wrote:
> This adds simple instruction matching to the libinsn.so plugin which
> is useful for examining the execution distance between instructions.
> For example to track how often we flush in ARM due to TLB updates:
> 
>   -plugin ./tests/plugin/libinsn.so,match=tlbi
> 
> which leads to output like this:
> 
>   0xffffffc01018fa00, tlbi aside1is, x0,  339, 32774 match hits, 23822 since 
> last, avg 47279
>   0xffffffc01018fa00, tlbi aside1is, x0,  340, 32775 match hits, 565051 since 
> last, avg 47295
>   0xffffffc0101915a4, tlbi vae1is, x0,  155, 32776 match hits, 151135 since 
> last, avg 47298
>   0xffffffc01018fc60, tlbi vae1is, x4,  224, 32777 match hits, 814 since 
> last, avg 47297
>   0xffffffc010194a44, tlbi vale1is, x1,  8835, 32778 match hits, 52027 since 
> last, avg 47297
>   0xffffffc010194a44, tlbi vale1is, x1,  8836, 32779 match hits, 8347 since 
> last, avg 47296
>   0xffffffc010194a44, tlbi vale1is, x1,  8837, 32780 match hits, 33677 since 
> last, avg 47295

Just nitpicking the output below.

> showing we do some sort of TLBI invalidation every 47 thousand
> instructions.
> 
> Cc: Vasilev Oleg <vasilev.oleg@huawei.com>
> Cc: Richard Henderson <richard.henderson@linaro.org>
> Cc: Emilio Cota <cota@braap.org>
> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> ---
>  tests/plugin/insn.c | 88 ++++++++++++++++++++++++++++++++++++++++++++-
>  1 file changed, 87 insertions(+), 1 deletion(-)

> +static void vcpu_insn_matched_exec_before(unsigned int cpu_index, void 
> *udata)
> +{
> +    unsigned int i = cpu_index % MAX_CPUS;
> +    Instruction *insn = (Instruction *) udata;
> +    Match *match = insn->match;
> +    g_autoptr(GString) ts = g_string_new("");
> +
> +    insn->hits++;
> +    g_string_append_printf(ts, "0x%" PRIx64 ", %s, % "PRId64,
> +                           insn->vaddr, insn->disas, insn->hits);

Maybe use something else the ',' to split last arg (hits)? \t or --?
Otherwise it seems part of the decoded instr.

> +
> +    uint64_t icount = counts[i].insn_count;
> +    uint64_t delta = icount - match->last_hit[i];
> +
> +    match->hits[i]++;
> +    match->total_delta[i] += delta;
> +
> +    g_string_append_printf(ts,
> +                           ", %"PRId64" match hits, %"PRId64

Maybe prefix delta with '+'.

> +                           " since last, avg %"PRId64"\n",
> +                           match->hits[i], delta,
> +                           match->total_delta[i] / match->hits[i]);
> +
> +    match->last_hit[i] = icount;
> +
> +    qemu_plugin_outs(ts->str);
> +
> +    g_ptr_array_add(match->history[i], insn);
> +}