QEMUに入門してみる(14. トレース関数の自動生成方法)

QEMUにはトレース出力用の関数を自動的に生成するフレームワークが存在している。これは命令トレースを出力するのとは異なり、各種イベントを取得するためのフレームワークを生成するものだ。

まず、取りたいイベントを定義しなければならない。target/myriscvx/trace-eventsというファイルを作成してそこに記述する。以下はRISC-Vの実装から取ってきた。

• qemu/target/myriscvx/trace-events

# target/myriscvx/cpu_helper.c
myriscvx_trap(uint64_t hartid, bool async, uint64_t cause, uint64_t epc, uint64_t tval, const char *desc) "hart:%"PRId64", async:%d, cause:%"PRId64", epc:0x%"PRIx64", tval:0x%"PRIx64", desc=%s"

myriscvx_trap()という関数を自動生成する。ここでは引数を指定しており、その引数を表示するためのprintf()のフォーマットを順番に与えている。この情報に基づいて関数が自動的に生成される。

このqemu/target/myriscvx/trace-eventsを利用するために、qemu/Makefile.objsに当該ディレクトリを追加する必要がある。これによりビルド対象に当該ディレクトリのtrace-eventsファイルが含まれるようになる。

• qemu/Makefile.objs

...
trace-events-subdirs += target/mips
trace-events-subdirs += target/ppc
trace-events-subdirs += target/riscv
trace-events-subdirs += target/myriscvx      # これを追加する。
trace-events-subdirs += target/s390x
trace-events-subdirs += target/sparc
...

これでQEMUのビルドを行うと、ビルドディレクトリにトレースファイル用のヘッダと実装が自動的に生成されていることが分かる。

 ls -lt build-myriscvx/target/myriscvx
total 32
-rw-rw-rw- 1 msyksphinz msyksphinz 20592 Jul 17 23:22 trace.o
-rw-rw-rw- 1 msyksphinz msyksphinz  8188 Jul 17 23:22 trace.d
-rw-rw-rw- 1 msyksphinz msyksphinz   644 Jul 17 23:22 trace.c
-rw-rw-rw- 1 msyksphinz msyksphinz  1373 Jul 17 23:22 trace.h
-rw-rw-rw- 1 msyksphinz msyksphinz   644 Jul 17 23:22 trace.c-timestamp
-rw-rw-rw- 1 msyksphinz msyksphinz  1373 Jul 17 23:22 trace.h-timestamp

trace.hを開いてみよう。先ほどの定義に基づいて関数が作られていることが分かる。

• build-myriscvx/target/myriscvx/trace.h

static inline void _nocheck__trace_myriscvx_trap(uint64_t hartid, bool async, uint64_t cause, uint64_t epc, uint64_t tval, const char * desc)
{
    if (trace_event_get_state(TRACE_MYRISCVX_TRAP) && qemu_loglevel_mask(LOG_TRACE)) {
        struct timeval _now;
        gettimeofday(&_now, NULL);
        qemu_log("%d@%zu.%06zu:myriscvx_trap " "hart:%"PRId64", async:%d, cause:%"PRId64", epc:0x%"PRIx64", tval:0x%"PRIx64", desc=%s" "\n",
                 qemu_get_thread_id(),
                 (size_t)_now.tv_sec, (size_t)_now.tv_usec
                 , hartid, async, cause, epc, tval, desc);
    }
}

static inline void trace_myriscvx_trap(uint64_t hartid, bool async, uint64_t cause, uint64_t epc, uint64_t tval, const char * desc)
{
    if (true) {
        _nocheck__trace_myriscvx_trap(hartid, async, cause, epc, tval, desc);
    }
}

trace.cにはトレースイベントの登録用関数が含まれており、trace_init()が呼び出されていることからこれは自動的に実行されるようだ。

• build-myriscvx/target/myriscvx/trace.c

TraceEvent _TRACE_MYRISCVX_TRAP_EVENT = {
    .id = 0,
    .vcpu_id = TRACE_VCPU_EVENT_NONE,
    .name = "myriscvx_trap",
    .sstate = TRACE_MYRISCVX_TRAP_ENABLED,
    .dstate = &_TRACE_MYRISCVX_TRAP_DSTATE 
};
TraceEvent *target_myriscvx_trace_events[] = {
    &_TRACE_MYRISCVX_TRAP_EVENT,
  NULL,
};

static void trace_target_myriscvx_register_events(void)
{
    trace_event_register_group(target_myriscvx_trace_events);
}
trace_init(trace_target_myriscvx_register_events)

そして、この自動生成されたtrace_myriscvx_trap()をしかるべき場所で呼び出す。今回の実装では割り込みが発生したときのハンドラで呼び出せばよい。

void myriscvx_cpu_do_interrupt(CPUState *cs)
{
#if !defined(CONFIG_USER_ONLY)

  MYRISCVXCPU *cpu = MYRISCVX_CPU(cs);
  CPUMYRISCVXState *env = &cpu->env;
...

  // ここにトレース生成の関数を記述する。
  trace_myriscvx_trap(env->mhartid, async, cause, env->pc, tval, cause < 23 ?
                      (async ? myriscvx_intr_names : myriscvx_excp_names)[cause] : "(unknown)");

  if (env->priv <= PRV_S &&
      cause < TARGET_LONG_BITS && ((deleg >> cause) & 1)) {
...

では、QEMUにオプションを付加してトレースを呼び出してみる。

$ ${QEMU_BUILD}/myriscvx64-softmmu/qemu-system-myriscvx64 --machine virt \
    --d in_asm --nographic \
    --trace myriscvx_trap \     # myriscvx_trapを追加する
    --kernel ${RISCV}/riscv64-unknown-elf/share/riscv-tests/isa/rv64ui-p-simple

このmyriscvx_trapはどこから来たのかというとtrace.cで定義されているイベント名で分かる。

TraceEvent _TRACE_MYRISCVX_TRAP_EVENT = {
    .id = 0,
    .vcpu_id = TRACE_VCPU_EVENT_NONE,
    .name = "myriscvx_trap",
    .sstate = TRACE_MYRISCVX_TRAP_ENABLED,
    .dstate = &_TRACE_MYRISCVX_TRAP_DSTATE 
};

IN:
Priv: 3; Virt: 0
0x0000000000000000:
OBJD-T: 00000000

1752@1595002791.401878:myriscvx_trap hart:0, async:0, cause:2, epc:0x0, tval:0x0, desc=illegal_instruction
----------------

トレースファイルが出力されていることが分かる。Illegal Instructionが大量に生成された。ほとんど命令を定義していないからか...

ちなみに、先ほどの--trace myriscvx_trapを--trace "*"に変えると大量のトレースを出力することができる。