Re: [PATCH] contrib/plugins: add mask plugin

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

Vasilev Oleg <vasilev.oleg@huawei.com> writes:

> On 1/24/2022 3:26 PM, Alex Bennée wrote:
>
>> Oleg Vasilev <me@svin.in> writes:
>>
>>> From: Oleg Vasilev <vasilev.oleg@huawei.com>
>>>
>>> Plugin can be used to track statistics based on virtual address mask matching.
>>> Useful for tracking kernel vs user translation blocks.
>> Could we have a bit more detail please, maybe some words for
>> devel/tcg/plugins.rst. Running:
>>
>> ./qemu-system-x86_64 -monitor none -display none -chardev file,path=test.out,id=output -device isa-debugcon,chardev=output -device isa-debug-exit,iobase=0xf4,iosize=0x4 -
>> kernel ./tests/tcg/x86_64-softmmu/memory -plugin contrib/plugins/libmask.so -d plugin
>> hint: all, mask: 0x0000000000000000, bits: 0x0000000000000000, hit_rate: 0.999023, mask_freq: 0.000004, tb_exec: 1024, tb_trans: 1
>> hint: kernel, mask: 0x8000000000000000, bits: 0x8000000000000000, hit_rate: -nan, mask_freq: 0.000000, tb_exec: 0, tb_trans: 0
>> hint: user, mask: 0x8000000000000000, bits: 0x0000000000000000, hit_rate: 0.999023, mask_freq: 0.000004, tb_exec: 1024, tb_trans: 1
>> hint: all, mask: 0x0000000000000000, bits: 0x0000000000000000, hit_rate: 0.999849, mask_freq: 0.078281, tb_exec: 21013504, tb_trans: 3169
>> hint: kernel, mask: 0x8000000000000000, bits: 0x8000000000000000, hit_rate: -nan, mask_freq: 0.000000, tb_exec: 0, tb_trans: 0
>> hint: user, mask: 0x8000000000000000, bits: 0x0000000000000000, hit_rate: 0.999849, mask_freq: 0.078281, tb_exec: 21013504, tb_trans: 3169
>>
>> ends up being a bit incomprehensible.
>>> Signed-off-by: Oleg Vasilev <vasilev.oleg@huawei.com>
>>> Signed-off-by: Oleg Vasilev <me@svin.in>
>>> ---
>>>  contrib/plugins/Makefile |   1 +
>>>  contrib/plugins/mask.c   | 144 +++++++++++++++++++++++++++++++++++++++
>>>  2 files changed, 145 insertions(+)
>>>  create mode 100644 contrib/plugins/mask.c
>>>
>>> diff --git a/contrib/plugins/Makefile b/contrib/plugins/Makefile
>>> index 54ac5ccd9f..7e9cb51c9d 100644
>>> --- a/contrib/plugins/Makefile
>>> +++ b/contrib/plugins/Makefile
>>> @@ -20,6 +20,7 @@ NAMES += howvec
>>>  NAMES += lockstep
>>>  NAMES += hwprofile
>>>  NAMES += cache
>>> +NAMES += mask
>>>  
>>>  SONAMES := $(addsuffix .so,$(addprefix lib,$(NAMES)))
>>>  
>>> diff --git a/contrib/plugins/mask.c b/contrib/plugins/mask.c
>>> new file mode 100644
>>> index 0000000000..c6d2bd2386
>>> --- /dev/null
>>> +++ b/contrib/plugins/mask.c
>>> @@ -0,0 +1,144 @@
>>> +/*
>>> + * Copyright (C) 2022, Oleg Vasilev <vasilev.oleg@huawei.com>
>>> + *
>>> + * Track statistics based on virtual address mask matching.
>>> + * Useful for tracking kernel vs user translation blocks.
>>> + *
>>> + * License: GNU GPL, version 2 or later.
>>> + *   See the COPYING file in the top-level directory.
>>> + */
>>> +
>>> +#include <assert.h>
>>> +#include <compiler.h>
>>> +#include <glib.h>
>>> +#include <inttypes.h>
>>> +#include <qemu-plugin.h>
>>> +#include <stdio.h>
>>> +#include <stdlib.h>
>>> +#include <string.h>
>>> +#include <unistd.h>
>>> +
>>> +#include <atomic.h>
>>> +
>>> +QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION;
>>> +
>>> +typedef struct {
>>> +    GMutex lock;
>>> +    const char *hint;
>>> +    uint64_t mask;
>>> +    uint64_t bits;
>>> +    uint64_t tb_exec;
>>> +    uint64_t tb_trans;
>>> +    uint64_t isins;
>>> +} MaskCounter;
>>> +
>>> +static GPtrArray *counters;
>>> +
>>> +static uint64_t report_every = 1 << 28;
>>> +static uint64_t tb_exec_every = 1 << 10;
>>> +static uint64_t total_tb_exec;
>>> +
>>> +static void gen_one_report(MaskCounter *counter, GString *report)
>>> +{
>>> +    g_mutex_lock(&counter->lock);
>>> +    uint64_t tb_exec = counter->tb_exec * tb_exec_every;
>>> +
>>> +    double hit_rate = (double)counter->tb_trans / tb_exec;
>>> +    hit_rate = 1 - hit_rate;
>>> +
>>> +    double mask_freq = (double) counter->tb_exec * tb_exec_every / report_every;
>>> +
>>> +    g_string_append_printf(report,
>>> +                           "hint: %s, mask: 0x%016lx, bits: 0x%016lx, hit_rate: %f, "
>>> +                           "mask_freq: %f, tb_exec: %ld, tb_trans: %ld\n",
>>> +                           counter->hint, counter->mask, counter->bits, hit_rate,
>>> +                           mask_freq, tb_exec, counter->tb_trans);
>> Could aiming for plainer CSV format make this information more
>> digestible by tooling?
>
> Hi, thanks for looking at the patch!
>
> What do you think, tskv would be fine, considering some tooling exists and it is also readable for eyes? 
>
> Like this:
> hint=kernel     hit_rate=0.999923       freq=0.110752   execs=29729792  translations=2299
> hint=user       hit_rate=0.999952       freq=0.889248   execs=238705664 translations=11557

So we should read this as 99% of the time we are executing already
translated code and we spend 88% of our execution in userspace address
ranges? I think a worked example in the docs would be good.

>>
>>> +
>>> +    counter->tb_exec = 0;
>>> +    counter->tb_trans = 0;
>>> +    counter->isins = 0;
>> Would it be worth tracking total lifetime vs period counts?
>
> Probably so, will add a config option to specify period length.
>
>>> +
>>> +    g_mutex_unlock(&counter->lock);
>>> +}
>>> +
>>> +static void report_all(void)
>>> +{
>>> +    g_autoptr(GString) report = g_string_new("");
>>> +    g_ptr_array_foreach(counters, (GFunc)gen_one_report, report);
>>> +    qemu_plugin_outs(report->str);
>>> +}
>>> +
>>> +static void plugin_exit(qemu_plugin_id_t id, void *p)
>>> +{
>>> +    report_all();
>>> +}
>>> +
>>> +static bool match(MaskCounter *counter, struct qemu_plugin_tb *tb)
>>> +{
>>> +    return (counter->mask & qemu_plugin_tb_vaddr(tb)) == counter->bits;
>>> +}
>>> +
>>> +static void tb_exec(MaskCounter *counter, struct qemu_plugin_tb *tb)
>>> +{
>>> +    if (!match(counter, tb)) {
>>> +        return;
>>> +    }
>>> +    g_mutex_lock(&counter->lock);
>>> +    counter->tb_exec++;
>>> +    g_mutex_unlock(&counter->lock);
>>> +}
>>> +
>>> +static void vcpu_tb_exec(unsigned int cpu_index, void *tb)
>>> +{
>>> +    uint64_t cur_tb_exec = qatomic_fetch_inc(&total_tb_exec);
>>> +    if ((cur_tb_exec & (tb_exec_every - 1)) == 0) {
>>> +        g_ptr_array_foreach(counters, (GFunc)tb_exec, tb);
>>> +    }
>>> +
>>> +    if ((cur_tb_exec & (report_every - 1)) == 0) {
>>> +        report_all();
>>> +    }
>>> +}
>>> +
>>> +static void tb_trans(MaskCounter *counter, struct qemu_plugin_tb *tb)
>>> +{
>>> +    if (!match(counter, tb)) {
>>> +        return;
>>> +    }
>>> +    g_mutex_lock(&counter->lock);
>>> +    counter->tb_trans++;
>>> +    g_mutex_unlock(&counter->lock);
>>> +}
>>> +
>>> +static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb)
>>> +{
>>> +    qemu_plugin_register_vcpu_tb_exec_cb(tb, vcpu_tb_exec,
>>> +                                         QEMU_PLUGIN_CB_NO_REGS, tb);
>> You can't pass qemu_plugin_tb to the exec handler like this as it is
>> only valid during the lifetime of translation. You need to extract the
>> information you need (qemu_plugin_tb_vaddr(tb)) and pass that.
>>
>> The restriction is the same as we state for qemu_plugin_tb_get_insn():
>>
>>  The returned handle can be used in follow up helper queries as well
>>  as when instrumenting an instruction. It is only valid for the
>>  lifetime of the callback.
>>
>> but it isn't attached to a API docs, we do mention it in the general
>> principles:
>>
>>   Lifetime of the query handle
>>   ~~~~~~~~~~~~~~~~~~~~~~~~~~~~
>>
>>   Each callback provides an opaque anonymous information handle which
>>   can usually be further queried to find out information about a
>>   translation, instruction or operation. The handles themselves are only
>>   valid during the lifetime of the callback so it is important that any
>>   information that is needed is extracted during the callback and saved
>>   by the plugin.
>>
> If I were to allocate a distinct structure per tb here, how could I
> free it? Or is it fine to just leave it leaked?

In this case I don't think you need to allocate a structure as you only
need to track vaddr so you might as well just use that as pure data
tracked by the plugin. However if you want to track more data you will
need to allocate a structure for it and pass that instead.

Generally you clean-up on plugin_exit. Although it's fairly safe to
assume plugin_exit will run at the end of execution where you can just
rely on the OS to clean-up after you it's good practice to for plugins
to clean-up after themselves. A plugin can for example call
qemu_plugin_uninstall to remove itself once it has collected enough data
and leave the program to continue running.

> Perhaps a new cb helper should be added for flush htable event, when
> we could reset all current tb structures?

Do you mean so the user can trigger an event from HMP/QMP to signal the
plugin to do something with its data? That might be useful but I think
we would need to take some care with the way that works so we don't end
up with a messy ad-hoc interface.

>
>>> +    g_ptr_array_foreach(counters, (GFunc)tb_trans, tb);
>>> +}
>>> +
>>> +static void add_counter(const char *hint, uint64_t mask, uint64_t bits)
>>> +{
>>> +    MaskCounter *counter = g_new0(MaskCounter, 1);
>>> +    counter->hint = hint;
>>> +    counter->mask = mask;
>>> +    counter->bits = bits;
>>> +    g_mutex_init(&counter->lock);
>>> +    g_ptr_array_add(counters, counter);
>>> +}
>>> +
>>> +QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
>>> +                                           const qemu_info_t *info, int argc,
>>> +                                           char **argv)
>>> +{
>>> +    counters = g_ptr_array_new();
>>> +
>>> +    // Update for a different mask
>>> +    add_counter("all", 0, 0);
>>> +    add_counter("kernel", 0x1ll << 63, 0x1ll << 63);
>>> +    add_counter("user", 0x1ll << 63, 0);
>> These seem very fixed - do they apply for all kernels/architectures?
>> Perhaps we could have sensible defaults based on info->target_name with
>> an option to hand set zones via CLI options?
>
> Generally for linux kernel the highest bit indicated kernel space AFAIK.
>
> Sensible default probably here would be to determine the highest bit
> based on 64 vs 32 bit current architecture.

Do different 64 bit architectures have different splits addresses?

> Regarding the CLI options, I considered adding that, and I am thinking
> those would be too complex. Much easier would be to change the code
> and write the correct mask. Do you think this can be merged without
> the CLI options, expecting users to modify these lines to achieve
> different zoning?

I don't think adding parameters is too complex. We have several plugins
that do that already. However if we have sensible defaults I think
arguments can be deferred to later patches.

>
> Best regards,
> Oleg
>
>>
>> Also what should happen in the case of !info->system_emulation? There is
>> probably a case for something similar tracking execution in various .so
>> libs but that would need a little additional information from the
>> infrastructure to track.
>>
>>> +
>>> +    qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans);
>>> +    qemu_plugin_register_atexit_cb(id, plugin_exit, NULL);
>>> +    return 0;
>>> +}


-- 
Alex Bennée