Re: [RFC PATCH 22/24] contrib/plugins: Allow to log registers

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

Akihiko Odaki <akihiko.odaki@daynix.com> writes:

> This demonstrates how a register can be read from a plugin.

I think it would be a little more useful as a demo if it tracked changes
to the register state rather than dumping it for every line executed.

>
> Signed-off-by: Akihiko Odaki <akihiko.odaki@daynix.com>
> ---
>  docs/devel/tcg-plugins.rst |  10 ++-
>  contrib/plugins/execlog.c  | 130 ++++++++++++++++++++++++++++---------
>  2 files changed, 108 insertions(+), 32 deletions(-)
>
> diff --git a/docs/devel/tcg-plugins.rst b/docs/devel/tcg-plugins.rst
> index 81dcd43a61..c9f8b27590 100644
> --- a/docs/devel/tcg-plugins.rst
> +++ b/docs/devel/tcg-plugins.rst
> @@ -497,6 +497,15 @@ arguments if required::
>    $ qemu-system-arm $(QEMU_ARGS) \
>      -plugin ./contrib/plugins/libexeclog.so,ifilter=st1w,afilter=0x40001808 -d plugin
>  
> +This plugin can also dump a specified register. The specification of register
> +follows `GDB standard target features <https://sourceware.org/gdb/onlinedocs/gdb/Standard-Target-Features.html>`__.
> +
> +Specify the name of the feature that contains the register and the name of the
> +register with ``rfile`` and ``reg`` options, respectively::
> +
> +  $ qemu-system-arm $(QEMU_ARGS) \
> +    -plugin ./contrib/plugins/libexeclog.so,rfile=org.gnu.gdb.arm.core,reg=sp -d plugin
> +
>  - contrib/plugins/cache.c
>  
>  Cache modelling plugin that measures the performance of a given L1 cache
> @@ -583,4 +592,3 @@ The following API is generated from the inline documentation in
>  include the full kernel-doc annotations.
>  
>  .. kernel-doc:: include/qemu/qemu-plugin.h
> -
> diff --git a/contrib/plugins/execlog.c b/contrib/plugins/execlog.c
> index ce67acf145..031ad67fbb 100644
> --- a/contrib/plugins/execlog.c
> +++ b/contrib/plugins/execlog.c
> @@ -15,27 +15,42 @@
>  
>  #include <qemu-plugin.h>
>  
> +typedef struct CPU {
> +    /* Store last executed instruction on each vCPU as a GString */
> +    GString *last_exec;
> +    GByteArray *reg_buf;
> +
> +    int reg;
> +} CPU;
> +
>  QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION;
>  
> -/* Store last executed instruction on each vCPU as a GString */
> -static GPtrArray *last_exec;
> +static CPU *cpus;
> +static int num_cpus;
>  static GRWLock expand_array_lock;
>  
>  static GPtrArray *imatches;
>  static GArray *amatches;
>  
> +static char *rfile_name;
> +static char *reg_name;
> +
>  /*
> - * Expand last_exec array.
> + * Expand cpu array.
>   *
>   * As we could have multiple threads trying to do this we need to
>   * serialise the expansion under a lock.
>   */
> -static void expand_last_exec(int cpu_index)
> +static void expand_cpu(int cpu_index)
>  {
> -    g_rw_lock_writer_unlock(&expand_array_lock);
> -    while (cpu_index >= last_exec->len) {
> -        GString *s = g_string_new(NULL);
> -        g_ptr_array_add(last_exec, s);
> +    g_rw_lock_writer_lock(&expand_array_lock);
> +    if (cpu_index >= num_cpus) {
> +        cpus = g_realloc_n(cpus, cpu_index + 1, sizeof(*cpus));
> +        while (cpu_index >= num_cpus) {
> +            cpus[num_cpus].last_exec = g_string_new(NULL);
> +            cpus[num_cpus].reg_buf = g_byte_array_new();
> +            num_cpus++;
> +        }
>      }
>      g_rw_lock_writer_unlock(&expand_array_lock);
>  }
> @@ -50,8 +65,8 @@ static void vcpu_mem(unsigned int cpu_index, qemu_plugin_meminfo_t info,
>  
>      /* Find vCPU in array */
>      g_rw_lock_reader_lock(&expand_array_lock);
> -    g_assert(cpu_index < last_exec->len);
> -    s = g_ptr_array_index(last_exec, cpu_index);
> +    g_assert(cpu_index < num_cpus);
> +    s = cpus[cpu_index].last_exec;
>      g_rw_lock_reader_unlock(&expand_array_lock);
>  
>      /* Indicate type of memory access */
> @@ -77,28 +92,35 @@ static void vcpu_mem(unsigned int cpu_index, qemu_plugin_meminfo_t info,
>   */
>  static void vcpu_insn_exec(unsigned int cpu_index, void *udata)
>  {
> -    GString *s;
> +    CPU cpu;
> +    int n;
> +    int i;
>  
>      /* Find or create vCPU in array */
>      g_rw_lock_reader_lock(&expand_array_lock);
> -    if (cpu_index >= last_exec->len) {
> -        g_rw_lock_reader_unlock(&expand_array_lock);
> -        expand_last_exec(cpu_index);
> -        g_rw_lock_reader_lock(&expand_array_lock);
> -    }
> -    s = g_ptr_array_index(last_exec, cpu_index);
> +    cpu = cpus[cpu_index];
>      g_rw_lock_reader_unlock(&expand_array_lock);
>  
>      /* Print previous instruction in cache */
> -    if (s->len) {
> -        qemu_plugin_outs(s->str);
> +    if (cpu.last_exec->len) {
> +        qemu_plugin_outs(cpu.last_exec->str);
>          qemu_plugin_outs("\n");
>      }
>  
>      /* Store new instruction in cache */
>      /* vcpu_mem will add memory access information to last_exec */
> -    g_string_printf(s, "%u, ", cpu_index);
> -    g_string_append(s, (char *)udata);
> +    g_string_printf(cpu.last_exec, "%u, ", cpu_index);
> +    g_string_append(cpu.last_exec, (char *)udata);
> +
> +    if (cpu.reg >= 0) {
> +        g_string_append(cpu.last_exec, ", reg,");
> +        n = qemu_plugin_read_register(cpu.reg_buf, cpu.reg);
> +        for (i = 0; i < n; i++) {
> +            g_string_append_printf(cpu.last_exec, " 0x%02X",
> +                                   cpu.reg_buf->data[i]);
> +        }

so instead of:

  0, 0x4001b4, 0xd10043ff, "sub sp, sp, #0x10", reg, 0x70 0xFF 0x7F 0x00 0x00 0x40 0x00 0x00

we could aim for something like:

  0, 0x4001b4, 0xd10043ff, "sub sp, sp, #0x10", sp => 0x70ff7f0000400000


> +        g_byte_array_set_size(cpu.reg_buf, 0);
> +    }
>  }
>  
>  /**
> @@ -167,8 +189,10 @@ static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb)
>                                               QEMU_PLUGIN_MEM_RW, NULL);
>  
>              /* Register callback on instruction */
> -            qemu_plugin_register_vcpu_insn_exec_cb(insn, vcpu_insn_exec,
> -                                                   QEMU_PLUGIN_CB_NO_REGS, output);
> +            qemu_plugin_register_vcpu_insn_exec_cb(
> +                insn, vcpu_insn_exec,
> +                rfile_name ? QEMU_PLUGIN_CB_R_REGS : QEMU_PLUGIN_CB_NO_REGS,
> +                output);
>  
>              /* reset skip */
>              skip = (imatches || amatches);
> @@ -177,17 +201,53 @@ static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb)
>      }
>  }
>  
> +static void vcpu_init(qemu_plugin_id_t id, unsigned int vcpu_index)
> +{
> +    int reg = 0;
> +    bool found = false;
> +
> +    expand_cpu(vcpu_index);
> +
> +    if (rfile_name) {
> +        int i;
> +        int j;
> +        int n;
> +
> +        qemu_plugin_register_file_t *rfiles =
> +            qemu_plugin_get_register_files(vcpu_index, &n);
> +
> +        for (i = 0; i < n; i++) {
> +            if (g_strcmp0(rfiles[i].name, rfile_name) == 0) {
> +                for (j = 0; j < rfiles[i].num_regs; j++) {
> +                    if (g_strcmp0(rfiles[i].regs[j], reg_name) == 0) {
> +                        reg += j;
> +                        found = true;
> +                        break;
> +                    }
> +                }
> +                break;
> +            }
> +
> +            reg += rfiles[i].num_regs;
> +        }
> +
> +        g_free(rfiles);
> +    }
> +
> +    g_rw_lock_writer_lock(&expand_array_lock);
> +    cpus[vcpu_index].reg = found ? reg : -1;
> +    g_rw_lock_writer_unlock(&expand_array_lock);
> +}
> +
>  /**
>   * On plugin exit, print last instruction in cache
>   */
>  static void plugin_exit(qemu_plugin_id_t id, void *p)
>  {
>      guint i;
> -    GString *s;
> -    for (i = 0; i < last_exec->len; i++) {
> -        s = g_ptr_array_index(last_exec, i);
> -        if (s->str) {
> -            qemu_plugin_outs(s->str);
> +    for (i = 0; i < num_cpus; i++) {
> +        if (cpus[i].last_exec->str) {
> +            qemu_plugin_outs(cpus[i].last_exec->str);
>              qemu_plugin_outs("\n");
>          }
>      }
> @@ -224,9 +284,7 @@ QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
>       * we don't know the size before emulation.
>       */
>      if (info->system_emulation) {
> -        last_exec = g_ptr_array_sized_new(info->system.max_vcpus);
> -    } else {
> -        last_exec = g_ptr_array_new();
> +        cpus = g_new(CPU, info->system.max_vcpus);
>      }
>  
>      for (int i = 0; i < argc; i++) {
> @@ -236,13 +294,23 @@ QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
>              parse_insn_match(tokens[1]);
>          } else if (g_strcmp0(tokens[0], "afilter") == 0) {
>              parse_vaddr_match(tokens[1]);
> +        } else if (g_strcmp0(tokens[0], "rfile") == 0) {
> +            rfile_name = g_strdup(tokens[1]);
> +        } else if (g_strcmp0(tokens[0], "reg") == 0) {
> +            reg_name = g_strdup(tokens[1]);
>          } else {
>              fprintf(stderr, "option parsing failed: %s\n", opt);
>              return -1;
>          }
>      }
>  
> +    if ((!rfile_name) != (!reg_name)) {
> +        fputs("file and reg need to be set at the same time\n", stderr);
> +        return -1;
> +    }
> +
>      /* Register translation block and exit callbacks */
> +    qemu_plugin_register_vcpu_init_cb(id, vcpu_init);
>      qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans);
>      qemu_plugin_register_atexit_cb(id, plugin_exit, NULL);


-- 
Alex Bennée
Virtualisation Tech Lead @ Linaro