[PATCH v2 0/2] execlog TCG plugin to log instructions

[PATCH v2 0/2] execlog TCG plugin to log instructions

[Alexandre Iooss]

execlog is a plugin that logs executed instructions with some useful
metadata including memory access.

The output of the plugin is designed to be usable with other tools. For
example it could be used with a side-channel leakage model to create
side-channel traces from QEMU for security evaluation.

Changes since v1:
 - The output is now easier to parse.
 - Use QEMU logging API rather than FILE* to write output.
 - Don't reject memory information in user mode.
 - Merge memory information with instruction execution. Now one line
   means one instruction.
 - Add documentation.

Alexandre Iooss (2):
  contrib/plugins: add execlog to log instruction execution and memory
    access
  docs/devel: tvg-plugins: add execlog plugin description

 MAINTAINERS                |   1 +
 contrib/plugins/Makefile   |   1 +
 contrib/plugins/execlog.c  | 123 +++++++++++++++++++++++++++++++++++++
 docs/devel/tcg-plugins.rst |  22 +++++++
 4 files changed, 147 insertions(+)
 create mode 100644 contrib/plugins/execlog.c

-- 
2.25.1

[PATCH v2 1/2] contrib/plugins: add execlog to log instruction execution and memory access

[Alexandre Iooss]

Log instruction execution and memory access to a file.
This plugin can be used for reverse engineering or for side-channel analysis
using QEMU.

Signed-off-by: Alexandre Iooss <erdnaxe@crans.org>
---
 MAINTAINERS               |   1 +
 contrib/plugins/Makefile  |   1 +
 contrib/plugins/execlog.c | 123 ++++++++++++++++++++++++++++++++++++++
 3 files changed, 125 insertions(+)
 create mode 100644 contrib/plugins/execlog.c

diff --git a/MAINTAINERS b/MAINTAINERS
index 7d9cd29042..65942d5802 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -2974,6 +2974,7 @@ F: include/tcg/
 
 TCG Plugins
 M: Alex Bennée <alex.bennee@linaro.org>
+R: Alexandre Iooss <erdnaxe@crans.org>
 S: Maintained
 F: docs/devel/tcg-plugins.rst
 F: plugins/
diff --git a/contrib/plugins/Makefile b/contrib/plugins/Makefile
index b9d7935e5e..51093acd17 100644
--- a/contrib/plugins/Makefile
+++ b/contrib/plugins/Makefile
@@ -13,6 +13,7 @@ include $(BUILD_DIR)/config-host.mak
 VPATH += $(SRC_PATH)/contrib/plugins
 
 NAMES :=
+NAMES += execlog
 NAMES += hotblocks
 NAMES += hotpages
 NAMES += howvec
diff --git a/contrib/plugins/execlog.c b/contrib/plugins/execlog.c
new file mode 100644
index 0000000000..995c4477f9
--- /dev/null
+++ b/contrib/plugins/execlog.c
@@ -0,0 +1,123 @@
+/*
+ * Copyright (C) 2021, Alexandre Iooss <erdnaxe@crans.org>
+ *
+ * Log instruction execution with memory access.
+ *
+ * License: GNU GPL, version 2 or later.
+ *   See the COPYING file in the top-level directory.
+ */
+#include <glib.h>
+#include <inttypes.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <unistd.h>
+
+#include <qemu-plugin.h>
+
+QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION;
+
+/* Store last executed instruction on each vCPU */
+GString **last_exec;
+
+/**
+ * Add memory read or write information to current instruction log
+ */
+static void vcpu_mem(unsigned int cpu_index, qemu_plugin_meminfo_t info,
+                     uint64_t vaddr, void *udata)
+{
+    if (qemu_plugin_mem_is_store(info)) {
+        g_string_append(last_exec[cpu_index], ", store");
+    } else {
+        g_string_append(last_exec[cpu_index], ", load");
+    }
+
+    /* If full system emulation log physical address and device name */
+    struct qemu_plugin_hwaddr *hwaddr = qemu_plugin_get_hwaddr(info, vaddr);
+    if (hwaddr) {
+        uint64_t addr = qemu_plugin_hwaddr_phys_addr(hwaddr);
+        const char *name = qemu_plugin_hwaddr_device_name(hwaddr);
+        g_string_append_printf(last_exec[cpu_index], ", 0x%08"PRIx64", %s",
+                               addr, name);
+    } else {
+        g_string_append_printf(last_exec[cpu_index], ", 0x%08"PRIx64, vaddr);
+    }
+}
+
+/**
+ * Log instruction execution
+ */
+static void vcpu_insn_exec(unsigned int cpu_index, void *udata)
+{
+    /* Print previous instruction in cache */
+    if (last_exec[cpu_index]->str) {
+        qemu_plugin_outs(last_exec[cpu_index]->str);
+        qemu_plugin_outs("\n");
+    }
+
+    /* Store new instruction in cache */
+    /* vcpu_mem will add memory access information to last_exec */
+    g_string_printf(last_exec[cpu_index], "%u, ", cpu_index);
+    g_string_append(last_exec[cpu_index], (char *)udata);
+}
+
+/**
+ * On translation block new translation
+ *
+ * QEMU convert code by translation block (TB). By hooking here we can then hook
+ * a callback on each instruction and memory access.
+ */
+static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb)
+{
+    struct qemu_plugin_insn *insn;
+    uint64_t insn_vaddr;
+    uint32_t insn_opcode;
+    char *insn_disas;
+
+    size_t n = qemu_plugin_tb_n_insns(tb);
+    for (size_t i = 0; i < n; i++) {
+        /*
+         * `insn` is shared between translations in QEMU, copy needed data here.
+         * `output` is never freed as it might be used multiple times during
+         * the emulation lifetime.
+         * We only consider the first 32 bits of the instruction, this may be
+         * a limitation for CISC architectures.
+         */
+        insn = qemu_plugin_tb_get_insn(tb, i);
+        insn_vaddr = qemu_plugin_insn_vaddr(insn);
+        insn_opcode = *((uint32_t *)qemu_plugin_insn_data(insn));
+        insn_disas = qemu_plugin_insn_disas(insn);
+        char *output = g_strdup_printf("0x%"PRIx64", 0x%"PRIx32", \"%s\"",
+                                       insn_vaddr, insn_opcode, insn_disas);
+
+        /* Register callback on memory read or write */
+        qemu_plugin_register_vcpu_mem_cb(insn, vcpu_mem,
+                                         QEMU_PLUGIN_CB_NO_REGS,
+                                         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);
+    }
+}
+
+/**
+ * Install the plugin
+ */
+QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
+                                           const qemu_info_t *info, int argc,
+                                           char **argv)
+{
+    int i;
+
+    /* Initialize instruction cache for each vCPU */
+    last_exec = calloc(info->system.max_vcpus, sizeof(GString *));
+    for (i = 0; i < info->system.max_vcpus; i++) {
+        last_exec[i] = g_string_new(NULL);
+    }
+
+    /* Register translation block callback */
+    qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans);
+
+    return 0;
+}
-- 
2.25.1

Re: [PATCH v2 1/2] contrib/plugins: add execlog to log instruction execution and memory access

[Alex Bennée]

Alexandre Iooss <erdnaxe@crans.org> writes:

> Log instruction execution and memory access to a file.
> This plugin can be used for reverse engineering or for side-channel analysis
> using QEMU.
>
> Signed-off-by: Alexandre Iooss <erdnaxe@crans.org>
> ---
>  MAINTAINERS               |   1 +
>  contrib/plugins/Makefile  |   1 +
>  contrib/plugins/execlog.c | 123 ++++++++++++++++++++++++++++++++++++++
>  3 files changed, 125 insertions(+)
>  create mode 100644 contrib/plugins/execlog.c
>
> diff --git a/MAINTAINERS b/MAINTAINERS
> index 7d9cd29042..65942d5802 100644
> --- a/MAINTAINERS
> +++ b/MAINTAINERS
> @@ -2974,6 +2974,7 @@ F: include/tcg/
>  
>  TCG Plugins
>  M: Alex Bennée <alex.bennee@linaro.org>
> +R: Alexandre Iooss <erdnaxe@crans.org>
>  S: Maintained
>  F: docs/devel/tcg-plugins.rst
>  F: plugins/
> diff --git a/contrib/plugins/Makefile b/contrib/plugins/Makefile
> index b9d7935e5e..51093acd17 100644
> --- a/contrib/plugins/Makefile
> +++ b/contrib/plugins/Makefile
> @@ -13,6 +13,7 @@ include $(BUILD_DIR)/config-host.mak
>  VPATH += $(SRC_PATH)/contrib/plugins
>  
>  NAMES :=
> +NAMES += execlog
>  NAMES += hotblocks
>  NAMES += hotpages
>  NAMES += howvec
> diff --git a/contrib/plugins/execlog.c b/contrib/plugins/execlog.c
> new file mode 100644
> index 0000000000..995c4477f9
> --- /dev/null
> +++ b/contrib/plugins/execlog.c
> @@ -0,0 +1,123 @@
> +/*
> + * Copyright (C) 2021, Alexandre Iooss <erdnaxe@crans.org>
> + *
> + * Log instruction execution with memory access.
> + *
> + * License: GNU GPL, version 2 or later.
> + *   See the COPYING file in the top-level directory.
> + */
> +#include <glib.h>
> +#include <inttypes.h>
> +#include <stdio.h>
> +#include <stdlib.h>
> +#include <string.h>
> +#include <unistd.h>
> +
> +#include <qemu-plugin.h>
> +
> +QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION;
> +
> +/* Store last executed instruction on each vCPU */
> +GString **last_exec;
> +
> +/**
> + * Add memory read or write information to current instruction log
> + */
> +static void vcpu_mem(unsigned int cpu_index, qemu_plugin_meminfo_t info,
> +                     uint64_t vaddr, void *udata)
> +{
> +    if (qemu_plugin_mem_is_store(info)) {
> +        g_string_append(last_exec[cpu_index], ", store");
> +    } else {
> +        g_string_append(last_exec[cpu_index], ", load");
> +    }
> +
> +    /* If full system emulation log physical address and device name
>  */

The comment and logic implies that we might be running in user-mode but...

> +    struct qemu_plugin_hwaddr *hwaddr = qemu_plugin_get_hwaddr(info, vaddr);
> +    if (hwaddr) {
> +        uint64_t addr = qemu_plugin_hwaddr_phys_addr(hwaddr);
> +        const char *name = qemu_plugin_hwaddr_device_name(hwaddr);
> +        g_string_append_printf(last_exec[cpu_index], ", 0x%08"PRIx64", %s",
> +                               addr, name);
> +    } else {
> +        g_string_append_printf(last_exec[cpu_index], ", 0x%08"PRIx64, vaddr);
> +    }
> +}
> +
> +/**
> + * Log instruction execution
> + */
> +static void vcpu_insn_exec(unsigned int cpu_index, void *udata)
> +{
> +    /* Print previous instruction in cache */
> +    if (last_exec[cpu_index]->str) {
> +        qemu_plugin_outs(last_exec[cpu_index]->str);
> +        qemu_plugin_outs("\n");
> +    }
> +
> +    /* Store new instruction in cache */
> +    /* vcpu_mem will add memory access information to last_exec */
> +    g_string_printf(last_exec[cpu_index], "%u, ", cpu_index);
> +    g_string_append(last_exec[cpu_index], (char *)udata);
> +}
> +
> +/**
> + * On translation block new translation
> + *
> + * QEMU convert code by translation block (TB). By hooking here we can then hook
> + * a callback on each instruction and memory access.
> + */
> +static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb)
> +{
> +    struct qemu_plugin_insn *insn;
> +    uint64_t insn_vaddr;
> +    uint32_t insn_opcode;
> +    char *insn_disas;
> +
> +    size_t n = qemu_plugin_tb_n_insns(tb);
> +    for (size_t i = 0; i < n; i++) {
> +        /*
> +         * `insn` is shared between translations in QEMU, copy needed data here.
> +         * `output` is never freed as it might be used multiple times during
> +         * the emulation lifetime.
> +         * We only consider the first 32 bits of the instruction, this may be
> +         * a limitation for CISC architectures.
> +         */
> +        insn = qemu_plugin_tb_get_insn(tb, i);
> +        insn_vaddr = qemu_plugin_insn_vaddr(insn);
> +        insn_opcode = *((uint32_t *)qemu_plugin_insn_data(insn));
> +        insn_disas = qemu_plugin_insn_disas(insn);
> +        char *output = g_strdup_printf("0x%"PRIx64", 0x%"PRIx32", \"%s\"",
> +                                       insn_vaddr, insn_opcode, insn_disas);
> +
> +        /* Register callback on memory read or write */
> +        qemu_plugin_register_vcpu_mem_cb(insn, vcpu_mem,
> +                                         QEMU_PLUGIN_CB_NO_REGS,
> +                                         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);
> +    }
> +}
> +
> +/**
> + * Install the plugin
> + */
> +QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
> +                                           const qemu_info_t *info, int argc,
> +                                           char **argv)
> +{
> +    int i;
> +
> +    /* Initialize instruction cache for each vCPU */
> +    last_exec = calloc(info->system.max_vcpus, sizeof(GString *));
> +    for (i = 0; i < info->system.max_vcpus; i++) {
> +        last_exec[i] = g_string_new(NULL);
> +    }

We only allocate last_exec for system.max_vcpus here. You need to check
the system_emulation bool before using that information and error out if
it's not system emulation.

> +
> +    /* Register translation block callback */
> +    qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans);
> +
> +    return 0;
> +}

Otherwise:

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>

-- 
Alex Bennée

Re: [PATCH v2 1/2] contrib/plugins: add execlog to log instruction execution and memory access

[Alexandre IOOSS]

[-- Attachment #1.1: Type: text/plain, Size: 385 bytes --]

On 6/22/21 10:37 AM, Alex Bennée wrote:
> We only allocate last_exec for system.max_vcpus here. You need to check
> the system_emulation bool before using that information and error out if
> it's not system emulation.

My bad, I did not test user mode emulation after converting last_exec to 
an array. Should I consider only one vCPU in user mode emulation?

-- Alexandre


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 840 bytes --]

Re: [PATCH v2 1/2] contrib/plugins: add execlog to log instruction execution and memory access

[Alex Bennée]

Alexandre IOOSS <erdnaxe@crans.org> writes:

> [[PGP Signed Part:Undecided]]
> On 6/22/21 10:37 AM, Alex Bennée wrote:
>> We only allocate last_exec for system.max_vcpus here. You need to check
>> the system_emulation bool before using that information and error out if
>> it's not system emulation.
>
> My bad, I did not test user mode emulation after converting last_exec
> to an array. Should I consider only one vCPU in user mode emulation?

It's up to you. The cpuid is essentially unbounded for linux-user so you
could either dynamically assign new entries as they come up or just not
load for non system emulation cases. If you attempt to run
multi-threaded programs with a single entry in the array you will get
weird interleaving issues.

>
> -- Alexandre
>
> [[End of PGP Signed Part]]


-- 
Alex Bennée

[PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alexandre Iooss]

This adds description of the execlog TCG plugin with an example.

Signed-off-by: Alexandre Iooss <erdnaxe@crans.org>
---
 docs/devel/tcg-plugins.rst | 22 ++++++++++++++++++++++
 1 file changed, 22 insertions(+)

diff --git a/docs/devel/tcg-plugins.rst b/docs/devel/tcg-plugins.rst
index 18c6581d85..02818a3327 100644
--- a/docs/devel/tcg-plugins.rst
+++ b/docs/devel/tcg-plugins.rst
@@ -319,3 +319,25 @@ the user to see what hardware is accessed how often. It has a number of options:
       off:0000001c, 1, 2
       off:00000020, 1, 2
       ...
+
+- contrib/plugins/execlog.c
+
+The execlog tool traces executed instructions with memory access. It can be used
+for debugging and security analysis purposes.
+The plugin takes no argument::
+
+  qemu-system-arm $(QEMU_ARGS) \
+    -plugin ./contrib/plugins/libexeclog.so -d plugin
+
+which will output an execution trace following this structure::
+
+  # vCPU, vAddr, opcode, disassembly[, load/store, memory addr, device]...
+  0, 0xa12, 0xf8012400, "movs r4, #0"
+  0, 0xa14, 0xf87f42b4, "cmp r4, r6"
+  0, 0xa16, 0xd206, "bhs #0xa26"
+  0, 0xa18, 0xfff94803, "ldr r0, [pc, #0xc]", load, 0x00010a28, RAM
+  0, 0xa1a, 0xf989f000, "bl #0xd30"
+  0, 0xd30, 0xfff9b510, "push {r4, lr}", store, 0x20003ee0, RAM, store, 0x20003ee4, RAM
+  0, 0xd32, 0xf9893014, "adds r0, #0x14"
+  0, 0xd34, 0xf9c8f000, "bl #0x10c8"
+  0, 0x10c8, 0xfff96c43, "ldr r3, [r0, #0x44]", load, 0x200000e4, RAM
-- 
2.25.1

Re: [PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alex Bennée]

Alexandre Iooss <erdnaxe@crans.org> writes:

> This adds description of the execlog TCG plugin with an example.
>
> Signed-off-by: Alexandre Iooss <erdnaxe@crans.org>
> ---
>  docs/devel/tcg-plugins.rst | 22 ++++++++++++++++++++++
>  1 file changed, 22 insertions(+)
>
> diff --git a/docs/devel/tcg-plugins.rst b/docs/devel/tcg-plugins.rst
> index 18c6581d85..02818a3327 100644
> --- a/docs/devel/tcg-plugins.rst
> +++ b/docs/devel/tcg-plugins.rst
> @@ -319,3 +319,25 @@ the user to see what hardware is accessed how often. It has a number of options:
>        off:0000001c, 1, 2
>        off:00000020, 1, 2
>        ...
> +
> +- contrib/plugins/execlog.c
> +
> +The execlog tool traces executed instructions with memory access. It can be used
> +for debugging and security analysis purposes.

We should probably mention that this will generate a lot of output.
Running the admittedly memory heavy softmmu memory test:

  ./aarch64-softmmu/qemu-system-aarch64 -D test.out -d plugin \
    -plugin contrib/plugins/libexeclog.so  \
    -cpu max -serial mon:stdio -M virt \
    -display none -semihosting-config chardev=serial0 \
    -kernel ./tests/tcg/aarch64-softmmu/memory

generates a 8.6Gb text file. I suspect once this is merged you might
want to look at options to target the instrumentation at areas of
specific interest or abbreviate information. 

> +The plugin takes no argument::
> +
> +  qemu-system-arm $(QEMU_ARGS) \
> +    -plugin ./contrib/plugins/libexeclog.so -d plugin
> +
> +which will output an execution trace following this structure::
> +
> +  # vCPU, vAddr, opcode, disassembly[, load/store, memory addr, device]...
> +  0, 0xa12, 0xf8012400, "movs r4, #0"
> +  0, 0xa14, 0xf87f42b4, "cmp r4, r6"
> +  0, 0xa16, 0xd206, "bhs #0xa26"
> +  0, 0xa18, 0xfff94803, "ldr r0, [pc, #0xc]", load, 0x00010a28, RAM
> +  0, 0xa1a, 0xf989f000, "bl #0xd30"
> +  0, 0xd30, 0xfff9b510, "push {r4, lr}", store, 0x20003ee0, RAM, store, 0x20003ee4, RAM
> +  0, 0xd32, 0xf9893014, "adds r0, #0x14"
> +  0, 0xd34, 0xf9c8f000, "bl #0x10c8"
> +  0, 0x10c8, 0xfff96c43, "ldr r3, [r0, #0x44]", load, 0x200000e4, RAM


-- 
Alex Bennée

Re: [PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alexandre IOOSS]

[-- Attachment #1.1: Type: text/plain, Size: 1898 bytes --]

On 6/22/21 10:48 AM, Alex Bennée wrote:
> Alexandre Iooss<erdnaxe@crans.org>  writes:
>> [...]
>> +
>> +The execlog tool traces executed instructions with memory access. It can be used
>> +for debugging and security analysis purposes.
> We should probably mention that this will generate a lot of output.
> Running the admittedly memory heavy softmmu memory test:
> 
>    ./aarch64-softmmu/qemu-system-aarch64 -D test.out -d plugin \
>      -plugin contrib/plugins/libexeclog.so  \
>      -cpu max -serial mon:stdio -M virt \
>      -display none -semihosting-config chardev=serial0 \
>      -kernel ./tests/tcg/aarch64-softmmu/memory
> 
> generates a 8.6Gb text file. I suspect once this is merged you might
> want to look at options to target the instrumentation at areas of
> specific interest or abbreviate information.

Yes! In my downstream version I am triggering the beginning and the end 
of trace acquisition by matching two virtual addresses of GPIO device 
access. This works in my case because I'm also using the same GPIO for 
triggering an oscilloscope, but maybe we would like to upstream 
something more generic.

I'm still thinking about this (maybe for a later patch) but I believe it 
would be nice to have the following:
  - If no argument is given to the plugin, log everything.
  - Allow the user to specify either a memory address, an instruction 
virtual address or an opcode that would start the acquisition.
  - Same to stop the acquisition.

This would look like this to start/stop acquisition using GPIO PA8 on 
STM32VLDISCOVERY:

   ./arm-softmmu/qemu-system-arm -M stm32vldiscovery \
     -kernel ./firmware.elf -d plugin \
     -plugin libexeclog.so,arg=mem:1073809424,arg=mem:1073809424

I would like to hear other users opinion on this, because I fear I might 
implement something too specific.

Thanks,
-- Alexandre


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 840 bytes --]

Re: [PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alex Bennée]

Alexandre IOOSS <erdnaxe@crans.org> writes:

> [[PGP Signed Part:Undecided]]
> On 6/22/21 10:48 AM, Alex Bennée wrote:
>> Alexandre Iooss<erdnaxe@crans.org>  writes:
>>> [...]
>>> +
>>> +The execlog tool traces executed instructions with memory access. It can be used
>>> +for debugging and security analysis purposes.
>> We should probably mention that this will generate a lot of output.
>> Running the admittedly memory heavy softmmu memory test:
>>    ./aarch64-softmmu/qemu-system-aarch64 -D test.out -d plugin \
>>      -plugin contrib/plugins/libexeclog.so  \
>>      -cpu max -serial mon:stdio -M virt \
>>      -display none -semihosting-config chardev=serial0 \
>>      -kernel ./tests/tcg/aarch64-softmmu/memory
>> generates a 8.6Gb text file. I suspect once this is merged you might
>> want to look at options to target the instrumentation at areas of
>> specific interest or abbreviate information.
>
> Yes! In my downstream version I am triggering the beginning and the
> end of trace acquisition by matching two virtual addresses of GPIO
> device access. This works in my case because I'm also using the same
> GPIO for triggering an oscilloscope, but maybe we would like to
> upstream something more generic.
>
> I'm still thinking about this (maybe for a later patch) but I believe
> it would be nice to have the following:
>  - If no argument is given to the plugin, log everything.
>  - Allow the user to specify either a memory address, an instruction
>    virtual address or an opcode that would start the acquisition.
>  - Same to stop the acquisition.

Sounds reasonable to me.

> This would look like this to start/stop acquisition using GPIO PA8 on
> STM32VLDISCOVERY:
>
>   ./arm-softmmu/qemu-system-arm -M stm32vldiscovery \
>     -kernel ./firmware.elf -d plugin \
>     -plugin libexeclog.so,arg=mem:1073809424,arg=mem:1073809424

I quite like the formats you can use for -dfilter, for example:

  0x1000+0x100,0x2100-0x100,0x3000..0x3100

it might even be worth exposing qemu_set_dfilter_ranges as a helper
function to plugins to avoid copy and paste.

So what would your above command trigger? A write to 1073809424 would
start the trace and the next write to the same address would stop it?

> I would like to hear other users opinion on this, because I fear I
> might implement something too specific.
>
> Thanks,
> -- Alexandre
>
> [[End of PGP Signed Part]]


-- 
Alex Bennée

Re: [PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alexandre IOOSS]

[-- Attachment #1.1: Type: text/plain, Size: 3448 bytes --]

On 6/22/21 12:37 PM, Alex Bennée wrote:
> 
> Alexandre IOOSS <erdnaxe@crans.org> writes:
> 
>> [[PGP Signed Part:Undecided]]
>> On 6/22/21 10:48 AM, Alex Bennée wrote:
>>> Alexandre Iooss<erdnaxe@crans.org>  writes:
>>>> [...]
>>>> +
>>>> +The execlog tool traces executed instructions with memory access. It can be used
>>>> +for debugging and security analysis purposes.
>>> We should probably mention that this will generate a lot of output.
>>> Running the admittedly memory heavy softmmu memory test:
>>>     ./aarch64-softmmu/qemu-system-aarch64 -D test.out -d plugin \
>>>       -plugin contrib/plugins/libexeclog.so  \
>>>       -cpu max -serial mon:stdio -M virt \
>>>       -display none -semihosting-config chardev=serial0 \
>>>       -kernel ./tests/tcg/aarch64-softmmu/memory
>>> generates a 8.6Gb text file. I suspect once this is merged you might
>>> want to look at options to target the instrumentation at areas of
>>> specific interest or abbreviate information.
>>
>> Yes! In my downstream version I am triggering the beginning and the
>> end of trace acquisition by matching two virtual addresses of GPIO
>> device access. This works in my case because I'm also using the same
>> GPIO for triggering an oscilloscope, but maybe we would like to
>> upstream something more generic.
>>
>> I'm still thinking about this (maybe for a later patch) but I believe
>> it would be nice to have the following:
>>   - If no argument is given to the plugin, log everything.
>>   - Allow the user to specify either a memory address, an instruction
>>     virtual address or an opcode that would start the acquisition.
>>   - Same to stop the acquisition.
> 
> Sounds reasonable to me.
> 
>> This would look like this to start/stop acquisition using GPIO PA8 on
>> STM32VLDISCOVERY:
>>
>>    ./arm-softmmu/qemu-system-arm -M stm32vldiscovery \
>>      -kernel ./firmware.elf -d plugin \
>>      -plugin libexeclog.so,arg=mem:1073809424,arg=mem:1073809424
> 
> I quite like the formats you can use for -dfilter, for example:
> 
>    0x1000+0x100,0x2100-0x100,0x3000..0x3100
> 
> it might even be worth exposing qemu_set_dfilter_ranges as a helper
> function to plugins to avoid copy and paste.

We could expose "-dfilter", but maybe it is better to reserve it to 
filter the output of the plugin rather than triggering the tracing?

I could implement a format similar to dfilter to configure triggering. 
This would enable someone to start logging on any access to a memory range.

> 
> So what would your above command trigger? A write to 1073809424 would
> start the trace and the next write to the same address would stop it?
> 

Yes exactly. In this case the first access set the GPIO high, and the 
second access set it low.

I don't believe the plugin can access the value stored in memory (i.e. 
differentiating between setting a GPIO output high or low). I don't find 
this problematic in my case, but maybe it could be for someone else.

 From the discussion I see the following possible patches:
1. Add an argument to trigger the beginning with one address (memory or 
instruction).
2. Add an argument to trigger the end with one address (memory or 
instruction).
3. Add the support for ranges (in "dfilter" style).
4. (maybe) Add the support to trigger on an opcode.
5. Add support for "-dfilter" to filter the logging output.

Thanks,
-- Alexandre


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 840 bytes --]

Re: [PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alex Bennée]

Alexandre IOOSS <erdnaxe@crans.org> writes:

> [[PGP Signed Part:Undecided]]
> On 6/22/21 12:37 PM, Alex Bennée wrote:
>> Alexandre IOOSS <erdnaxe@crans.org> writes:
>> 
>>> [[PGP Signed Part:Undecided]]
>>> On 6/22/21 10:48 AM, Alex Bennée wrote:
>>>> Alexandre Iooss<erdnaxe@crans.org>  writes:
>>>>> [...]
>>>>> +
>>>>> +The execlog tool traces executed instructions with memory access. It can be used
>>>>> +for debugging and security analysis purposes.
>>>> We should probably mention that this will generate a lot of output.
>>>> Running the admittedly memory heavy softmmu memory test:
>>>>     ./aarch64-softmmu/qemu-system-aarch64 -D test.out -d plugin \
>>>>       -plugin contrib/plugins/libexeclog.so  \
>>>>       -cpu max -serial mon:stdio -M virt \
>>>>       -display none -semihosting-config chardev=serial0 \
>>>>       -kernel ./tests/tcg/aarch64-softmmu/memory
>>>> generates a 8.6Gb text file. I suspect once this is merged you might
>>>> want to look at options to target the instrumentation at areas of
>>>> specific interest or abbreviate information.
>>>
>>> Yes! In my downstream version I am triggering the beginning and the
>>> end of trace acquisition by matching two virtual addresses of GPIO
>>> device access. This works in my case because I'm also using the same
>>> GPIO for triggering an oscilloscope, but maybe we would like to
>>> upstream something more generic.
>>>
>>> I'm still thinking about this (maybe for a later patch) but I believe
>>> it would be nice to have the following:
>>>   - If no argument is given to the plugin, log everything.
>>>   - Allow the user to specify either a memory address, an instruction
>>>     virtual address or an opcode that would start the acquisition.
>>>   - Same to stop the acquisition.
>> Sounds reasonable to me.
>> 
>>> This would look like this to start/stop acquisition using GPIO PA8 on
>>> STM32VLDISCOVERY:
>>>
>>>    ./arm-softmmu/qemu-system-arm -M stm32vldiscovery \
>>>      -kernel ./firmware.elf -d plugin \
>>>      -plugin libexeclog.so,arg=mem:1073809424,arg=mem:1073809424
>> I quite like the formats you can use for -dfilter, for example:
>>    0x1000+0x100,0x2100-0x100,0x3000..0x3100
>> it might even be worth exposing qemu_set_dfilter_ranges as a helper
>> function to plugins to avoid copy and paste.
>
> We could expose "-dfilter", but maybe it is better to reserve it to
> filter the output of the plugin rather than triggering the tracing?

I meant the parsing code for dfilter style expressions, the dfilter
itself ;-)

> I could implement a format similar to dfilter to configure triggering.
> This would enable someone to start logging on any access to a memory
> range.
>
>> So what would your above command trigger? A write to 1073809424
>> would
>> start the trace and the next write to the same address would stop it?
>> 
>
> Yes exactly. In this case the first access set the GPIO high, and the
> second access set it low.
>
> I don't believe the plugin can access the value stored in memory (i.e.
> differentiating between setting a GPIO output high or low). I don't
> find this problematic in my case, but maybe it could be for someone
> else.

Not currently but in principle it wouldn't be too hard to do. It would
just be extra data to copy into a TCG Arg. We would probably want to
make it optional though.

>
> From the discussion I see the following possible patches:
> 1. Add an argument to trigger the beginning with one address (memory
> or instruction).
> 2. Add an argument to trigger the end with one address (memory or
> instruction).
> 3. Add the support for ranges (in "dfilter" style).
> 4. (maybe) Add the support to trigger on an opcode.
> 5. Add support for "-dfilter" to filter the logging output.
>
> Thanks,
> -- Alexandre
>
> [[End of PGP Signed Part]]


-- 
Alex Bennée

Re: [PATCH v2 2/2] docs/devel: tvg-plugins: add execlog plugin description

[Alex Bennée]

Alexandre Iooss <erdnaxe@crans.org> writes:

<snip>

Sorry also missed s/tvg/tcg/ in the subject line.

-- 
Alex Bennée

Re: [PATCH v2 0/2] execlog TCG plugin to log instructions

[Alexandre IOOSS]

[-- Attachment #1.1: Type: text/plain, Size: 1234 bytes --]

Supersedes: <20210614090116.816833-1-erdnaxe@crans.org>

On 6/18/21 11:10 AM, Alexandre Iooss wrote:
> execlog is a plugin that logs executed instructions with some useful
> metadata including memory access.
> 
> The output of the plugin is designed to be usable with other tools. For
> example it could be used with a side-channel leakage model to create
> side-channel traces from QEMU for security evaluation.
> 
> Changes since v1:
>   - The output is now easier to parse.
>   - Use QEMU logging API rather than FILE* to write output.
>   - Don't reject memory information in user mode.
>   - Merge memory information with instruction execution. Now one line
>     means one instruction.
>   - Add documentation.
> 
> Alexandre Iooss (2):
>    contrib/plugins: add execlog to log instruction execution and memory
>      access
>    docs/devel: tvg-plugins: add execlog plugin description
> 
>   MAINTAINERS                |   1 +
>   contrib/plugins/Makefile   |   1 +
>   contrib/plugins/execlog.c  | 123 +++++++++++++++++++++++++++++++++++++
>   docs/devel/tcg-plugins.rst |  22 +++++++
>   4 files changed, 147 insertions(+)
>   create mode 100644 contrib/plugins/execlog.c
> 

-- 
Alexandre


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 840 bytes --]

Re: [PATCH v2 0/2] execlog TCG plugin to log instructions

[Alex Bennée]

Alexandre Iooss <erdnaxe@crans.org> writes:

> execlog is a plugin that logs executed instructions with some useful
> metadata including memory access.
>
> The output of the plugin is designed to be usable with other tools. For
> example it could be used with a side-channel leakage model to create
> side-channel traces from QEMU for security evaluation.
>
> Changes since v1:
>  - The output is now easier to parse.
>  - Use QEMU logging API rather than FILE* to write output.
>  - Don't reject memory information in user mode.
>  - Merge memory information with instruction execution. Now one line
>    means one instruction.
>  - Add documentation.

Where you planning on posting v3? I'm just seeing if we can get this
merged before code freeze in a weeks time.

-- 
Alex Bennée

Re: [PATCH v2 0/2] execlog TCG plugin to log instructions

[Alexandre IOOSS]

[-- Attachment #1.1: Type: text/plain, Size: 1188 bytes --]



On 7/1/21 8:49 PM, Alex Bennée wrote:
> 
> Alexandre Iooss <erdnaxe@crans.org> writes:
> 
>> execlog is a plugin that logs executed instructions with some useful
>> metadata including memory access.
>>
>> The output of the plugin is designed to be usable with other tools. For
>> example it could be used with a side-channel leakage model to create
>> side-channel traces from QEMU for security evaluation.
>>
>> Changes since v1:
>>   - The output is now easier to parse.
>>   - Use QEMU logging API rather than FILE* to write output.
>>   - Don't reject memory information in user mode.
>>   - Merge memory information with instruction execution. Now one line
>>     means one instruction.
>>   - Add documentation.
> 
> Where you planning on posting v3? I'm just seeing if we can get this
> merged before code freeze in a weeks time.
> 

I had a deadline next week but I managed to move it later, so I can try 
to make the important changes tomorrow and send v3.

I think I will contribute the support for triggering the beginning and 
end of tracing in another patch as I believe that's something we don't 
want to rush.

Thanks,

-- Alexandre


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 840 bytes --]

Re: [PATCH v2 0/2] execlog TCG plugin to log instructions

[Alex Bennée]

Alexandre IOOSS <erdnaxe@crans.org> writes:

> [[PGP Signed Part:Undecided]]
>
>
> On 7/1/21 8:49 PM, Alex Bennée wrote:
>> Alexandre Iooss <erdnaxe@crans.org> writes:
>> 
>>> execlog is a plugin that logs executed instructions with some useful
>>> metadata including memory access.
>>>
>>> The output of the plugin is designed to be usable with other tools. For
>>> example it could be used with a side-channel leakage model to create
>>> side-channel traces from QEMU for security evaluation.
>>>
>>> Changes since v1:
>>>   - The output is now easier to parse.
>>>   - Use QEMU logging API rather than FILE* to write output.
>>>   - Don't reject memory information in user mode.
>>>   - Merge memory information with instruction execution. Now one line
>>>     means one instruction.
>>>   - Add documentation.
>> Where you planning on posting v3? I'm just seeing if we can get this
>> merged before code freeze in a weeks time.
>> 
>
> I had a deadline next week but I managed to move it later, so I can
> try to make the important changes tomorrow and send v3.

Cool.

> I think I will contribute the support for triggering the beginning and
> end of tracing in another patch as I believe that's something we don't
> want to rush.

That's fine ;-)

-- 
Alex Bennée