diff --git a/.gitmodules b/.gitmodules index 2bdeeacef88..09791be7a69 100644 --- a/.gitmodules +++ b/.gitmodules @@ -64,3 +64,10 @@ [submodule "roms/vbootrom"] path = roms/vbootrom url = https://git.qemu.org/git/vbootrom.git +[submodule "trace/cheri-perfetto"] + path = trace_extra/cheri-perfetto + url = https://github.com/CTSRD-CHERI/cheri-perfetto.git + branch = cheri-perfetto +[submodule "trace_extra/dynamorio"] + path = trace_extra/dynamorio + url = https://github.com/CTSRD-CHERI/dynamorio.git diff --git a/Jenkinsfile b/Jenkinsfile index 6c40e9112a3..d61c587314e 100644 --- a/Jenkinsfile +++ b/Jenkinsfile @@ -133,6 +133,9 @@ selectedConfigs.each { config -> if (isDebug) { extraQemuArgs = '--qemu/configure-options=--enable-rvfi-dii --qemu/build-type=Debug --qemu/use-asan' } + if (os == "linux") { + extraQemuArgs += ' --qemu/configure-options=--enable-perfetto-log-instr' + } def qemuResult = cheribuildProject(target: 'qemu', cpu: 'native', skipArtifacts: true, nodeLabel: null, extraArgs: "--without-sdk --install-prefix=/usr $extraQemuArgs", diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c index b834006e8ab..518cc8cedb3 100644 --- a/accel/tcg/cpu-exec.c +++ b/accel/tcg/cpu-exec.c @@ -32,6 +32,7 @@ #include "exec/tb-hash.h" #include "exec/tb-lookup.h" #include "exec/log.h" +#include "exec/log_instr.h" #include "qemu/main-loop.h" #if defined(TARGET_I386) && !defined(CONFIG_USER_ONLY) #include "hw/i386/apic.h" @@ -703,6 +704,7 @@ static inline void cpu_loop_exec_tb(CPUState *cpu, TranslationBlock *tb, #ifndef CONFIG_USER_ONLY /* Ensure global icount has gone forward */ icount_update(cpu); + /* Refill decrementer and continue execution. */ insns_left = MIN(0xffff, cpu->icount_budget); cpu_neg(cpu)->icount_decr.u16.low = insns_left; diff --git a/accel/tcg/log_instr.c b/accel/tcg/log_instr.c index d454eeda7bc..621d6e52c0c 100644 --- a/accel/tcg/log_instr.c +++ b/accel/tcg/log_instr.c @@ -1,7 +1,7 @@ /*- * SPDX-License-Identifier: BSD-2-Clause * - * Copyright (c) 2020 Alfredo Mazzinghi + * Copyright (c) 2020,2021 Alfredo Mazzinghi * * This software was developed by SRI International and the University of * Cambridge Computer Laboratory (Department of Computer Science and @@ -35,12 +35,14 @@ #include "qemu/osdep.h" #include "qemu/range.h" #include "qemu/log.h" +#include "qapi/error.h" #include "cpu-param.h" #include "cpu.h" #include "exec/exec-all.h" #include "exec/log.h" #include "exec/helper-proto.h" #include "exec/log_instr.h" +#include "exec/log_instr_internal.h" #include "exec/memop.h" #include "disas/disas.h" #include "exec/translator.h" @@ -67,26 +69,12 @@ * active. Each CPU holds a private logging state, that can be controlled * individually. * - * TODO(am2419): how do we deal with orderding in case multiple registers are updated? - * This is critical to recognize which value goes in which register, and also how to - * tie multiple memory accesses to the respective value/register. - * We could add an explicit target-specific register ID handle in place of the - * register name. This could be used also to fetch the register name and would - * provide an identifier to external parsers. - * Memory updates are harder to deal with, at least in the current format, perhaps - * the semantic of the instruction is enough to recover the ordering from a trace. */ #ifdef CONFIG_TCG_LOG_INSTR // #define CONFIG_DEBUG_TCG -#ifdef CONFIG_DEBUG_TCG -#define log_assert(x) assert((x)) -#else -#define log_assert(x) -#endif - #ifndef TARGET_MAX_INSN_SIZE #error "Target does not define TARGET_MAX_INSN_SIZE in cpu-param.h" #endif @@ -96,532 +84,199 @@ */ extern GArray *debug_regions; -/* - * Instruction log info associated with each committed log entry. - * This is stored in the per-cpu log cpustate. - */ -typedef struct cpu_log_instr_info { -#define cpu_log_iinfo_startzero asid - uint16_t asid; - int flags; -/* Entry contains a synchronous exception */ -#define LI_FLAG_INTR_TRAP 1 -/* Entry contains an asynchronous exception */ -#define LI_FLAG_INTR_ASYNC (1 << 1) -#define LI_FLAG_INTR_MASK 0x3 -/* Entry contains a CPU mode-switch and associated code */ -#define LI_FLAG_MODE_SWITCH (1 << 2) - - qemu_log_instr_cpu_mode_t next_cpu_mode; - uint32_t intr_code; - target_ulong intr_vector; - target_ulong intr_faultaddr; - - target_ulong pc; - /* Generic instruction opcode buffer */ - int insn_size; - char insn_bytes[TARGET_MAX_INSN_SIZE]; -#define cpu_log_iinfo_endzero mem - /* - * For now we allow multiple accesses to be tied to one instruction. - * Some architectures may have multiple memory accesses - * in the same instruction (e.g. x86-64 pop r/m64, - * vector/matrix instructions, load/store pair). It is unclear - * whether we would treat these as multiple trace "entities". - * - * Array of log_meminfo_t - */ - GArray *mem; - /* Register modifications. Array of log_reginfo_t */ - GArray *regs; - /* Extra text-only log */ - GString *txt_buffer; -} cpu_log_instr_info_t; - -/* - * Register update info. - * This records a CPU register update occurred during an instruction. - */ -typedef struct { - uint16_t flags; -#define LRI_CAP_REG 1 -#define LRI_HOLDS_CAP 2 - - const char *name; - union { - target_ulong gpr; -#ifdef TARGET_CHERI - cap_register_t cap; -#endif - }; -} log_reginfo_t; - -#define reginfo_is_cap(ri) (ri->flags & LRI_CAP_REG) -#define reginfo_has_cap(ri) (reginfo_is_cap(ri) && (ri->flags & LRI_HOLDS_CAP)) +/* Global trace format selector. Defaults to text tracing */ +qemu_log_instr_backend_t qemu_log_instr_backend = QEMU_LOG_INSTR_BACKEND_TEXT; -/* - * Memory access info. - * This records a memory access occurred during an instruction. - */ -typedef struct { - uint8_t flags; -#define LMI_LD 1 -#define LMI_ST 2 -#define LMI_CAP 4 - MemOp op; - target_ulong addr; - union { - uint64_t value; -#ifdef TARGET_CHERI - cap_register_t cap; -#endif - }; -} log_meminfo_t; +static const char *trace_logfile_name = "qemu_trace.txt"; /* - * Callbacks defined by a trace format implementation. - * These are called to covert instruction tracing events to the corresponding - * binary or text format. + * The number of entries in the trace buffer at startup. + * + * This is set by hooks in the command line argument parsing before + * CPUs are initialized. */ -struct trace_fmt_hooks { - void (*emit_header)(CPUArchState *env); - void (*emit_start)(CPUArchState *env, target_ulong pc); - void (*emit_stop)(CPUArchState *env, target_ulong pc); - void (*emit_entry)(CPUArchState *env, cpu_log_instr_info_t *iinfo); -}; -typedef struct trace_fmt_hooks trace_fmt_hooks_t; - -/* Global trace format selector. Defaults to text tracing */ -qemu_log_instr_fmt_t qemu_log_instr_format = QLI_FMT_TEXT; +static unsigned long reset_entry_buffer_size = DEFAULT_ENTRY_BUFFER_SIZE; /* Current format callbacks. */ -static trace_fmt_hooks_t *trace_format = NULL; - -/* Existing format callbacks list, indexed by qemu_log_instr_fmt_t */ -static trace_fmt_hooks_t trace_formats[]; +static trace_backend_hooks_t *trace_backend; -/* - * CHERI binary trace format, originally used for MIPS only. - * The format is limited to one entry per instruction, each - * entry can hold at most one register modification and one - * memory address. - * Note that the CHERI format is the legacy MIPS format and - * assumes big-endian byte order. - */ -typedef struct { - uint8_t entry_type; -#define CTE_NO_REG 0 /* No register is changed. */ -#define CTE_GPR 1 /* GPR change (val2) */ -#define CTE_LD_GPR 2 /* Load into GPR (val2) from address (val1) */ -#define CTE_ST_GPR 3 /* Store from GPR (val2) to address (val1) */ -#define CTE_CAP 11 /* Cap change (val2,val3,val4,val5) */ -#define CTE_LD_CAP 12 /* Load Cap (val2,val3,val4,val5) from addr (val1) */ -#define CTE_ST_CAP 13 /* Store Cap (val2,val3,val4,val5) to addr (val1) */ - uint8_t exception; /* 0=none, 1=TLB Mod, 2=TLB Load, 3=TLB Store, etc. */ -#define CTE_EXCEPTION_NONE 31 - uint16_t cycles; /* Currently not used. */ - uint32_t inst; /* Encoded instruction. */ - uint64_t pc; /* PC value of instruction. */ - uint64_t val1; /* val1 is used for memory address. */ - uint64_t val2; /* val2, val3, val4, val5 are used for reg content. */ - uint64_t val3; - uint64_t val4; - uint64_t val5; - uint8_t thread; /* Hardware thread/CPU (i.e. cpu->cpu_index ) */ - uint8_t asid; /* Address Space ID */ -} __attribute__((packed)) cheri_trace_entry_t; - -/* Version 3 Cheri Stream Trace header info */ -#define CTE_QEMU_VERSION (0x80U + 3) -#define CTE_QEMU_MAGIC "CheriTraceV03" - -/* Number of per-cpu ring buffer entries for ring-buffer tracing mode */ -#define MIN_ENTRY_BUFFER_SIZE (1 << 16) - -static unsigned long reset_entry_buffer_size = MIN_ENTRY_BUFFER_SIZE; +static void emit_nop_entry(CPUArchState *env, cpu_log_entry_t *entry); /* - * Fetch the log state for a cpu. + * Existing format callbacks list, indexed by qemu_log_instr_backend_t. */ -static inline cpu_log_instr_state_t *get_cpu_log_state(CPUArchState *env) -{ - return &env_cpu(env)->log_state; -} - -/* - * Fetch the given cpu current instruction info - */ -static inline cpu_log_instr_info_t *get_cpu_log_instr_info(CPUArchState *env) -{ - cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - - return &g_array_index(cpulog->instr_info, cpu_log_instr_info_t, - cpulog->ring_head); -} +static trace_backend_hooks_t trace_backends[] = { + { + .emit_instr = emit_text_instr + }, { + .emit_instr = emit_nop_entry + }, { +#ifdef CONFIG_TRACE_CVTRACE + .init = emit_cvtrace_header, + .sync = NULL, + .emit_instr = emit_cvtrace_entry +#endif + }, { +#ifdef CONFIG_TRACE_PERFETTO + .init = init_perfetto_backend, + .sync = sync_perfetto_backend, + .emit_instr = emit_perfetto_entry +#endif + }, { +#ifdef CONFIG_TRACE_PROTOBUF + .init = init_protobuf_backend, + .sync = sync_protobuf_backend, + .emit_instr = emit_protobuf_entry +#endif + }, { +#ifdef CONFIG_TRACE_JSON + .init = init_json_backend, + .sync = sync_json_backend, + .emit_instr = emit_json_entry +#endif + }, +}; -/* Text trace format emitters */ +/* Existing trace filters list, indexed by cpu_log_instr_filter_t */ +static cpu_log_instr_filter_fn_t trace_filters[]; -/* - * Emit textual trace representation of memory access - */ -static inline void emit_text_ldst(log_meminfo_t *minfo, const char *direction) -{ +/* Trace filters to activate when a new CPU is seen */ +static GArray *reset_filters; -#ifndef TARGET_CHERI - log_assert((minfo->flags & LMI_CAP) == 0 && - "Capability memory access without CHERI support"); -#else - if (minfo->flags & LMI_CAP) { - qemu_log(" Cap Memory %s [" TARGET_FMT_lx "] = v:%d PESBT:" - TARGET_FMT_lx " Cursor:" TARGET_FMT_lx "\n", - direction, minfo->addr, minfo->cap.cr_tag, - CAP_cc(compress_mem)(&minfo->cap), - cap_get_cursor(&minfo->cap)); - } else -#endif - { - switch (memop_size(minfo->op)) { - default: - qemu_log(" Unknown memory access width\n"); - /* fallthrough */ - case 8: - qemu_log(" Memory %s [" TARGET_FMT_lx "] = " TARGET_FMT_plx "\n", - direction, minfo->addr, minfo->value); - break; - case 4: - qemu_log(" Memory %s [" TARGET_FMT_lx "] = %08x\n", - direction, minfo->addr, (uint32_t)minfo->value); - break; - case 2: - qemu_log(" Memory %s [" TARGET_FMT_lx "] = %04x\n", - direction, minfo->addr, (uint16_t)minfo->value); - break; - case 1: - qemu_log(" Memory %s [" TARGET_FMT_lx "] = %02x\n", - direction, minfo->addr, (uint8_t)minfo->value); - break; - } - } -} +bool trace_debug; -/* - * Emit textual trace representation of register modification - */ -static inline void emit_text_reg(log_reginfo_t *rinfo) +static void emit_nop_entry(CPUArchState *env, cpu_log_entry_t *entry) { -#ifndef TARGET_CHERI - log_assert(!reginfo_is_cap(rinfo) && "Register marked as capability " - "register whitout CHERI support"); -#else - if (reginfo_is_cap(rinfo)) { - if (reginfo_has_cap(rinfo)) - qemu_log(" Write %s|" PRINT_CAP_FMTSTR_L1 "\n" - " |" PRINT_CAP_FMTSTR_L2 "\n", - rinfo->name, - PRINT_CAP_ARGS_L1(&rinfo->cap), - PRINT_CAP_ARGS_L2(&rinfo->cap)); - else - qemu_log(" %s <- " TARGET_FMT_lx " (setting integer value)\n", - rinfo->name, rinfo->gpr); - } else -#endif - { - qemu_log(" Write %s = " TARGET_FMT_lx "\n", rinfo->name, - rinfo->gpr); - } + return; } -/* - * Emit textual trace entry to the log. - */ -static void emit_text_entry(CPUArchState *env, cpu_log_instr_info_t *iinfo) +static void dump_debug_stats(CPUState *cpu) { - QemuLogFile *logfile; - int i; - - /* Dump CPU-ID:ASID + address */ - qemu_log("[%d:%d] ", env_cpu(env)->cpu_index, iinfo->asid); - - /* - * Instruction disassembly, note that we use the instruction info - * opcode bytes, without accessing target memory here. - */ - rcu_read_lock(); - logfile = qatomic_rcu_read(&qemu_logfile); - if (logfile) { - target_disas_buf(logfile->fd, env_cpu(env), iinfo->insn_bytes, - sizeof(iinfo->insn_bytes), iinfo->pc, 1); - } - rcu_read_unlock(); - - /* - * TODO(am2419): what to do with injected instructions? - * Is the rvfi_dii_trace state valid at log commit? - */ - - /* Dump mode switching info */ - if (iinfo->flags & LI_FLAG_MODE_SWITCH) - qemu_log("-> Switch to %s mode\n", cpu_get_mode_name(iinfo->next_cpu_mode)); - /* Dump interrupt/exception info */ - switch (iinfo->flags & LI_FLAG_INTR_MASK) { - case LI_FLAG_INTR_TRAP: - qemu_log("-> Exception #%u vector 0x" TARGET_FMT_lx - " fault-addr 0x" TARGET_FMT_lx "\n", - iinfo->intr_code, iinfo->intr_vector, iinfo->intr_faultaddr); - break; - case LI_FLAG_INTR_ASYNC: - qemu_log("-> Interrupt #%04x vector 0x" TARGET_FMT_lx "\n", - iinfo->intr_code, iinfo->intr_vector); - break; - default: - /* No interrupt */ - break; - } + cpu_log_instr_state_t *cpulog = get_cpu_log_state(cpu->env_ptr); + qemu_log_instr_stats_t *stats = &cpulog->stats; - /* Dump memory access */ - for (i = 0; i < iinfo->mem->len; i++) { - log_meminfo_t *minfo = &g_array_index(iinfo->mem, log_meminfo_t, i); - if (minfo->flags & LMI_LD) { - emit_text_ldst(minfo, "Read"); - } else if (minfo->flags & LMI_ST) { - emit_text_ldst(minfo, "Write"); - } + if (!trace_debug) { + return; } - /* Dump register changes and side-effects */ - for (i = 0; i < iinfo->regs->len; i++) { - log_reginfo_t *rinfo = &g_array_index(iinfo->regs, log_reginfo_t, i); - emit_text_reg(rinfo); + fprintf(stderr, "TCG Instruction tracing statistics: CPU #%d\n", + cpu->cpu_index); + fprintf(stderr, "entries emitted: %lu\n", stats->entries_emitted); + fprintf(stderr, "trace slices: %lu\n", stats->trace_start); + if (stats->trace_start != stats->trace_stop) { + fprintf(stderr, "Unbalanced trace stop: %lu\n", stats->trace_stop); } - - /* Dump extra logged messages, if any */ - if (iinfo->txt_buffer->len > 0) - qemu_log("%s", iinfo->txt_buffer->str); } -/* - * Emit text tracing start event. - */ -static void emit_text_start(CPUArchState *env, target_ulong pc) +void qemu_log_instr_enable_trace_debug(void) { - cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - - if (cpulog->loglevel == QEMU_LOG_INSTR_LOGLEVEL_USER) { - qemu_log("[%u:%u] Requested user-mode only instruction logging " - "@ " TARGET_FMT_lx " \n", - env_cpu(env)->cpu_index, cpu_get_asid(env, pc), pc); - } else { - qemu_log("[%u:%u] Requested instruction logging @ " TARGET_FMT_lx " \n", - env_cpu(env)->cpu_index, cpu_get_asid(env, pc), pc); - } + trace_debug = true; } -/* - * Emit text tracing stop event. - */ -static void emit_text_stop(CPUArchState *env, target_ulong pc) +static void emit_regdump_event(CPUArchState *env, cpu_log_entry_t *entry) { - cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + log_event_t event; - if (cpulog->loglevel == QEMU_LOG_INSTR_LOGLEVEL_USER) { - qemu_log("[%u:%u] Disabled user-mode only instruction logging " - "@ " TARGET_FMT_lx " \n", - env_cpu(env)->cpu_index, cpu_get_asid(env, pc), pc); - } else { - qemu_log("[%u:%u] Disabled instruction logging @ " TARGET_FMT_lx " \n", - env_cpu(env)->cpu_index, cpu_get_asid(env, pc), pc); + event.id = LOG_EVENT_REGDUMP; + if (cpu_log_instr_event_regdump(env, &event)) { + return; } + g_array_append_val(entry->events, event); } -/* CHERI trace V3 format emitters */ - -/* - * Emit cvtrace trace trace header. This is a magic byte + string - */ -static void emit_cvtrace_header(CPUArchState *env) +static inline void emit_start_event(cpu_log_instr_state_t *cpulog, cpu_log_entry_t *entry, target_ulong pc) { - FILE *logfile = qemu_log_lock(); - char buffer[sizeof(cheri_trace_entry_t)]; + log_event_t event; - buffer[0] = CTE_QEMU_VERSION; - g_strlcpy(buffer + 1, CTE_QEMU_MAGIC, sizeof(buffer) - 2); - fwrite(buffer, sizeof(buffer), 1, logfile); - qemu_log_unlock(logfile); -} - -/* - * Emit cvtrace trace entry. - * Note: this format is very MIPS-specific. - */ -static void emit_cvtrace_entry(CPUArchState *env, cpu_log_instr_info_t *iinfo) -{ - FILE *logfile; - cheri_trace_entry_t entry; - static uint16_t cycles = 0; // TODO(am2419): this should be a per-cpu counter. - uint32_t *insn = (uint32_t *)&iinfo->insn_bytes[0]; - - entry.entry_type = CTE_NO_REG; - entry.thread = (uint8_t)env_cpu(env)->cpu_index; - entry.asid = (uint8_t)iinfo->asid; - entry.pc = cpu_to_be64(iinfo->pc); - entry.cycles = cpu_to_be16(cycles++); + event.id = LOG_EVENT_STATE; + event.state.next_state = LOG_EVENT_STATE_START; + event.state.level = cpulog->loglevel; + event.state.pc = pc; + /* Start events always have incomplete instruction data */ + entry->flags &= ~LI_FLAG_HAS_INSTR_DATA; /* - * TODO(am2419): The instruction bytes are alread in target byte-order, however - * cheritrace does not currently expect this. + * Also update PC to the one given in the start event. + * This ensures that the pc field is always correct, even on the first + * incomplete entry of the trace, where the start trigger occurs. + * XXX-AM: Does this mean that we can do away with the state.pc field? */ - entry.inst = cpu_to_be32(*insn); - switch (iinfo->flags & LI_FLAG_INTR_MASK) { - case LI_FLAG_INTR_TRAP: - entry.exception = (uint8_t)(iinfo->intr_code & 0xff); - case LI_FLAG_INTR_ASYNC: - entry.exception = 0; - default: - entry.exception = CTE_EXCEPTION_NONE; - } - - if (iinfo->regs->len) { - log_reginfo_t *rinfo = &g_array_index(iinfo->regs, log_reginfo_t, 0); -#ifndef TARGET_CHERI - log_assert(!reginfo_is_cap(rinfo) && "Capability register access " - "without CHERI support"); -#else - if (reginfo_is_cap(rinfo)) { - cap_register_t intcap; - cap_register_t *cr = &rinfo->cap; + entry->pc = pc; - if (!reginfo_has_cap(rinfo)) { - // cvtrace expects a null capability in the integer case - cr = null_capability(&intcap); - } - uint64_t metadata = (((uint64_t)cr->cr_tag << 63) | - ((uint64_t)cap_get_otype_signext(cr) << 32) | - ((uint64_t)COMBINED_PERMS_VALUE(cr) << 1) | - (uint64_t)(cap_is_unsealed(cr) ? 0 : 1)); - - entry.entry_type = CTE_CAP; - entry.val2 = cpu_to_be64(metadata); - entry.val3 = cpu_to_be64(cap_get_cursor(cr)); - entry.val4 = cpu_to_be64(cap_get_base(cr)); - entry.val5 = cpu_to_be64(cap_get_length_sat(cr)); - } else -#endif - { - entry.entry_type = CTE_GPR; - entry.val2 = cpu_to_be64(rinfo->gpr); - } - } - - if (iinfo->mem->len) { - log_meminfo_t *minfo = &g_array_index(iinfo->mem, log_meminfo_t, 0); -#ifndef TARGET_CHERI - log_assert((minfo->flags & LMI_CAP) == 0 && "Capability memory access " - "without CHERI support"); -#endif - entry.val1 = cpu_to_be64(minfo->addr); - // Hack to avoid checking for GPR or CAP - if (minfo->flags & LMI_LD) - entry.entry_type += 1; - else if (minfo->flags & LMI_ST) - entry.entry_type += 2; - } - - logfile = qemu_log_lock(); - fwrite(&entry, sizeof(entry), 1, logfile); - qemu_log_unlock(logfile); + g_array_append_val(entry->events, event); } -static void emit_cvtrace_start(CPUArchState *env, target_ulong pc) +static inline void emit_stop_event(cpu_log_instr_state_t *cpulog, cpu_log_entry_t *entry, target_ulong pc) { - // TODO(am2419) Emit an event for instruction logging start -} + log_event_t event; -static void emit_cvtrace_stop(CPUArchState *env, target_ulong pc) -{ - // TODO(am2419) Emit an event for instruction logging stop -} + event.id = LOG_EVENT_STATE; + event.state.next_state = LOG_EVENT_STATE_STOP; + event.state.level = cpulog->loglevel; + event.state.pc = pc; -/* Core instruction logging implementation */ - -static inline void emit_start_event(CPUArchState *env, target_ulong pc) -{ - if ((get_cpu_log_state(env)->flags & QEMU_LOG_INSTR_FLAG_BUFFERED) == 0) - trace_format->emit_start(env, pc); -} - -static inline void emit_stop_event(CPUArchState *env, target_ulong pc) -{ - if ((get_cpu_log_state(env)->flags & QEMU_LOG_INSTR_FLAG_BUFFERED) == 0) - trace_format->emit_stop(env, pc); + g_array_append_val(entry->events, event); } -static inline void emit_entry_event(CPUArchState *env, cpu_log_instr_info_t *iinfo) +/* Reset instruction info buffer for next instruction */ +static void reset_log_buffer(cpu_log_instr_state_t *cpulog, + cpu_log_entry_t *entry) { - cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + log_event_t *evt; + int i; - if (cpulog->flags & QEMU_LOG_INSTR_FLAG_BUFFERED) { - cpulog->ring_head = (cpulog->ring_head + 1) % cpulog->instr_info->len; - if (cpulog->ring_tail == cpulog->ring_head) - cpulog->ring_tail = (cpulog->ring_tail + 1) % cpulog->instr_info->len; - } - else { - trace_format->emit_entry(env, iinfo); + memset(&entry->cpu_log_entry_startzero, 0, + ((char *)&entry->cpu_log_entry_endzero - + (char *)&entry->cpu_log_entry_startzero)); + g_array_remove_range(entry->regs, 0, entry->regs->len); + g_array_remove_range(entry->mem, 0, entry->mem->len); + /* + * Need to free any dynamic allocation in the event structures to + * avoid leaking memory. This is called before the log entry is + * reused, so the memory might be reclaimed much later than the allocation + * time. + */ + for (i = 0; i < entry->events->len; i++) { + evt = &g_array_index(entry->events, log_event_t, i); + if (evt->id == LOG_EVENT_REGDUMP) { + g_array_free(evt->reg_dump.gpr, true); + } } -} - -/* Reset instruction info buffer for next instruction */ -static void reset_log_buffer(cpu_log_instr_state_t *cpulog, - cpu_log_instr_info_t *iinfo) -{ - memset(&iinfo->cpu_log_iinfo_startzero, 0, - ((char *)&iinfo->cpu_log_iinfo_endzero - - (char *)&iinfo->cpu_log_iinfo_startzero)); - g_array_remove_range(iinfo->regs, 0, iinfo->regs->len); - g_array_remove_range(iinfo->mem, 0, iinfo->mem->len); - g_string_erase(iinfo->txt_buffer, 0, -1); + g_array_remove_range(entry->events, 0, entry->events->len); + g_string_erase(entry->txt_buffer, 0, -1); cpulog->force_drop = false; cpulog->starting = false; } /* Common instruction commit implementation */ + static void do_instr_commit(CPUArchState *env) { cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); + cpu_log_instr_filter_fn_t filter; + int i; log_assert(cpulog != NULL && "Invalid log state"); - log_assert(iinfo != NULL && "Invalid log buffer"); + log_assert(entry != NULL && "Invalid log buffer"); if (cpulog->force_drop) return; - if (cpulog->starting) { - cpulog->starting = false; - emit_start_event(env, cpu_get_recent_pc(env)); - return; + for (i = 0; i < cpulog->filters->len; i++) { + filter = g_array_index(cpulog->filters, cpu_log_instr_filter_fn_t, i); + if (!filter(entry)) { + return; + } } - /* Check for dfilter matches in this instruction */ - if (debug_regions) { - int i, j; - bool match = false; - for (i = 0; !match && i < debug_regions->len; i++) { - Range *range = &g_array_index(debug_regions, Range, i); - match = range_contains(range, iinfo->pc); - if (match) - break; - - for (j = 0; j < iinfo->mem->len; j++) { - log_meminfo_t *minfo = &g_array_index(iinfo->mem, log_meminfo_t, j); - match = range_contains(range, minfo->addr); - if (match) - break; - } - } - if (match) - emit_entry_event(env, iinfo); + if (cpulog->flags & QEMU_LOG_INSTR_FLAG_BUFFERED) { + cpulog->ring_head = (cpulog->ring_head + 1) % cpulog->entry_buffer->len; + if (cpulog->ring_tail == cpulog->ring_head) + cpulog->ring_tail = + (cpulog->ring_tail + 1) % cpulog->entry_buffer->len; } else { - /* dfilter disabled, always log */ - emit_entry_event(env, iinfo); + trace_backend->emit_instr(env, entry); + QEMU_LOG_INSTR_INC_STAT(cpulog, entries_emitted); } } @@ -640,14 +295,17 @@ static void do_cpu_loglevel_switch(CPUState *cpu, run_on_cpu_data data) { CPUArchState *env = cpu->env_ptr; cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); qemu_log_instr_loglevel_t prev_level = cpulog->loglevel; bool prev_level_active = cpulog->loglevel_active; - qemu_log_instr_loglevel_t next_level = data.host_int; + qemu_log_next_level_arg_t *arg = data.host_ptr; + target_ulong pc = (arg->global) ? cpu_get_recent_pc(env) : arg->pc; bool next_level_active; + log_assert(qemu_loglevel_mask(CPU_LOG_INSTR)); + /* Decide whether we have to pause/resume logging */ - switch (next_level) { + switch (arg->next_level) { case QEMU_LOG_INSTR_LOGLEVEL_NONE: next_level_active = false; break; @@ -656,57 +314,72 @@ static void do_cpu_loglevel_switch(CPUState *cpu, run_on_cpu_data data) break; case QEMU_LOG_INSTR_LOGLEVEL_USER: /* - * Assume iinfo holds the mode switch that caused cpu_loglevel_switch + * Assume entry holds the mode switch that caused cpu_loglevel_switch * to be called */ - if (iinfo->flags & LI_FLAG_MODE_SWITCH) - next_level_active = (iinfo->next_cpu_mode == QEMU_LOG_INSTR_CPU_USER); + if (entry->flags & LI_FLAG_MODE_SWITCH) + next_level_active = + (entry->next_cpu_mode == QEMU_LOG_INSTR_CPU_USER); else next_level_active = cpu_in_user_mode(env); break; default: log_assert(false && "Invalid cpu instruction log level"); - warn_report("Invalid cpu %d instruction log level\r", - cpu->cpu_index); + warn_report("Invalid cpu %d instruction log level\r", cpu->cpu_index); } /* Update level */ - cpulog->loglevel = next_level; + cpulog->loglevel = arg->next_level; cpulog->loglevel_active = next_level_active; /* Check if this was a no-op */ - if (next_level == prev_level && prev_level_active == next_level_active) - return; - - /* Flushing all translations makes things incredibly slow. Instead, - * we put whether tracing is currently enabled into cflags */ - + if (arg->next_level == prev_level && + prev_level_active == next_level_active) { + goto done; + } + /* tb_flush(cpu); */ /* Emit start/stop events */ if (prev_level_active) { if (cpulog->starting) { - reset_log_buffer(cpulog, iinfo); - return; + reset_log_buffer(cpulog, entry); + goto done; } + emit_stop_event(cpulog, entry, pc); + QEMU_LOG_INSTR_INC_STAT(cpulog, trace_stop); do_instr_commit(env); - emit_stop_event(env, cpu_get_recent_pc(env)); - /* Instruction commit may have advanced to the next iinfo buffer slot */ - iinfo = get_cpu_log_instr_info(env); - reset_log_buffer(cpulog, iinfo); + /* Instruction commit may have advanced to the next entry buffer slot */ + entry = get_cpu_log_entry(env); + reset_log_buffer(cpulog, entry); } if (next_level_active) { cpulog->starting = true; + /* + * Note: the start event is emitted by the first instruction being + * traced + */ + emit_start_event(cpulog, entry, pc); + emit_regdump_event(env, entry); + QEMU_LOG_INSTR_INC_STAT(cpulog, trace_start); } + +done: + g_free(arg); } -static void cpu_loglevel_switch(CPUArchState *env, - qemu_log_instr_loglevel_t level) +static void cpu_loglevel_switch(CPUArchState *env, target_ulong pc, + qemu_log_instr_loglevel_t level, bool global) { + qemu_log_next_level_arg_t *arg = g_new(qemu_log_next_level_arg_t, 1); + + arg->next_level = level; + arg->pc = pc; + arg->global = global; async_safe_run_on_cpu(env_cpu(env), do_cpu_loglevel_switch, - RUN_ON_CPU_HOST_INT(level)); + RUN_ON_CPU_HOST_PTR(arg)); } /* Start global logging flag if it was disabled */ -static void global_loglevel_enable() +static void global_loglevel_enable(void) { if (!qemu_loglevel_mask(CPU_LOG_INSTR)) qemu_set_log_internal(qemu_loglevel | CPU_LOG_INSTR); @@ -719,10 +392,11 @@ static void global_loglevel_enable() */ static void do_global_loglevel_switch(CPUState *cpu, run_on_cpu_data data) { - qemu_log_instr_loglevel_t level = data.host_int; + qemu_log_next_level_arg_t *arg = data.host_ptr; - if (level != QEMU_LOG_INSTR_LOGLEVEL_NONE) + if (arg->next_level != QEMU_LOG_INSTR_LOGLEVEL_NONE) { global_loglevel_enable(); + } /* * TODO(am2419): To do things cleanly, we should clear the CPU_LOG_INSTR * flag when stopping, however to do this we would need to keep track @@ -730,7 +404,7 @@ static void do_global_loglevel_switch(CPUState *cpu, run_on_cpu_data data) * clear the flag on the last CPU. * qemu_set_log_internal(qemu_loglevel & (~CPU_LOG_INSTR)); */ - do_cpu_loglevel_switch(cpu, RUN_ON_CPU_HOST_INT(level)); + do_cpu_loglevel_switch(cpu, data); } /* @@ -743,20 +417,25 @@ static void do_global_loglevel_switch(CPUState *cpu, run_on_cpu_data data) int qemu_log_instr_global_switch(int log_flags) { CPUState *cpu; - qemu_log_instr_loglevel_t level; + qemu_log_next_level_arg_t *arg; - if (log_flags & CPU_LOG_INSTR_U) { - level = QEMU_LOG_INSTR_LOGLEVEL_USER; - log_flags |= CPU_LOG_INSTR; - } else if (log_flags & CPU_LOG_INSTR) { - level = QEMU_LOG_INSTR_LOGLEVEL_ALL; - } else { - level = QEMU_LOG_INSTR_LOGLEVEL_NONE; - } + CPU_FOREACH(cpu) + { + arg = g_new(qemu_log_next_level_arg_t, 1); + + if (log_flags & CPU_LOG_INSTR_U) { + arg->next_level = QEMU_LOG_INSTR_LOGLEVEL_USER; + log_flags |= CPU_LOG_INSTR; + } else if (log_flags & CPU_LOG_INSTR) { + arg->next_level = QEMU_LOG_INSTR_LOGLEVEL_ALL; + } else { + arg->next_level = QEMU_LOG_INSTR_LOGLEVEL_NONE; + } + arg->global = true; - CPU_FOREACH(cpu) { + /* arg ownership transferred to do_global_loglevel_switch */ async_safe_run_on_cpu(cpu, do_global_loglevel_switch, - RUN_ON_CPU_HOST_INT(level)); + RUN_ON_CPU_HOST_PTR(arg)); } return log_flags; @@ -765,26 +444,52 @@ int qemu_log_instr_global_switch(int log_flags) /* * Initialize instruction info entry from the ring buffer. */ -static void qemu_log_instr_info_init(cpu_log_instr_info_t *iinfo) +static void qemu_log_entry_init(cpu_log_entry_t *entry) { - if (iinfo->txt_buffer == NULL) - iinfo->txt_buffer = g_string_new(NULL); - if (iinfo->regs == NULL) - iinfo->regs = g_array_new(false, true, sizeof(log_reginfo_t)); - if (iinfo->mem == NULL) - iinfo->mem = g_array_new(false, true, sizeof(log_meminfo_t)); + if (entry->txt_buffer == NULL) { + entry->txt_buffer = g_string_new(NULL); + } + if (entry->regs == NULL) { + entry->regs = g_array_new(false, true, sizeof(log_reginfo_t)); + } + if (entry->mem == NULL) { + entry->mem = g_array_new(false, true, sizeof(log_meminfo_t)); + } + if (entry->events == NULL) { + entry->events = g_array_new(false, true, sizeof(log_event_t)); + } } /* * Clear an instruction info entry from the ring buffer. */ -static void qemu_log_instr_info_destroy(gpointer data) +static void qemu_log_entry_destroy(gpointer data) { - cpu_log_instr_info_t *iinfo = data; + cpu_log_entry_t *entry = data; + log_event_t *evt; + int i; + + g_string_free(entry->txt_buffer, true); + g_array_free(entry->regs, true); + g_array_free(entry->mem, true); + for (i = 0; i < entry->events->len; i++) { + evt = &g_array_index(entry->events, log_event_t, i); + if (evt->id == LOG_EVENT_REGDUMP) { + /* Need to free the register dump array */ + g_array_free(evt->reg_dump.gpr, true); + } + } + g_array_free(entry->events, true); +} - g_string_free(iinfo->txt_buffer, TRUE); - g_array_free(iinfo->regs, TRUE); - g_array_free(iinfo->mem, TRUE); +/* + * CLI parameters hook to configure the logfile for instruction traces. + * We stop reusing the qemu logfile because we don't want to RCU-lock it + * and we want to run our own aio context with it. + */ +void qemu_log_instr_conf_logfile(const char *name) +{ + trace_logfile_name = name; } /* @@ -797,62 +502,103 @@ static void qemu_log_instr_info_destroy(gpointer data) void qemu_log_instr_init(CPUState *cpu) { cpu_log_instr_state_t *cpulog = &cpu->log_state; - GArray *iinfo_ring = g_array_sized_new(FALSE, TRUE, - sizeof(cpu_log_instr_info_t), reset_entry_buffer_size); - cpu_log_instr_info_t *iinfo; + GArray *entry_ring = g_array_sized_new(false, true, sizeof(cpu_log_entry_t), + reset_entry_buffer_size); + qemu_log_next_level_arg_t *start_level; + cpu_log_entry_t *entry; int i; - g_array_set_size(iinfo_ring, reset_entry_buffer_size); - g_array_set_clear_func(iinfo_ring, qemu_log_instr_info_destroy); + g_array_set_size(entry_ring, reset_entry_buffer_size); + g_array_set_clear_func(entry_ring, qemu_log_entry_destroy); - for (i = 0; i < iinfo_ring->len; i++) { - iinfo = &g_array_index(iinfo_ring, cpu_log_instr_info_t, i); - qemu_log_instr_info_init(iinfo); + for (i = 0; i < entry_ring->len; i++) { + entry = &g_array_index(entry_ring, cpu_log_entry_t, i); + qemu_log_entry_init(entry); } cpulog->loglevel = QEMU_LOG_INSTR_LOGLEVEL_NONE; cpulog->loglevel_active = false; - cpulog->instr_info = iinfo_ring; + cpulog->filters = g_array_sized_new( + false, true, sizeof(cpu_log_instr_filter_fn_t), LOG_INSTR_FILTER_MAX); + cpulog->entry_buffer = entry_ring; cpulog->ring_head = 0; cpulog->ring_tail = 0; - reset_log_buffer(cpulog, iinfo); - - // Make sure we are using the correct trace format. - if (trace_format == NULL) { - trace_format = &trace_formats[qemu_log_instr_format]; - // Only emit header on first init - if (trace_format->emit_header) - trace_format->emit_header(cpu->env_ptr); + reset_log_buffer(cpulog, entry); + + /* Make sure we are using the correct trace format. */ + if (trace_backend == NULL) { + trace_backend = &trace_backends[qemu_log_instr_backend]; + } + + /* Initialize backend state on this CPU */ + if (trace_backend->init) { + trace_backend->init(cpu->env_ptr, trace_logfile_name); } /* If we are starting with instruction logging enabled, switch it on now */ - if (qemu_loglevel_mask(CPU_LOG_INSTR_U)) - do_cpu_loglevel_switch( - cpu, RUN_ON_CPU_HOST_INT(QEMU_LOG_INSTR_LOGLEVEL_USER)); - else if (qemu_loglevel_mask(CPU_LOG_INSTR)) - do_cpu_loglevel_switch(cpu, - RUN_ON_CPU_HOST_INT(QEMU_LOG_INSTR_LOGLEVEL_ALL)); + if (qemu_loglevel_mask(CPU_LOG_INSTR | CPU_LOG_INSTR_U)) { + start_level = g_new(qemu_log_next_level_arg_t, 1); + if (qemu_loglevel_mask(CPU_LOG_INSTR_U)) { + assert(qemu_loglevel_mask(CPU_LOG_INSTR) && + "CPU_LOG_INSTR_U implies CPU_LOG_INSTR broken"); + start_level->next_level = QEMU_LOG_INSTR_LOGLEVEL_USER; + } else { + start_level->next_level = QEMU_LOG_INSTR_LOGLEVEL_ALL; + } + start_level->global = true; + do_cpu_loglevel_switch(cpu, RUN_ON_CPU_HOST_PTR(start_level)); + } + + if (reset_filters != NULL) { + for (i = 0; i < reset_filters->len; i++) { + qemu_log_instr_add_filter( + cpu, g_array_index(reset_filters, cpu_log_instr_filter_t, i)); + } + } + + memset(&cpulog->stats, 0, sizeof(cpulog->stats)); +} + +static void do_log_backend_sync(CPUState *cpu, run_on_cpu_data _unused) +{ + if (trace_backend->sync != NULL) { + trace_backend->sync(cpu->env_ptr); + } + dump_debug_stats(cpu); +} + +/* + * Attempt to syncronize buffers in the tracing backend for each CPU. + * NOTE: This is a blocking operation that may delay the exit path. + */ +void qemu_log_instr_sync_buffers(void) +{ + CPUState *cpu; + + CPU_FOREACH(cpu) + { + run_on_cpu(cpu, do_log_backend_sync, RUN_ON_CPU_NULL); + } } -static void -do_log_buffer_resize(CPUState *cpu, run_on_cpu_data data) +static void do_log_buffer_resize(CPUState *cpu, run_on_cpu_data data) { unsigned long new_size = data.host_ulong; cpu_log_instr_state_t *cpulog = get_cpu_log_state(cpu->env_ptr); - cpu_log_instr_info_t *iinfo; + cpu_log_entry_t *entry; int i; - g_array_set_size(cpulog->instr_info, new_size); + g_array_set_size(cpulog->entry_buffer, new_size); cpulog->ring_head = 0; cpulog->ring_tail = 0; - for (i = 0; i < cpulog->instr_info->len; i++) { + for (i = 0; i < cpulog->entry_buffer->len; i++) { /* * Clear and reinitialize all the entries, * a bit overkill but should not be a frequent operation. */ - iinfo = &g_array_index(cpulog->instr_info, cpu_log_instr_info_t, i); - qemu_log_instr_info_init(iinfo); - reset_log_buffer(cpulog, iinfo); + entry = &g_array_index(cpulog->entry_buffer, cpu_log_entry_t, i); + qemu_log_entry_init(entry); + reset_log_buffer(cpulog, entry); } } @@ -861,16 +607,17 @@ void qemu_log_instr_set_buffer_size(unsigned long new_size) CPUState *cpu; if (new_size < MIN_ENTRY_BUFFER_SIZE) { - warn_report("New trace entry buffer size is too small < %zu, ignored.\n", + warn_report("New trace entry buffer size is too small < %zu, ignored.", (size_t)MIN_ENTRY_BUFFER_SIZE); return; } /* Set this in case this is called from qemu option parsing */ reset_entry_buffer_size = new_size; - CPU_FOREACH(cpu) { + CPU_FOREACH(cpu) + { async_safe_run_on_cpu(cpu, do_log_buffer_resize, - RUN_ON_CPU_HOST_ULONG(new_size)); + RUN_ON_CPU_HOST_ULONG(new_size)); } } @@ -894,25 +641,26 @@ bool qemu_log_instr_check_enabled(CPUArchState *env) * initiated here. */ void qemu_log_instr_mode_switch(CPUArchState *env, - qemu_log_instr_cpu_mode_t mode, target_ulong pc) + qemu_log_instr_cpu_mode_t mode, target_ulong pc) { cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_assert(cpulog != NULL && "Invalid log state"); - log_assert(iinfo != NULL && "Invalid log info"); + log_assert(entry != NULL && "Invalid log info"); - iinfo->flags |= LI_FLAG_MODE_SWITCH; - iinfo->next_cpu_mode = mode; + entry->flags |= LI_FLAG_MODE_SWITCH; + entry->next_cpu_mode = mode; /* If we are not logging in user-only mode, bail */ if (!qemu_loglevel_mask(CPU_LOG_INSTR) || - cpulog->loglevel != QEMU_LOG_INSTR_LOGLEVEL_USER) + cpulog->loglevel != QEMU_LOG_INSTR_LOGLEVEL_USER) { return; + } /* Check if we are switching to an interesting mode */ if ((mode == QEMU_LOG_INSTR_CPU_USER) != cpulog->loglevel_active) { - cpu_loglevel_switch(env, cpulog->loglevel); + cpu_loglevel_switch(env, pc, cpulog->loglevel, false); } } @@ -928,26 +676,27 @@ void qemu_log_instr_drop(CPUArchState *env) void qemu_log_instr_commit(CPUArchState *env) { cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_assert(cpulog != NULL && "Invalid log state"); - log_assert(iinfo != NULL && "Invalid log info"); + log_assert(entry != NULL && "Invalid log info"); do_instr_commit(env); - /* commit may have advanced to the next iinfo buffer slot */ - iinfo = get_cpu_log_instr_info(env); - reset_log_buffer(cpulog, iinfo); + /* commit may have advanced to the next entry buffer slot */ + entry = get_cpu_log_entry(env); + reset_log_buffer(cpulog, entry); } -void qemu_log_instr_reg(CPUArchState *env, const char *reg_name, target_ulong value) +void qemu_log_instr_reg(CPUArchState *env, const char *reg_name, + target_ulong value) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_reginfo_t r; r.flags = 0; r.name = reg_name; r.gpr = value; - g_array_append_val(iinfo->regs, r); + g_array_append_val(entry->regs, r); } void helper_qemu_log_instr_reg(CPUArchState *env, const void *reg_name, @@ -959,15 +708,15 @@ void helper_qemu_log_instr_reg(CPUArchState *env, const void *reg_name, #ifdef TARGET_CHERI void qemu_log_instr_cap(CPUArchState *env, const char *reg_name, - const cap_register_t *cr) + const cap_register_t *cr) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_reginfo_t r; r.flags = LRI_CAP_REG | LRI_HOLDS_CAP; r.name = reg_name; r.cap = *cr; - g_array_append_val(iinfo->regs, r); + g_array_append_val(entry->regs, r); } void helper_qemu_log_instr_cap(CPUArchState *env, const void *reg_name, @@ -978,15 +727,15 @@ void helper_qemu_log_instr_cap(CPUArchState *env, const void *reg_name, } void qemu_log_instr_cap_int(CPUArchState *env, const char *reg_name, - target_ulong value) + target_ulong value) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_reginfo_t r; r.flags = LRI_CAP_REG; r.name = reg_name; r.gpr = value; - g_array_append_val(iinfo->regs, r); + g_array_append_val(entry->regs, r); } #endif @@ -994,14 +743,14 @@ static inline void qemu_log_instr_mem_int(CPUArchState *env, target_ulong addr, int flags, TCGMemOpIdx oi, target_ulong value) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_meminfo_t m; m.flags = flags; m.op = get_memop(oi); m.addr = addr; m.value = value; - g_array_append_val(iinfo->mem, m); + g_array_append_val(entry->mem, m); } void qemu_log_instr_ld_int(CPUArchState *env, target_ulong addr, TCGMemOpIdx oi, @@ -1023,18 +772,18 @@ void qemu_log_instr_st_int(CPUArchState *env, target_ulong addr, TCGMemOpIdx oi, * as well. Need to think whether there is value to keep logging what * was loaded directly. */ -static inline void qemu_log_instr_mem_cap( - CPUArchState *env, target_ulong addr, int flags, - const cap_register_t *value) +static inline void qemu_log_instr_mem_cap(CPUArchState *env, target_ulong addr, + int flags, + const cap_register_t *value) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); log_meminfo_t m; m.flags = flags; m.op = 0; m.addr = addr; m.cap = *value; - g_array_append_val(iinfo->mem, m); + g_array_append_val(entry->mem, m); } void qemu_log_instr_ld_cap(CPUArchState *env, target_ulong addr, @@ -1052,60 +801,102 @@ void qemu_log_instr_st_cap(CPUArchState *env, target_ulong addr, void qemu_log_instr(CPUArchState *env, target_ulong pc, const char *insn, uint32_t size) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); - iinfo->pc = pc; - iinfo->insn_size = size; - memcpy(iinfo->insn_bytes, insn, size); + entry->pc = pc; + entry->insn_size = size; + entry->flags |= LI_FLAG_HAS_INSTR_DATA; + memcpy(entry->insn_bytes, insn, size); } void qemu_log_instr_asid(CPUArchState *env, uint16_t asid) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); - iinfo->asid = asid; + entry->asid = asid; } void qemu_log_instr_exception(CPUArchState *env, uint32_t code, target_ulong vector, target_ulong faultaddr) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); - iinfo->flags |= LI_FLAG_INTR_TRAP; - iinfo->intr_code = code; - iinfo->intr_vector = vector; - iinfo->intr_faultaddr = faultaddr; + entry->flags |= LI_FLAG_INTR_TRAP; + entry->intr_code = code; + entry->intr_vector = vector; + entry->intr_faultaddr = faultaddr; } void qemu_log_instr_interrupt(CPUArchState *env, uint32_t code, target_ulong vector) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); + + entry->flags |= LI_FLAG_INTR_ASYNC; + entry->intr_code = code; + entry->intr_vector = vector; +} + +void qemu_log_instr_event(CPUArchState *env, log_event_t *evt) +{ + cpu_log_entry_t *entry = get_cpu_log_entry(env); + + /* Note: transfer ownership of dynamically allocated data in evt */ + g_array_append_val(entry->events, *evt); +} + +void qemu_log_instr_event_create_regdump(log_event_t *evt, int nregs) +{ + evt->reg_dump.gpr = g_array_sized_new(false, false, sizeof(log_reginfo_t), + nregs * sizeof(log_reginfo_t)); +} + +void qemu_log_instr_event_dump_reg(log_event_t *evt, const char *reg_name, + target_ulong value) +{ + log_reginfo_t r; + + r.flags = 0; + r.name = reg_name; + r.gpr = value; + /* + * Assume that the reg_dump array has been initialized, + * should put an assertion in here. + */ + g_array_append_val(evt->reg_dump.gpr, r); +} + +#ifdef TARGET_CHERI +void qemu_log_instr_event_dump_cap(log_event_t *evt, const char *reg_name, + const cap_register_t *value) +{ + log_reginfo_t r; - iinfo->flags |= LI_FLAG_INTR_ASYNC; - iinfo->intr_code = code; - iinfo->intr_vector = vector; + r.flags = LRI_CAP_REG | LRI_HOLDS_CAP; + r.name = reg_name; + r.cap = *value; + g_array_append_val(evt->reg_dump.gpr, r); } -void qemu_log_instr_evt(CPUArchState *env, uint16_t fn, target_ulong arg0, - target_ulong arg1, target_ulong arg2, - target_ulong arg3) +void qemu_log_instr_event_dump_cap_int(log_event_t *evt, const char *reg_name, + target_ulong value) { - /* iinfo->cv_buffer.entry_type = CVT_EVT; */ - /* iinfo->cv_buffer.val5 = fn; */ - /* iinfo->cv_buffer.val1 = arg0; */ - /* iinfo->cv_buffer.val2 = arg1; */ - /* iinfo->cv_buffer.val3 = arg2; */ - /* iinfo->cv_buffer.val4 = arg3; */ + log_reginfo_t r; + + r.flags = LRI_CAP_REG; + r.name = reg_name; + r.gpr = value; + g_array_append_val(evt->reg_dump.gpr, r); } +#endif void qemu_log_instr_extra(CPUArchState *env, const char *msg, ...) { - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); + cpu_log_entry_t *entry = get_cpu_log_entry(env); va_list va; va_start(va, msg); - g_string_append_vprintf(iinfo->txt_buffer, msg, va); + g_string_append_vprintf(entry->txt_buffer, msg, va); va_end(va); } @@ -1477,15 +1268,32 @@ void qemu_log_instr_flush(CPUArchState *env) { cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); size_t curr = cpulog->ring_tail; - cpu_log_instr_info_t *iinfo; + cpu_log_entry_t *entry = get_cpu_log_entry(env); + log_event_t event; - if ((cpulog->flags & QEMU_LOG_INSTR_FLAG_BUFFERED) == 0) + /* Emit FLUSH event so that it can be picked up by backends */ + event.id = LOG_EVENT_STATE; + event.state.next_state = LOG_EVENT_STATE_FLUSH; + event.state.level = cpulog->loglevel; + event.state.pc = entry->pc; + qemu_log_instr_event(env, &event); + + /* + * If tracing is disabled, force the commit of events in this + * trace entry. + */ + if (!qemu_log_instr_check_enabled(env)) { + qemu_log_instr_commit(env); + } + if ((cpulog->flags & QEMU_LOG_INSTR_FLAG_BUFFERED) == 0) { return; + } while (curr != cpulog->ring_head) { - iinfo = &g_array_index(cpulog->instr_info, cpu_log_instr_info_t, curr); - trace_format->emit_entry(env, iinfo); - curr = (curr + 1) % cpulog->instr_info->len; + entry = &g_array_index(cpulog->entry_buffer, cpu_log_entry_t, curr); + trace_backend->emit_instr(env, entry); + QEMU_LOG_INSTR_INC_STAT(cpulog, entries_emitted); + curr = (curr + 1) % cpulog->entry_buffer->len; } cpulog->ring_tail = cpulog->ring_head; } @@ -1507,8 +1315,7 @@ void helper_qemu_log_printf_dump(CPUArchState *env) return; } - cpu_log_instr_info_t *iinfo = get_cpu_log_instr_info(env); - + cpu_log_entry_t *entry = get_cpu_log_entry(env); while (valid) { size_t ndx = ctz64(valid); valid ^= (1 << ndx); @@ -1516,7 +1323,7 @@ void helper_qemu_log_printf_dump(CPUArchState *env) cpulog->qemu_log_printf_buf.args + (ndx * QEMU_LOG_PRINTF_ARG_MAX); const char *fmt = cpulog->qemu_log_printf_buf.fmts[ndx]; - g_string_append_printf_union_args(iinfo->txt_buffer, fmt, args); + g_string_append_printf_union_args(entry->txt_buffer, fmt, args); } } @@ -1541,8 +1348,9 @@ void helper_qemu_log_instr_buffer_flush(CPUArchState *env) qemu_log_instr_flush(env); } -/* Start logging all instructions on the current CPU */ -void helper_qemu_log_instr_start(CPUArchState *env, target_ulong pc) +static void do_qemu_log_instr_start(CPUArchState *env, target_ulong pc, + qemu_log_instr_loglevel_t level, + bool global) { cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); @@ -1550,62 +1358,69 @@ void helper_qemu_log_instr_start(CPUArchState *env, target_ulong pc) global_loglevel_enable(); /* If we are already started in the correct mode, bail */ - if (cpulog->loglevel == QEMU_LOG_INSTR_LOGLEVEL_ALL && - cpulog->loglevel_active) + if (cpulog->loglevel == level && cpulog->loglevel_active) { return; + } - cpu_loglevel_switch(env, QEMU_LOG_INSTR_LOGLEVEL_ALL); + cpu_loglevel_switch(env, pc, level, global); } -/* Start logging user-only instructions on the current CPU */ -void helper_qemu_log_instr_user_start(CPUArchState *env, target_ulong pc) +static void do_qemu_log_instr_stop(CPUArchState *env, target_ulong pc, + bool global) { - cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); - - log_assert(cpulog != NULL && "Invalid log state"); - global_loglevel_enable(); + cpu_loglevel_switch(env, pc, QEMU_LOG_INSTR_LOGLEVEL_NONE, global); +} - /* If we are already in the correct mode, bail */ - if (cpulog->loglevel == QEMU_LOG_INSTR_LOGLEVEL_USER) - return; +/* Start logging all instructions on the current CPU */ +void helper_qemu_log_instr_start(CPUArchState *env, target_ulong pc) +{ + do_qemu_log_instr_start(env, pc, QEMU_LOG_INSTR_LOGLEVEL_ALL, false); +} - cpu_loglevel_switch(env, QEMU_LOG_INSTR_LOGLEVEL_USER); +/* Start logging user-only instructions on the current CPU */ +void helper_qemu_log_instr_user_start(CPUArchState *env, target_ulong pc) +{ + do_qemu_log_instr_start(env, pc, QEMU_LOG_INSTR_LOGLEVEL_USER, false); } /* Stop logging on the current CPU */ void helper_qemu_log_instr_stop(CPUArchState *env, target_ulong pc) { - - cpu_loglevel_switch(env, QEMU_LOG_INSTR_LOGLEVEL_NONE); + do_qemu_log_instr_stop(env, pc, false); } /* Start logging all instructions on all CPUs */ -void helper_qemu_log_instr_allcpu_start() +void helper_qemu_log_instr_allcpu_start(void) { CPUState *cpu; - CPU_FOREACH(cpu) { - helper_qemu_log_instr_start(cpu->env_ptr, 0); + CPU_FOREACH(cpu) + { + do_qemu_log_instr_start(cpu->env_ptr, 0, QEMU_LOG_INSTR_LOGLEVEL_ALL, + true); } } /* Start logging user-only instructions on all CPUs */ -void helper_qemu_log_instr_allcpu_user_start() +void helper_qemu_log_instr_allcpu_user_start(void) { CPUState *cpu; - CPU_FOREACH(cpu) { - helper_qemu_log_instr_user_start(cpu->env_ptr, 0); + CPU_FOREACH(cpu) + { + do_qemu_log_instr_start(cpu->env_ptr, 0, QEMU_LOG_INSTR_LOGLEVEL_USER, + true); } } /* Stop logging instructions on all CPUs */ -void helper_qemu_log_instr_allcpu_stop() +void helper_qemu_log_instr_allcpu_stop(void) { CPUState *cpu; - CPU_FOREACH(cpu) { - helper_qemu_log_instr_stop(cpu->env_ptr, 0); + CPU_FOREACH(cpu) + { + do_qemu_log_instr_stop(cpu->env_ptr, 0, true); } } @@ -1642,37 +1457,154 @@ void helper_qemu_log_instr_store32(CPUArchState *env, target_ulong addr, qemu_log_instr_mem_int(env, addr, LMI_ST, oi, (uint64_t)value); } -void helper_log_value(CPUArchState *env, const void* ptr, uint64_t value) +void helper_log_value(CPUArchState *env, const void *ptr, uint64_t value) { qemu_maybe_log_instr_extra(env, "%s: " TARGET_FMT_plx "\n", ptr, value); } -static void emit_nop_start(CPUArchState *env, target_ulong pc) {} -static void emit_nop_stop(CPUArchState *env, target_ulong pc) {} -static void emit_nop_entry(CPUArchState *env, cpu_log_instr_info_t *iinfo) {} - /* - * Hooks for each trace format + * Instruction stream filtering */ -static trace_fmt_hooks_t trace_formats[] = { - { - .emit_header = NULL, - .emit_start = emit_text_start, - .emit_stop = emit_text_stop, - .emit_entry = emit_text_entry - }, + +void qemu_log_instr_add_filter(CPUState *cpu, cpu_log_instr_filter_t filter) +{ + cpu_log_instr_state_t *cpulog = &cpu->log_state; + cpu_log_instr_filter_fn_t new_fn, fn; + int i; + + if (filter >= LOG_INSTR_FILTER_MAX) { + warn_report("Instruction trace filter index is invalid"); + return; + } + new_fn = trace_filters[filter]; + /* Check for duplicates */ + for (i = 0; i < cpulog->filters->len; i++) { + fn = g_array_index(cpulog->filters, cpu_log_instr_filter_fn_t, i); + if (new_fn == fn) { + return; + } + } + g_array_append_val(cpulog->filters, new_fn); +} + +void qemu_log_instr_allcpu_add_filter(cpu_log_instr_filter_t filter) +{ + CPUState *cpu; + + CPU_FOREACH(cpu) { - .emit_header = emit_cvtrace_header, - .emit_start = emit_cvtrace_start, - .emit_stop = emit_cvtrace_stop, - .emit_entry = emit_cvtrace_entry - }, + qemu_log_instr_add_filter(cpu, filter); + } +} + +void qemu_log_instr_remove_filter(CPUState *cpu, cpu_log_instr_filter_t filter) +{ + cpu_log_instr_state_t *cpulog = &cpu->log_state; + cpu_log_instr_filter_fn_t curr; + int i; + + if (filter >= LOG_INSTR_FILTER_MAX) { + warn_report("Instruction trace filter index is invalid"); + return; + } + + for (i = 0; i < cpulog->filters->len; i++) { + curr = g_array_index(cpulog->filters, cpu_log_instr_filter_fn_t, i); + if (curr == trace_filters[filter]) { + g_array_remove_index_fast(cpulog->filters, i); + break; + } + } +} + +void qemu_log_instr_allcpu_remove_filter(cpu_log_instr_filter_t filter) +{ + CPUState *cpu; + + CPU_FOREACH(cpu) { - .emit_header = NULL, - .emit_start = emit_nop_start, - .emit_stop = emit_nop_stop, - .emit_entry = emit_nop_entry + qemu_log_instr_remove_filter(cpu, filter); } -}; +} + +void qemu_log_instr_add_startup_filter(cpu_log_instr_filter_t filter) +{ + if (reset_filters == NULL) { + reset_filters = + g_array_new(false, true, sizeof(cpu_log_instr_filter_t)); + } + + if (first_cpu == NULL) { + g_array_append_val(reset_filters, filter); + } else { + qemu_log_instr_allcpu_add_filter(filter); + } +} + +void qemu_log_instr_set_cli_filters(const char *filter_spec, Error **errp) +{ + gchar **names = g_strsplit(filter_spec, ",", 0); + int i; + + for (i = 0; names[i]; i++) { + if (strcmp(names[i], "events") == 0) { + qemu_log_instr_add_startup_filter(LOG_FILTER_EVENTS); + } else { + error_setg(errp, "Invalid trace filter name"); + break; + } + } +} + +/* + * Log entry filter reusing the qemu -dfilter infrastructure to + * filter instructions that run from or access given address ranges. + */ +static bool entry_mem_regions_filter(cpu_log_entry_t *entry) +{ + int i, j; + bool match = false; + if (debug_regions == NULL) { + return true; + } + + /* Check for dfilter matches in this instruction */ + for (i = 0; !match && i < debug_regions->len; i++) { + Range *range = &g_array_index(debug_regions, Range, i); + match = range_contains(range, entry->pc); + if (match) { + break; + } + + for (j = 0; j < entry->mem->len; j++) { + log_meminfo_t *minfo = &g_array_index(entry->mem, log_meminfo_t, j); + match = range_contains(range, minfo->addr); + if (match) { + break; + } + } + } + return match; +} + +/* + * Log entry filter to retain only entries with events attached. + */ +static bool entry_event_filter(cpu_log_entry_t *entry) +{ + if (entry->events->len > 0) { + return true; + } + return false; +} + +/* + * Trace filters mapping. Note that indices must match the + * cpu_log_instr_filter_t enum values. + */ +static cpu_log_instr_filter_fn_t trace_filters[] = { + entry_mem_regions_filter, + entry_event_filter, +}; #endif /* CONFIG_TCG_LOG_INSTR */ diff --git a/accel/tcg/log_instr_cvtrace.c b/accel/tcg/log_instr_cvtrace.c new file mode 100644 index 00000000000..fb10f9b1d3f --- /dev/null +++ b/accel/tcg/log_instr_cvtrace.c @@ -0,0 +1,181 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * CHERI Trace binary format backend + */ + +#include "qemu/osdep.h" +#include "qemu/log.h" +#include "cpu.h" +#include "exec/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/memop.h" +#include "disas/disas.h" + +/* + * CHERI binary trace format, originally used for MIPS only. + * The format is limited to one entry per instruction, each + * entry can hold at most one register modification and one + * memory address. + * Note that the CHERI format is the legacy MIPS format and + * assumes big-endian byte order. + */ +typedef struct { + uint8_t entry_type; +#define CTE_NO_REG 0 /* No register is changed. */ +#define CTE_GPR 1 /* GPR change (val2) */ +#define CTE_LD_GPR 2 /* Load into GPR (val2) from address (val1) */ +#define CTE_ST_GPR 3 /* Store from GPR (val2) to address (val1) */ +#define CTE_CAP 11 /* Cap change (val2,val3,val4,val5) */ +#define CTE_LD_CAP 12 /* Load Cap (val2,val3,val4,val5) from addr (val1) */ +#define CTE_ST_CAP 13 /* Store Cap (val2,val3,val4,val5) to addr (val1) */ + uint8_t exception; /* 0=none, 1=TLB Mod, 2=TLB Load, 3=TLB Store, etc. */ +#define CTE_EXCEPTION_NONE 31 + uint16_t cycles; /* Currently not used. */ + uint32_t inst; /* Encoded instruction. */ + uint64_t pc; /* PC value of instruction. */ + uint64_t val1; /* val1 is used for memory address. */ + uint64_t val2; /* val2, val3, val4, val5 are used for reg content. */ + uint64_t val3; + uint64_t val4; + uint64_t val5; + uint8_t thread; /* Hardware thread/CPU (i.e. cpu->cpu_index ) */ + uint8_t asid; /* Address Space ID */ +} __attribute__((packed)) cheri_trace_entry_t; + +/* Version 3 Cheri Stream Trace header info */ +#define CTE_QEMU_VERSION (0x80U + 3) +#define CTE_QEMU_MAGIC "CheriTraceV03" + +/* + * Emit cvtrace trace trace header. This is a magic byte + string + */ +void emit_cvtrace_header(CPUArchState *env) +{ + static bool initialized; + FILE *logfile; + char buffer[sizeof(cheri_trace_entry_t)]; + + if (initialized) { + return; + } + initialized = true; + logfile = qemu_log_lock(); + buffer[0] = CTE_QEMU_VERSION; + g_strlcpy(buffer + 1, CTE_QEMU_MAGIC, sizeof(buffer) - 2); + fwrite(buffer, sizeof(buffer), 1, logfile); + qemu_log_unlock(logfile); +} + +/* + * Emit cvtrace trace entry. + * Note: this format is very MIPS-specific. + */ +void emit_cvtrace_entry(CPUArchState *env, cpu_log_entry_t *entry) +{ + FILE *logfile; + cheri_trace_entry_t ct_entry; + /* TODO(am2419): this should be a per-cpu counter. */ + static uint16_t cycles; + uint32_t *insn = (uint32_t *)&entry->insn_bytes[0]; + + ct_entry.entry_type = CTE_NO_REG; + ct_entry.thread = (uint8_t)env_cpu(env)->cpu_index; + ct_entry.asid = (uint8_t)entry->asid; + ct_entry.pc = cpu_to_be64(entry->pc); + ct_entry.cycles = cpu_to_be16(cycles++); + /* + * TODO(am2419): The instruction bytes are alread in target byte-order, + * however cheritrace does not currently expect this. + */ + ct_entry.inst = cpu_to_be32(*insn); + switch (entry->flags & LI_FLAG_INTR_MASK) { + case LI_FLAG_INTR_TRAP: + ct_entry.exception = (uint8_t)(entry->intr_code & 0xff); + case LI_FLAG_INTR_ASYNC: + ct_entry.exception = 0; + default: + ct_entry.exception = CTE_EXCEPTION_NONE; + } + + if (entry->regs->len) { + log_reginfo_t *rinfo = &g_array_index(entry->regs, log_reginfo_t, 0); +#ifndef TARGET_CHERI + log_assert(!reginfo_is_cap(rinfo) && "Capability register access " + "without CHERI support"); +#else + if (reginfo_is_cap(rinfo)) { + cap_register_t intcap; + cap_register_t *cr = &rinfo->cap; + + if (!reginfo_has_cap(rinfo)) { + /* cvtrace expects a null capability in the integer case */ + cr = null_capability(&intcap); + } + uint64_t metadata = (((uint64_t)cr->cr_tag << 63) | + ((uint64_t)cap_get_otype_unsigned(cr) << 32) | + ((uint64_t)COMBINED_PERMS_VALUE(cr) << 1) | + (uint64_t)(cap_is_unsealed(cr) ? 0 : 1)); + + ct_entry.entry_type = CTE_CAP; + ct_entry.val2 = cpu_to_be64(metadata); + ct_entry.val3 = cpu_to_be64(cap_get_cursor(cr)); + ct_entry.val4 = cpu_to_be64(cap_get_base(cr)); + ct_entry.val5 = cpu_to_be64(cap_get_length_sat(cr)); + } else +#endif + { + ct_entry.entry_type = CTE_GPR; + ct_entry.val2 = cpu_to_be64(rinfo->gpr); + } + } + + if (entry->mem->len) { + log_meminfo_t *minfo = &g_array_index(entry->mem, log_meminfo_t, 0); +#ifndef TARGET_CHERI + log_assert((minfo->flags & LMI_CAP) == 0 && "Capability memory access " + "without CHERI support"); +#endif + ct_entry.val1 = cpu_to_be64(minfo->addr); + /* Hack to avoid checking for GPR or CAP */ + if (minfo->flags & LMI_LD) { + ct_entry.entry_type += 1; + } else if (minfo->flags & LMI_ST) { + ct_entry.entry_type += 2; + } + } + + logfile = qemu_log_lock(); + fwrite(&ct_entry, sizeof(ct_entry), 1, logfile); + qemu_log_unlock(logfile); +} diff --git a/accel/tcg/log_instr_json.c b/accel/tcg/log_instr_json.c new file mode 100644 index 00000000000..4a9474bd0a2 --- /dev/null +++ b/accel/tcg/log_instr_json.c @@ -0,0 +1,289 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * Similar functionality as the text backend but with a more stable format. + */ + +#include +#include + +#include "qemu/osdep.h" +#include "qemu/log.h" +#include "cpu.h" +#include "exec/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/memop.h" +#include "disas/disas.h" + +static cJSON *emit_json_hex(uint64_t value) +{ + char buf[sizeof(value) * 2 + 1]; + + snprintf((char *)&buf, sizeof(buf), "%lx", value); + return cJSON_CreateString((char *)&buf); +} + +#ifdef TARGET_CHERI +static cJSON *emit_json_capability(cap_register_t *cap) +{ + cJSON *js_cap = cJSON_CreateObject(); + cJSON *valid = cJSON_CreateBool(cap->cr_tag); + cJSON *sealed = cJSON_CreateBool(cap_is_sealed_with_type(cap)); + cJSON *perms = cJSON_CreateNumber(COMBINED_PERMS_VALUE(cap)); + cJSON *flags = cJSON_CreateNumber(cap_get_flags(cap)); + cJSON *base = emit_json_hex(cap_get_base(cap)); + cJSON *length = emit_json_hex(cap_get_length_sat(cap)); + cJSON *offset = emit_json_hex(cap_get_offset(cap)); + cJSON *otype = emit_json_hex(cap_get_otype_unsigned(cap)); + + cJSON_AddItemToObject(js_cap, "v", valid); + cJSON_AddItemToObject(js_cap, "s", sealed); + cJSON_AddItemToObject(js_cap, "p", perms); + cJSON_AddItemToObject(js_cap, "f", flags); + cJSON_AddItemToObject(js_cap, "b", base); + cJSON_AddItemToObject(js_cap, "l", length); + cJSON_AddItemToObject(js_cap, "o", offset); + cJSON_AddItemToObject(js_cap, "t", otype); + return js_cap; +} +#endif + +static void emit_json_ldst(log_meminfo_t *minfo, cJSON *list) +{ + cJSON *mem = cJSON_CreateObject(); + cJSON *is_load = cJSON_CreateBool((minfo->flags & LMI_LD) != 0); + cJSON *size = cJSON_CreateNumber(memop_size(minfo->op)); + cJSON *addr = emit_json_hex(minfo->addr); + cJSON *value; + +#ifndef TARGET_CHERI + assert((minfo->flags & LMI_CAP) == 0 && + "Capability memory access without CHERI support"); +#else + if (minfo->flags & LMI_CAP) { + value = emit_json_capability(&minfo->cap); + } else +#endif + { + value = emit_json_hex(minfo->value); + } + + cJSON_AddItemToObject(mem, "is_load", is_load); + cJSON_AddItemToObject(mem, "size", size); + cJSON_AddItemToObject(mem, "addr", addr); + cJSON_AddItemToObject(mem, "value", value); + cJSON_AddItemToArray(list, mem); +} + +static void emit_json_reg(log_reginfo_t *rinfo, cJSON *list) +{ + cJSON *reg = cJSON_CreateObject(); + cJSON *name = cJSON_CreateString(rinfo->name); + cJSON *value; + + cJSON_AddItemToObject(reg, "name", name); + +#ifndef TARGET_CHERI + assert(!reginfo_is_cap(rinfo) && "Register marked as capability " + "register whitout CHERI support"); +#else + if (reginfo_is_cap(rinfo)) { + if (reginfo_has_cap(rinfo)) { + value = emit_json_capability(&rinfo->cap); + } else { + value = cJSON_CreateNumber(rinfo->gpr); + } + } else +#endif + { + value = cJSON_CreateNumber(rinfo->gpr); + } + + cJSON_AddItemToObject(reg, "value", value); + cJSON_AddItemToArray(list, reg); +} + +static void emit_json_evt_state(const log_event_trace_state_update_t *evt, + cJSON *list) +{ + cJSON *update = cJSON_CreateObject(); + cJSON *evt_name = cJSON_CreateString("state"); + cJSON *next_state = cJSON_CreateNumber(evt->next_state); + cJSON *pc = cJSON_CreateNumber(evt->pc); + + cJSON_AddItemToObject(update, "id", evt_name); + cJSON_AddItemToObject(update, "next", next_state); + cJSON_AddItemToObject(update, "pc", pc); + cJSON_AddItemToArray(list, update); +} + +static void emit_json_evt_regdump(const log_event_regdump_t *evt, cJSON *list) +{ + cJSON *regdump = cJSON_CreateObject(); + cJSON *evt_name = cJSON_CreateString("rdump"); + cJSON *gpr = cJSON_CreateArray(); + int i; + + for (i = 0; i < evt->gpr->len; i++) { + log_reginfo_t *rinfo = &g_array_index(evt->gpr, log_reginfo_t, i); + emit_json_reg(rinfo, gpr); + } + cJSON_AddItemToObject(regdump, "id", evt_name); + cJSON_AddItemToObject(regdump, "gpr", gpr); + cJSON_AddItemToObject(list, "rdump", regdump); +} + +void sync_json_backend(CPUArchState *env) +{ + /* + * If we are shutting down, close the json entry list manually + * and add a dummy entry. This is an hack but it's easier than + * deleting the preceding comma. + */ + qemu_log("{}]"); +} + +void init_json_backend(CPUArchState *env, const char *logfile) +{ + /* Initialize the json logfile */ + static bool initialized; + + if (!initialized) { + initialized = true; + qemu_log("["); + } +} + +void emit_json_entry(CPUArchState *env, cpu_log_entry_t *entry) +{ + const log_event_t *event; + int i; + + /* + * XXX would be nice to use libxo but it's an annoying requirement for Linux + * targets. + */ + cJSON *js_entry = cJSON_CreateObject(); + + if (entry->flags & LI_FLAG_HAS_INSTR_DATA) { + cJSON *pc = emit_json_hex(entry->pc); + cJSON *cpu = cJSON_CreateNumber(env_cpu(env)->cpu_index); + cJSON *asid = cJSON_CreateNumber(entry->asid); + cJSON *insn = cJSON_CreateString( + disas_one_strbuf(env_cpu(env), entry->insn_bytes, + sizeof(entry->insn_bytes), entry->pc)); + cJSON_AddItemToObject(js_entry, "pc", pc); + cJSON_AddItemToObject(js_entry, "cpu", cpu); + cJSON_AddItemToObject(js_entry, "asid", asid); + cJSON_AddItemToObject(js_entry, "insn", insn); + + if (entry->flags & LI_FLAG_MODE_SWITCH) { + cJSON *mode = + cJSON_CreateString(cpu_get_mode_name(entry->next_cpu_mode)); + cJSON_AddItemToObject(js_entry, "mode-switch", mode); + } + + if (entry->flags & LI_FLAG_INTR_MASK) { + cJSON *exc = cJSON_CreateObject(); + cJSON *vec = cJSON_CreateNumber(entry->intr_vector); + cJSON *code = cJSON_CreateNumber(entry->intr_code); + cJSON *faultaddr = NULL; + cJSON *type; + if (entry->flags & LI_FLAG_INTR_TRAP) { + type = cJSON_CreateString("trap"); + faultaddr = emit_json_hex(entry->intr_faultaddr); + + } else if (entry->flags & LI_FLAG_INTR_ASYNC) { + type = cJSON_CreateString("intr"); + } else { + assert(0 && "invalid exception flags"); + } + cJSON_AddItemToObject(exc, "type", type); + cJSON_AddItemToObject(exc, "vec", vec); + cJSON_AddItemToObject(exc, "code", code); + if (faultaddr) { + cJSON_AddItemToObject(exc, "faultaddr", faultaddr); + } + cJSON_AddItemToObject(js_entry, "exc", exc); + } + + if (entry->mem->len > 0) { + cJSON *mem = cJSON_CreateArray(); + for (i = 0; i < entry->mem->len; i++) { + log_meminfo_t *minfo = + &g_array_index(entry->mem, log_meminfo_t, i); + emit_json_ldst(minfo, mem); + } + cJSON_AddItemToObject(js_entry, "mem", mem); + } + + if (entry->regs->len > 0) { + cJSON *reg = cJSON_CreateArray(); + for (i = 0; i < entry->regs->len; i++) { + log_reginfo_t *rinfo = + &g_array_index(entry->regs, log_reginfo_t, i); + emit_json_reg(rinfo, reg); + } + cJSON_AddItemToObject(js_entry, "reg", reg); + } + } + + if (entry->events->len > 0) { + cJSON *js_evt = cJSON_CreateArray(); + for (i = 0; i < entry->events->len; i++) { + event = &g_array_index(entry->events, const log_event_t, i); + switch (event->id) { + case LOG_EVENT_STATE: + emit_json_evt_state(&event->state, js_evt); + break; + case LOG_EVENT_CTX_UPDATE: + /* TODO Unimpl */ + break; + case LOG_EVENT_MARKER: + /* TODO Unimpl */ + break; + case LOG_EVENT_REGDUMP: + emit_json_evt_regdump(&event->reg_dump, js_evt); + break; + case LOG_EVENT_COUNTER: + /* TODO Unimpl */ + break; + default: + assert(0 && "unknown event ID"); + } + } + cJSON_AddItemToObject(js_entry, "evt", js_evt); + } + qemu_log("%s,", cJSON_PrintUnformatted(js_entry)); + cJSON_Delete(js_entry); +} diff --git a/accel/tcg/log_instr_perfetto.c b/accel/tcg/log_instr_perfetto.c new file mode 100644 index 00000000000..71d62b426f4 --- /dev/null +++ b/accel/tcg/log_instr_perfetto.c @@ -0,0 +1,208 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * C Glue code to bridge TCG instruction logging to the C++ perfetto interface. + */ + +#include "qemu/osdep.h" +#include "qemu/log_instr.h" +#include "cpu.h" +#include "exec/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/log_instr_perfetto.h" +#include "target/cheri-common/cheri_defs.h" +/* + * Initialize perfetto tracing. + * + * Start tracing thread when first called. + */ +void init_perfetto_backend(CPUArchState *env, const char *logfile) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + int cpu_id = env_cpu(env)->cpu_index; + + perfetto_init_cpu(cpu_id, logfile, &cpulog->backend_data); +} + +/* Syncronize buffers on this CPU. */ +void sync_perfetto_backend(CPUArchState *env) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + + perfetto_sync_cpu(cpulog->backend_data); +} + +void emit_perfetto_entry(CPUArchState *env, cpu_log_entry_t *entry) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + + perfetto_emit_instr(cpulog->backend_data, entry); +} + +log_event_t *perfetto_log_event(cpu_log_entry_handle handle, int idx) +{ + return &g_array_index(handle->events, log_event_t, idx); +} + +/* Helpers to access cpu_log_entry_t fields */ +CPU_LOG_ENTRY_GETTER(uint16_t, asid) +CPU_LOG_ENTRY_GETTER(int, flags) +CPU_LOG_ENTRY_GETTER(qemu_log_instr_cpu_mode_t, next_cpu_mode) +CPU_LOG_ENTRY_GETTER(uint32_t, intr_code) +CPU_LOG_ENTRY_GETTER(uint64_t, intr_vector) +CPU_LOG_ENTRY_GETTER(uint64_t, intr_faultaddr) +CPU_LOG_ENTRY_GETTER(uint64_t, pc) +CPU_LOG_ENTRY_GETTER_DECL(const char *, insn_bytes) +{ + return &handle->insn_bytes[0]; +} +CPU_LOG_ENTRY_GETTER(int, insn_size) +CPU_LOG_ENTRY_GETTER_DECL(int, mem) +{ + return handle->mem->len; +} +CPU_LOG_ENTRY_GETTER_DECL(int, regs) +{ + return handle->regs->len; +} +CPU_LOG_ENTRY_GETTER_DECL(int, events) +{ + return handle->events->len; +} +CPU_LOG_ENTRY_GETTER_DECL(const char *, txt_buffer) +{ + return handle->txt_buffer->str; +} + +REG_INFO_GETTER(uint16_t, flags) +REG_INFO_GETTER(const char *, name) +REG_INFO_GETTER(uint64_t, gpr) +REG_INFO_GETTER_DECL(cap_register_handle, cap) +{ +#ifdef TARGET_CHERI + log_reginfo_t *r = &g_array_index(handle->regs, log_reginfo_t, idx); + return (cap_register_handle)(&r->cap); +#else + return NULL; +#endif +} + +MEM_INFO_GETTER(uint8_t, flags) +MEM_INFO_GETTER(int, op) +MEM_INFO_GETTER(uint64_t, addr) +MEM_INFO_GETTER(uint64_t, value) +MEM_INFO_GETTER_DECL(cap_register_handle, cap) +{ +#ifdef TARGET_CHERI + log_meminfo_t *m = &g_array_index(handle->mem, log_meminfo_t, idx); + return (cap_register_handle)(&m->cap); +#else + return NULL; +#endif +} + +CAPREG_GETTER_DECL(bool, tag) +{ +#ifdef TARGET_CHERI + return ((cap_register_t *)handle)->cr_tag; +#else + /* + * XXX-AM Error instead? these must be defined for non-CHERI + * targets but will never be called. + */ + return 0; +#endif +} + +CAPREG_GETTER_DECL(bool, sealed) +{ +#ifdef TARGET_CHERI + return !cap_is_unsealed((cap_register_t *)handle); +#else + return 0; +#endif +} + +CAPREG_GETTER_DECL(uint64_t, base) +{ +#ifdef TARGET_CHERI + return cap_get_base((cap_register_t *)handle); +#else + return 0; +#endif +} + +CAPREG_GETTER_DECL(uint64_t, cursor) +{ +#ifdef TARGET_CHERI + return cap_get_cursor((cap_register_t *)handle); +#else + return 0; +#endif +} + +CAPREG_GETTER_DECL(uint64_t, length) +{ +#ifdef TARGET_CHERI + return cap_get_length_full((cap_register_t *)handle); +#else + return 0; +#endif +} + +CAPREG_GETTER_DECL(uint32_t, perms) +{ +#ifdef TARGET_CHERI + return cap_get_perms((cap_register_t *)handle); +#else + return 0; +#endif +} + +CAPREG_GETTER_DECL(uint32_t, otype) +{ +#ifdef TARGET_CHERI + return cap_get_otype_unsigned((cap_register_t *)handle); +#else + return 0; +#endif +} + +TARGET_CAP_DECL(uint32_t, size) +{ +#ifdef TARGET_CHERI + return CHERI_CAP_SIZE; +#else + return 0; +#endif +} diff --git a/accel/tcg/log_instr_protobuf.c b/accel/tcg/log_instr_protobuf.c new file mode 100644 index 00000000000..9fe883ff9df --- /dev/null +++ b/accel/tcg/log_instr_protobuf.c @@ -0,0 +1,389 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021, 2023 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * Similar functionality as the text backend but with a more stable format. + */ + +#include + +#include "qemu/osdep.h" +#include "qemu/log.h" +#include "cpu.h" +#include "exec/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/memop.h" +#include "disas/disas.h" + +#include "qemu_log_entry.pb-c.h" + +static FILE *protobuf_logfile; + +/* + * Helpers to simplify access to namespaced protobuf values + * For consistency, redefine types to mirror the generated + * code from protobuf-c but strip the package prefix. + */ +#define GEN_TYPE_NS(x) Perfetto__Protos__##x +#define GEN_TYPE_PREFIX(x) GEN_TYPE_NS(QEMULogEntry##x) +typedef GEN_TYPE_PREFIX(Capability) QEMULogEntryCapability; +typedef GEN_TYPE_PREFIX(Mem) QEMULogEntryMem; +typedef GEN_TYPE_PREFIX(Reg) QEMULogEntryReg; +typedef GEN_TYPE_PREFIX(Evt) QEMULogEntryEvt; +typedef GEN_TYPE_PREFIX(Exc) QEMULogEntryExc; +typedef GEN_TYPE_PREFIX() QEMULogEntry; +typedef GEN_TYPE_PREFIX(EvtTraceState) QEMULogEntryEvtTraceState; +typedef GEN_TYPE_PREFIX(EvtCtxUpdate) QEMULogEntryEvtCtxUpdate; +typedef GEN_TYPE_PREFIX(EvtRegdump) QEMULogEntryEvtRegdump; +typedef GEN_TYPE_NS(QEMULogEventTraceState) QEMULogEventTraceState; + +#define GEN_FN_NS(x) perfetto__protos__##x +#define GEN_FN_PREFIX(x) GEN_FN_NS(qemulog_entry_##x) +#define qemulog_entry_capability__init GEN_FN_PREFIX(capability__init) +#define qemulog_entry_mem__init GEN_FN_PREFIX(mem__init) +#define qemulog_entry_reg__init GEN_FN_PREFIX(reg__init) +#define qemulog_entry_evt__init GEN_FN_PREFIX(evt__init) +#define qemulog_entry_evt_trace_state__init GEN_FN_PREFIX(evt_trace_state__init) +#define qemulog_entry_evt_ctx_update__init GEN_FN_PREFIX(evt_ctx_update__init) +#define qemulog_entry_evt_regdump__init GEN_FN_PREFIX(evt_regdump__init) +#define qemulog_entry__get_packed_size GEN_FN_PREFIX(_get_packed_size) +#define qemulog_entry__pack GEN_FN_PREFIX(_pack) + +#define GEN_CONST_NS(x) PERFETTO__PROTOS__##x +#define GEN_CONST_PREFIX(x) GEN_CONST_NS(QEMULOG_ENTRY_##x) +#define ENUM_ENTRY_MEM_VALUE(v) GEN_CONST_PREFIX(MEM__VALUE_##v) +#define ENUM_ENTRY_REG_VALUE(v) GEN_CONST_PREFIX(REG__VALUE_##v) +#define ENUM_ENTRY_EVT_CASE(v) GEN_CONST_PREFIX(EVT__EVENT_##v) +#define ENUM_ENTRY_INSN_CASE(v) GEN_CONST_PREFIX(_INSN_##v) +#define ENUM_ENTRY_MODE_CASE(v) GEN_CONST_PREFIX(_MODE_MODE_##v) +#define ENUM_ENTRY_EXC_CASE(v) GEN_CONST_PREFIX(EXC_TYPE__##v) +#define QEMULOG_ENTRY__INIT GEN_CONST_NS(QEMULOG_ENTRY__INIT) +#define QEMULOG_ENTRY_EXC__INIT GEN_CONST_PREFIX(EXC__INIT) + +#ifdef TARGET_CHERI +static QEMULogEntryCapability *emit_protobuf_capability(cap_register_t *cap) +{ + QEMULogEntryCapability *pb_cap = g_malloc(sizeof(QEMULogEntryCapability)); + + qemulog_entry_capability__init(pb_cap); + pb_cap->valid = cap->cr_tag; + pb_cap->sealed = cap_is_sealed_with_type(cap); + pb_cap->perms = COMBINED_PERMS_VALUE(cap); + /* pb_cap->flags = cap_get_flags(cap); */ + pb_cap->otype = cap_get_otype_unsigned(cap); + pb_cap->cap_base = cap_get_base(cap); + pb_cap->cap_cursor = cap_get_cursor(cap); + pb_cap->cap_length = cap_get_length_sat(cap); + return pb_cap; +} +#endif + +static void emit_protobuf_meminfo(log_meminfo_t *minfo, + QEMULogEntryMem **pb_mem) +{ + QEMULogEntryMem *mem = g_malloc(sizeof(QEMULogEntryMem)); + + qemulog_entry_mem__init(mem); + mem->is_load = (minfo->flags & LMI_LD) != 0; + mem->size = memop_size(minfo->op); + mem->addr = minfo->addr; +#ifndef TARGET_CHERI + assert((minfo->flags & LMI_CAP) == 0 && + "Capability memory access without CHERI support"); +#else + if (minfo->flags & LMI_CAP) { + mem->value_case = ENUM_ENTRY_MEM_VALUE(CAP_VALUE); + mem->cap_value = emit_protobuf_capability(&minfo->cap); + } else +#endif + { + mem->value_case = ENUM_ENTRY_MEM_VALUE(INT_VALUE); + mem->int_value = minfo->value; + } + *pb_mem = mem; +} + +static void release_protobuf_meminfo(QEMULogEntryMem *pb_mem) +{ + if (pb_mem->value_case == ENUM_ENTRY_MEM_VALUE(CAP_VALUE)) { + g_free(pb_mem->cap_value); + } + g_free(pb_mem); +} + +static void emit_protobuf_reginfo(log_reginfo_t *rinfo, + QEMULogEntryReg **pb_reg) +{ + QEMULogEntryReg *reg = g_malloc(sizeof(QEMULogEntryReg)); + + qemulog_entry_reg__init(reg); + /* Safe to de-const cast as the pointer is only used during packing */ + reg->name = (char *)rinfo->name; + +#ifndef TARGET_CHERI + assert(!reginfo_is_cap(rinfo) && "Register marked as capability " + "register whitout CHERI support"); +#else + if (reginfo_is_cap(rinfo)) { + if (reginfo_has_cap(rinfo)) { + reg->value_case = ENUM_ENTRY_REG_VALUE(CAP_VALUE); + reg->cap_value = emit_protobuf_capability(&rinfo->cap); + } else { + reg->value_case = ENUM_ENTRY_REG_VALUE(INT_VALUE); + reg->int_value = rinfo->gpr; + } + } else +#endif + { + reg->value_case = ENUM_ENTRY_REG_VALUE(INT_VALUE); + reg->int_value = rinfo->gpr; + } + *pb_reg = reg; +} + +static void release_protobuf_reginfo(QEMULogEntryReg *pb_reg) +{ + if (pb_reg->value_case == ENUM_ENTRY_REG_VALUE(CAP_VALUE)) { + g_free(pb_reg->cap_value); + } + g_free(pb_reg); +} + +static void emit_protobuf_event(log_event_t *evtinfo, QEMULogEntryEvt **pb_evt) +{ + QEMULogEntryEvt *pb_evt_entry = g_malloc(sizeof(QEMULogEntryEvt)); + int i; + + qemulog_entry_evt__init(pb_evt_entry); + switch (evtinfo->id) { + case LOG_EVENT_STATE: + pb_evt_entry->event_case = ENUM_ENTRY_EVT_CASE(STATE); + pb_evt_entry->state = g_malloc(sizeof(QEMULogEntryEvtTraceState)); + qemulog_entry_evt_trace_state__init(pb_evt_entry->state); + pb_evt_entry->state->next_state = + (QEMULogEventTraceState)evtinfo->state.next_state; + pb_evt_entry->state->pc = evtinfo->state.pc; + break; + case LOG_EVENT_CTX_UPDATE: + pb_evt_entry->event_case = ENUM_ENTRY_EVT_CASE(CTX_UPDATE); + pb_evt_entry->ctx_update = g_malloc(sizeof(QEMULogEntryEvtCtxUpdate)); + qemulog_entry_evt_ctx_update__init(pb_evt_entry->ctx_update); + pb_evt_entry->ctx_update->pid = evtinfo->ctx_update.pid; + pb_evt_entry->ctx_update->tid = evtinfo->ctx_update.tid; + pb_evt_entry->ctx_update->cid = evtinfo->ctx_update.cid; + /* Safe to de-const cast as the pointer is only used during packing */ + pb_evt_entry->ctx_update->mode = + (char *)cpu_get_mode_name(evtinfo->ctx_update.mode); + break; + case LOG_EVENT_MARKER: + pb_evt_entry->event_case = ENUM_ENTRY_EVT_CASE(MARKER); + pb_evt_entry->marker = evtinfo->marker; + break; + case LOG_EVENT_REGDUMP: { + log_event_regdump_t *regdump = &evtinfo->reg_dump; + QEMULogEntryEvtRegdump *pb_regdump = + g_malloc(sizeof(QEMULogEntryEvtRegdump)); + QEMULogEntryReg **pb_regs; + qemulog_entry_evt_regdump__init(pb_regdump); + + pb_evt_entry->event_case = ENUM_ENTRY_EVT_CASE(REGDUMP); + pb_evt_entry->regdump = pb_regdump; + pb_regdump->n_regs = regdump->gpr->len; + pb_regs = g_malloc(regdump->gpr->len * sizeof(QEMULogEntryReg *)); + pb_regdump->regs = pb_regs; + for (i = 0; i < regdump->gpr->len; i++, pb_regs++) { + log_reginfo_t *rinfo = + &g_array_index(regdump->gpr, log_reginfo_t, i); + emit_protobuf_reginfo(rinfo, pb_regs); + } + } break; + case LOG_EVENT_COUNTER: + break; + default: + assert(0 && "unknown event ID"); + } + *pb_evt = pb_evt_entry; +} + +static void release_protobuf_event(QEMULogEntryEvt *pb_evt) +{ + int i; + + if (pb_evt->event_case == ENUM_ENTRY_EVT_CASE(STATE)) { + g_free(pb_evt->state); + } + if (pb_evt->event_case == ENUM_ENTRY_EVT_CASE(CTX_UPDATE)) { + g_free(pb_evt->ctx_update); + } + if (pb_evt->event_case == ENUM_ENTRY_EVT_CASE(REGDUMP)) { + for (i = 0; i < pb_evt->regdump->n_regs; i++) { + release_protobuf_reginfo(pb_evt->regdump->regs[i]); + } + g_free(pb_evt->regdump->regs); + g_free(pb_evt->regdump); + } + g_free(pb_evt); +} + +void init_protobuf_backend(CPUArchState *env, const char *trace_logfile) +{ + /* + * XXX we may want to store a cache of protobuf structures in the backend + * data so that we avoid all the g_malloc() and g_free(). + */ + + if (protobuf_logfile == NULL) { + protobuf_logfile = fopen(trace_logfile, "w+b"); + } +} + +void sync_protobuf_backend(CPUArchState *env) +{ + if (protobuf_logfile != NULL) { + fflush(protobuf_logfile); + } +} + +void emit_protobuf_entry(CPUArchState *env, cpu_log_entry_t *entry) +{ + QEMULogEntry pb_entry = QEMULOG_ENTRY__INIT; + QEMULogEntryExc pb_exc = QEMULOG_ENTRY_EXC__INIT; + QEMULogEntryMem **pb_mem; + QEMULogEntryReg **pb_reg; + QEMULogEntryEvt **pb_evt; + uint8_t *buf; + size_t len; + uint32_t preamble = 0; + int i; + + pb_entry.pc = entry->pc; + + if (entry->flags & LI_FLAG_HAS_INSTR_DATA) { + pb_entry.insn_case = ENUM_ENTRY_INSN_CASE(DISAS); + pb_entry.disas = disas_one_str(env_cpu(env), entry->insn_bytes, + sizeof(entry->insn_bytes), entry->pc); + pb_entry.cpu = env_cpu(env)->cpu_index; + pb_entry.asid = entry->asid; + if (entry->flags & LI_FLAG_MODE_SWITCH) { + /* + * Safe to de-const cast as the pointer is only used during packing + */ + pb_entry.mode_case = ENUM_ENTRY_MODE_CASE(NAME); + pb_entry.mode_name = + (char *)cpu_get_mode_name(entry->next_cpu_mode); + } + if (entry->flags & LI_FLAG_INTR_MASK) { + pb_entry.exception = &pb_exc; + pb_exc.vector = entry->intr_vector; + pb_exc.code = entry->intr_code; + if (entry->flags & LI_FLAG_INTR_TRAP) { + pb_exc.type = ENUM_ENTRY_EXC_CASE(TRAP); + pb_exc.faultaddr = entry->intr_faultaddr; + } else if (entry->flags & LI_FLAG_INTR_ASYNC) { + pb_exc.type = ENUM_ENTRY_EXC_CASE(INTR); + } else { + assert(0 && "invalid exception flags"); + } + } + if (entry->mem->len > 0) { + pb_mem = g_malloc(entry->mem->len * sizeof(QEMULogEntryMem *)); + pb_entry.n_mem = entry->mem->len; + pb_entry.mem = pb_mem; + for (i = 0; i < entry->mem->len; i++, pb_mem++) { + log_meminfo_t *minfo = + &g_array_index(entry->mem, log_meminfo_t, i); + emit_protobuf_meminfo(minfo, pb_mem); + } + } + if (entry->regs->len > 0) { + pb_reg = g_malloc(entry->regs->len * sizeof(QEMULogEntryReg *)); + pb_entry.n_reg = entry->regs->len; + pb_entry.reg = pb_reg; + for (i = 0; i < entry->regs->len; i++, pb_reg++) { + log_reginfo_t *rinfo = + &g_array_index(entry->regs, log_reginfo_t, i); + emit_protobuf_reginfo(rinfo, pb_reg); + } + } + } + + if (entry->events->len > 0) { + pb_evt = NULL; + pb_evt = g_malloc(entry->events->len * sizeof(QEMULogEntryEvt *)); + pb_entry.n_evt = entry->events->len; + pb_entry.evt = pb_evt; + for (i = 0; i < entry->events->len; i++, pb_evt++) { + log_event_t *event = &g_array_index(entry->events, log_event_t, i); + emit_protobuf_event(event, pb_evt); + } + } + + len = qemulog_entry__get_packed_size(&pb_entry); + preamble = len; + assert(preamble == len && "Message preamble overflow"); + + buf = g_malloc(len + sizeof(preamble)); + *((uint32_t *)buf) = preamble; + qemulog_entry__pack(&pb_entry, buf + sizeof(preamble)); + + /* + * Technically we should not use the qemu logfile as it is not open in + * binary mode + */ + qemu_flockfile(protobuf_logfile); + fwrite(buf, len + sizeof(preamble), 1, protobuf_logfile); + qemu_funlockfile(protobuf_logfile); + + if (entry->flags & LI_FLAG_HAS_INSTR_DATA) { + g_free(pb_entry.disas); + + if (entry->mem->len > 0) { + for (i = 0; i < entry->mem->len; i++) { + release_protobuf_meminfo(pb_entry.mem[i]); + } + g_free(pb_entry.mem); + } + if (entry->regs->len > 0) { + for (i = 0; i < entry->regs->len; i++) { + release_protobuf_reginfo(pb_entry.reg[i]); + } + g_free(pb_entry.reg); + } + } + if (entry->events->len > 0) { + for (i = 0; i < entry->events->len; i++) { + release_protobuf_event(pb_entry.evt[i]); + } + g_free(pb_entry.evt); + } + g_free(buf); +} diff --git a/accel/tcg/log_instr_stats.c b/accel/tcg/log_instr_stats.c new file mode 100644 index 00000000000..4b82bac02ea --- /dev/null +++ b/accel/tcg/log_instr_stats.c @@ -0,0 +1,122 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * Statistic-gathering instruction logging backend + */ + +#include + +#include "qemu/osdep.h" +#include "qemu/log.h" +#include "exec/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/log_instr_stats.h" + +struct cpu_stats { + qemu_cpu_stats_t qstats; + target_ulong last_pc; + target_ulong pc_range_start; +}; + +static struct cpu_stats *get_cpu_stats(CPUArchState *env) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + return (struct cpu_stats *)cpulog->backend_data; +} + +/* + * Initialize the backend. + */ +void init_stats_backend(CPUArchState *env) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + struct cpu_stats *stats; + + stats = malloc(sizeof(struct cpu_stats)); + stats->qstats = qemu_cpu_stats_create(env_cpu(env)->cpu_index); + stats->last_pc = 0; + stats->pc_range_start = 0; + cpulog->backend_data = stats; +} + +/* + * Emit a textual representation of events recorded by the given trace entry. + */ +void emit_stats_events(CPUArchState *env, cpu_log_entry_t *entry) +{ + struct cpu_stats *stats = get_cpu_stats(env); + QemuLogFile *logfile; + const log_event_t *event; + bool header = false; + int i; + + log_assert(stats != NULL && "Missing stats backend data"); + + for (i = 0; i < entry->events->len; i++) { + event = &g_array_index(entry->events, const log_event_t, i); + if (event->id == LOG_EVENT_STATE) { + if (event->state.next_state == LOG_EVENT_STATE_FLUSH) { + rcu_read_lock(); + logfile = qatomic_rcu_read(&qemu_logfile); + if (logfile) { + if (ftell(logfile->fd) == 0) { + header = true; + } + qemu_cpu_stats_dump(stats->qstats, fileno(logfile->fd), + header); + fflush(logfile->fd); + } + rcu_read_unlock(); + break; + } + } + } +} + +/* + * Emit textual representation of the instruction in the given + * trace entry to the log. + */ +void emit_stats_entry(CPUArchState *env, cpu_log_entry_t *entry) +{ + struct cpu_stats *stats = get_cpu_stats(env); + + log_assert(stats != NULL && "Missing stats backend data"); + + if (entry->pc - stats->last_pc > entry->insn_size) { + qemu_cpu_stats_record_bb_hit(stats->qstats, stats->pc_range_start, + stats->last_pc); + stats->pc_range_start = entry->pc; + } + stats->last_pc = entry->pc; +} diff --git a/accel/tcg/log_instr_text.c b/accel/tcg/log_instr_text.c new file mode 100644 index 00000000000..743bbb17add --- /dev/null +++ b/accel/tcg/log_instr_text.c @@ -0,0 +1,243 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * Text instruction logging backend + */ + +#include "qemu/osdep.h" +#include "qemu/log.h" +#include "cpu.h" +#include "exec/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/memop.h" +#include "disas/disas.h" + +/* + * Emit textual trace representation of memory access + */ +static inline void emit_text_ldst(log_meminfo_t *minfo, const char *direction) +{ + +#ifndef TARGET_CHERI + log_assert((minfo->flags & LMI_CAP) == 0 && + "Capability memory access without CHERI support"); +#else + if (minfo->flags & LMI_CAP) { + qemu_log(" Cap Memory %s [" TARGET_FMT_lx + "] = v:%d PESBT:" TARGET_FMT_lx " Cursor:" TARGET_FMT_lx "\n", + direction, minfo->addr, minfo->cap.cr_tag, + CAP_cc(compress_mem)(&minfo->cap), + cap_get_cursor(&minfo->cap)); + } else +#endif + { + switch (memop_size(minfo->op)) { + default: + qemu_log(" Unknown memory access width\n"); + /* fallthrough */ + case 8: + qemu_log(" Memory %s [" TARGET_FMT_lx "] = " TARGET_FMT_plx "\n", + direction, minfo->addr, minfo->value); + break; + case 4: + qemu_log(" Memory %s [" TARGET_FMT_lx "] = %08x\n", direction, + minfo->addr, (uint32_t)minfo->value); + break; + case 2: + qemu_log(" Memory %s [" TARGET_FMT_lx "] = %04x\n", direction, + minfo->addr, (uint16_t)minfo->value); + break; + case 1: + qemu_log(" Memory %s [" TARGET_FMT_lx "] = %02x\n", direction, + minfo->addr, (uint8_t)minfo->value); + break; + } + } +} + +/* + * Emit textual trace representation of register modification + */ +static inline void emit_text_reg(log_reginfo_t *rinfo) +{ +#ifndef TARGET_CHERI + log_assert(!reginfo_is_cap(rinfo) && "Register marked as capability " + "register whitout CHERI support"); +#else + if (reginfo_is_cap(rinfo)) { + if (reginfo_has_cap(rinfo)) + qemu_log(" Write %s|" PRINT_CAP_FMTSTR_L1 "\n" + " |" PRINT_CAP_FMTSTR_L2 "\n", + rinfo->name, PRINT_CAP_ARGS_L1(&rinfo->cap), + PRINT_CAP_ARGS_L2(&rinfo->cap)); + else + qemu_log(" %s <- " TARGET_FMT_lx " (setting integer value)\n", + rinfo->name, rinfo->gpr); + } else +#endif + { + qemu_log(" Write %s = " TARGET_FMT_lx "\n", rinfo->name, rinfo->gpr); + } +} + +/* + * Emit textual representation of the instruction in the given + * trace entry to the log. + */ +void emit_text_instr(CPUArchState *env, cpu_log_entry_t *entry) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + QemuLogFile *logfile; + const log_event_t *event; + const char *log_state_op; + int i, j; + bool incremental; + + if (entry->flags & LI_FLAG_HAS_INSTR_DATA) { + /* Dump CPU-ID:ASID + address */ + qemu_log("[%d:%d] ", env_cpu(env)->cpu_index, entry->asid); + + /* + * Instruction disassembly, note that we use the instruction info + * opcode bytes, without accessing target memory here. + */ + rcu_read_lock(); + logfile = qatomic_rcu_read(&qemu_logfile); + if (logfile) { + target_disas_buf(logfile->fd, env_cpu(env), entry->insn_bytes, + sizeof(entry->insn_bytes), entry->pc, 1); + } + rcu_read_unlock(); + + /* + * TODO(am2419): what to do with injected instructions? + * Is the rvfi_dii_trace state valid at log commit? + */ + + /* Dump mode switching info */ + if (entry->flags & LI_FLAG_MODE_SWITCH) + qemu_log("-> Switch to %s mode\n", + cpu_get_mode_name(entry->next_cpu_mode)); + /* Dump interrupt/exception info */ + switch (entry->flags & LI_FLAG_INTR_MASK) { + case LI_FLAG_INTR_TRAP: + qemu_log("-> Exception #%u vector 0x" TARGET_FMT_lx + " fault-addr 0x" TARGET_FMT_lx "\n", + entry->intr_code, entry->intr_vector, + entry->intr_faultaddr); + break; + case LI_FLAG_INTR_ASYNC: + qemu_log("-> Interrupt #%04x vector 0x" TARGET_FMT_lx "\n", + entry->intr_code, entry->intr_vector); + break; + default: + /* No interrupt */ + break; + } + + /* Dump memory access */ + for (i = 0; i < entry->mem->len; i++) { + log_meminfo_t *minfo = &g_array_index(entry->mem, log_meminfo_t, i); + if (minfo->flags & LMI_LD) { + emit_text_ldst(minfo, "Read"); + } else if (minfo->flags & LMI_ST) { + emit_text_ldst(minfo, "Write"); + } + } + + /* Dump register changes and side-effects */ + for (i = 0; i < entry->regs->len; i++) { + log_reginfo_t *rinfo = + &g_array_index(entry->regs, log_reginfo_t, i); + emit_text_reg(rinfo); + } + } + + /* Dump extra logged messages, if any */ + if (entry->txt_buffer->len > 0) { + qemu_log("%s", entry->txt_buffer->str); + } + + /* Emit events recorded by the given trace entry */ + for (i = 0; i < entry->events->len; i++) { + event = &g_array_index(entry->events, const log_event_t, i); + switch (event->id) { + case LOG_EVENT_STATE: + if (event->state.next_state == LOG_EVENT_STATE_START) { + log_state_op = "Requested"; + } else if (event->state.next_state == LOG_EVENT_STATE_STOP) { + log_state_op = "Disabled"; + } else { + continue; + } + + if (cpulog->loglevel == QEMU_LOG_INSTR_LOGLEVEL_USER) { + qemu_log( + "[%u:%u] %s user-mode only instruction logging @ %lx\n", + env_cpu(env)->cpu_index, cpu_get_asid(env, event->state.pc), + log_state_op, event->state.pc); + } else { + qemu_log("[%u:%u] %s instruction logging @ %lx\n", + env_cpu(env)->cpu_index, + cpu_get_asid(env, event->state.pc), log_state_op, + event->state.pc); + } + break; + case LOG_EVENT_CTX_UPDATE: + qemu_log("Context switch pid=0x%lx tid=0x%lx cid=0x%lx\n", + event->ctx_update.pid, event->ctx_update.tid, + event->ctx_update.cid); + break; + case LOG_EVENT_MARKER: + qemu_log("Guest trace marker %lx\n", event->marker); + break; + case LOG_EVENT_REGDUMP: + qemu_log("Register dump\n"); + for (j = 0; j < event->reg_dump.gpr->len; j++) { + log_reginfo_t *r = + &g_array_index(event->reg_dump.gpr, log_reginfo_t, j); + emit_text_reg(r); + } + break; + case LOG_EVENT_COUNTER: + incremental = log_event_counter_incremental(event->counter.flags); + qemu_log("Counter %s %s[%d]: %lx\n", (incremental) ? "INC" : "ABS", + event->counter.name, + log_event_counter_slot(event->counter.flags), + event->counter.value); + break; + default: + assert(0 && "unknown event ID"); + } + } +} diff --git a/accel/tcg/meson.build b/accel/tcg/meson.build index 2b73cd433c0..711490f8171 100644 --- a/accel/tcg/meson.build +++ b/accel/tcg/meson.build @@ -14,3 +14,16 @@ specific_ss.add_all(when: 'CONFIG_TCG', if_true: tcg_ss) specific_ss.add(when: ['CONFIG_SOFTMMU', 'CONFIG_TCG'], if_true: files('tcg-all.c', 'cputlb.c', 'tcg-cpus.c')) specific_ss.add(when: ['CONFIG_TCG_LOG_INSTR', 'CONFIG_TCG'], if_true: files('log_instr.c')) +specific_ss.add(when: ['CONFIG_TCG_LOG_INSTR', 'CONFIG_TCG'], if_true: files('log_instr_text.c')) +specific_ss.add(when: ['CONFIG_TCG_LOG_INSTR', 'CONFIG_TCG'], if_true: files('log_instr_cvtrace.c')) +specific_ss.add(when: ['CONFIG_TRACE_PERFETTO', 'CONFIG_TCG_LOG_INSTR', 'CONFIG_TCG'], if_true: files('log_instr_perfetto.c')) +specific_ss.add(when: ['CONFIG_TRACE_PROTOBUF', 'CONFIG_TCG_LOG_INSTR', 'CONFIG_TCG'], if_true: files('log_instr_protobuf.c')) +specific_ss.add(when: ['CONFIG_TRACE_JSON', 'CONFIG_TCG_LOG_INSTR', 'CONFIG_TCG'], if_true: files('log_instr_json.c')) + +if config_all.has_key('CONFIG_TCG_LOG_INSTR') and config_all.has_key('CONFIG_TRACE_PROTOBUF') + specific_ss.add(dependency('libprotobuf-c')) +endif + +if config_all.has_key('CONFIG_TCG_LOG_INSTR') and config_all.has_key('CONFIG_TRACE_JSON') + specific_ss.add(dependency('libcjson')) +endif diff --git a/chardev/char-mux.c b/chardev/char-mux.c index 6f980bb8364..32d53a44e56 100644 --- a/chardev/char-mux.c +++ b/chardev/char-mux.c @@ -26,12 +26,21 @@ #include "qapi/error.h" #include "qemu/module.h" #include "qemu/option.h" +#include "qemu/error-report.h" +#include "qemu/log_instr.h" #include "chardev/char.h" #include "sysemu/block-backend.h" #include "sysemu/sysemu.h" #include "chardev-internal.h" /* MUX driver for serial I/O splitting */ +#ifdef CONFIG_TCG_LOG_INSTR +__attribute__((weak)) void qemu_log_instr_sync_buffers() +{ + /* Real implementation in accel/tcg/log_instr.c */ + warn_report("Calling no-op %s\r", __func__); +} +#endif /* Called with chr_write_lock held. */ static int mux_chr_write(Chardev *chr, const uint8_t *buf, int len) @@ -149,6 +158,9 @@ static int mux_proc_byte(Chardev *chr, MuxChardev *d, int ch) break; case 'x': { +#ifdef CONFIG_TCG_LOG_INSTR + qemu_log_instr_sync_buffers(); +#endif const char *term = "QEMU: Terminated\n\r"; qemu_chr_write_all(chr, (uint8_t *)term, strlen(term)); exit(0); diff --git a/configure b/configure index 9f89ca22a55..0b1f9fda713 100755 --- a/configure +++ b/configure @@ -340,6 +340,9 @@ pvrdma="" gprof="no" debug_tcg="no" tcg_log_instr="yes" +tcg_log_instr_perfetto="no" +tcg_log_instr_protobuf="no" +tcg_log_instr_json="no" rvfi_dii="no" debug="no" sanitizers="no" @@ -1036,6 +1039,18 @@ for opt do ;; --disable-tcg-log-instr) tcg_log_instr="no" ;; + --enable-perfetto-log-instr) tcg_log_instr_perfetto="yes" + ;; + --disable-perfetto-log-instr) tcg_log_instr_perfetto="no" + ;; + --enable-protobuf-log-instr) tcg_log_instr_protobuf="yes" + ;; + --disable-protobuf-log-instr) tcg_log_instr_protobuf="no" + ;; + --enable-json-log-instr) tcg_log_instr_json="yes" + ;; + --disable-json-log-instr) tcg_log_instr_json="no" + ;; --enable-rvfi-dii) rvfi_dii="yes" ;; --disable-rvfi-dii) rvfi_dii="no" @@ -5968,6 +5983,15 @@ fi if test "$tcg_log_instr" = "yes" ; then echo "CONFIG_TCG_LOG_INSTR=y" >> $config_host_mak fi +if test "$tcg_log_instr_perfetto" = "yes" ; then + echo "CONFIG_TRACE_PERFETTO=y" >> $config_host_mak +fi +if test "$tcg_log_instr_protobuf" = "yes" ; then + echo "CONFIG_TRACE_PROTOBUF=y" >> $config_host_mak +fi +if test "$tcg_log_instr_json" = "yes" ; then + echo "CONFIG_TRACE_JSON=y" >> $config_host_mak +fi if test "$rvfi_dii" = "yes" ; then echo "CONFIG_RVFI_DII=y" >> $config_host_mak fi diff --git a/disas.c b/disas.c index a0de01cc39a..a54b3bd7e35 100644 --- a/disas.c +++ b/disas.c @@ -355,6 +355,90 @@ char *plugin_disas(CPUState *cpu, uint64_t addr, size_t size) return g_string_free(ds, false); } +static inline void do_disas_one(CPUState *cpu, void *code, unsigned long size, target_ulong vma, fprintf_function dump_fn, void *dump_arg) +{ + CPUClass *cc = CPU_GET_CLASS(cpu); + CPUDebug s; + + initialize_debug_target(&s, cpu); + s.info.read_memory_func = host_read_memory; + s.info.fprintf_func = dump_fn; + s.info.stream = (FILE *)dump_arg; /* abuse this slot */ + s.info.buffer = code; + s.info.buffer_vma = vma; + s.info.buffer_length = size; + +#ifdef TARGET_WORDS_BIGENDIAN + s.info.endian = BFD_ENDIAN_BIG; +#else + s.info.endian = BFD_ENDIAN_LITTLE; +#endif + + if (cc->disas_set_info) { + cc->disas_set_info(cpu, &s.info); + } + + if (s.info.cap_arch >= 0 && cap_disas_target(&s.info, vma, size)) { + ; /* done */ + } else if (s.info.print_insn) { + s.info.print_insn(vma, &s.info); + } else { + ; /* cannot disassemble -- return empty string */ + } +} + +/* + * Disassemble one instruction to a buffer. + * The string returned must be freed by the caller with g_free(). + */ +char *disas_one_str(CPUState *cpu, void *code, unsigned long size, + target_ulong vma) +{ + GString *ds = g_string_new(NULL); + + do_disas_one(cpu, code, size, vma, plugin_printf, ds); + + /* Return the buffer, freeing the GString container. */ + return g_string_free(ds, false); +} + +struct disas_one_args { + char *buf; + int maxlen; +}; + +static int strbuf_printf(FILE *stream, const char *fmt, ...) +{ + struct disas_one_args *args = (struct disas_one_args *)stream; + va_list va; + int n; + + va_start(va, fmt); + n = vsnprintf(args->buf, args->maxlen, fmt, va); + va_end(va); + + /* Update args for append behaviour */ + if (n >= args->maxlen) { + n = args->maxlen; + args->maxlen = 0; + } else { + args->buf += n; + args->maxlen -= n; + } + + return n; +} + +/* + * Disassemble one instruction to an existing, fixed size, string buffer. + */ +void disas_one_strbuf(CPUState *cpu, void *code, unsigned long size, + target_ulong vma, char *buf, int bufsize) +{ + struct disas_one_args args = {buf, bufsize}; + do_disas_one(cpu, code, size, vma, strbuf_printf, &args); +} + /* Disassemble this for me please... (debugging). */ void disas(FILE *out, const void *code, unsigned long size) { diff --git a/hw/misc/sifive_test.c b/hw/misc/sifive_test.c index 2deb2072cc8..9cce43e7502 100644 --- a/hw/misc/sifive_test.c +++ b/hw/misc/sifive_test.c @@ -22,6 +22,7 @@ #include "hw/sysbus.h" #include "qapi/error.h" #include "qemu/log.h" +#include "qemu/log_instr.h" #include "qemu/module.h" #include "sysemu/runstate.h" #include "hw/hw.h" @@ -42,6 +43,9 @@ static void sifive_test_write(void *opaque, hwaddr addr, case FINISHER_FAIL: exit(code); case FINISHER_PASS: +#ifdef CONFIG_TCG_LOG_INSTR + qemu_log_instr_sync_buffers(); +#endif exit(0); case FINISHER_RESET: qemu_system_reset_request(SHUTDOWN_CAUSE_GUEST_RESET); diff --git a/include/disas/disas.h b/include/disas/disas.h index ca3a801913f..c22c611e485 100644 --- a/include/disas/disas.h +++ b/include/disas/disas.h @@ -18,6 +18,12 @@ void monitor_disas(Monitor *mon, CPUState *cpu, char *plugin_disas(CPUState *cpu, uint64_t addr, size_t size); +char *disas_one_str(CPUState *cpu, void *code, unsigned long size, + target_ulong vma); + +void disas_one_strbuf(CPUState *cpu, void *code, unsigned long size, + target_ulong vma, char *buf, int bufsize); + /* Look up symbol for debugging purpose. Returns "" if unknown. */ const char *lookup_symbol(target_ulong orig_addr); #endif diff --git a/include/exec/log_instr.h b/include/exec/log_instr.h index 72dcaace78f..6ccecec5d81 100644 --- a/include/exec/log_instr.h +++ b/include/exec/log_instr.h @@ -46,7 +46,11 @@ * - uint16_t cpu_get_asid(env, pc) * return the hardware address space identifier for a particular address * - const char *cpu_get_mode_name(mode) - * return the mode name associated with a qemu_log_instr_cpu_mode_t for printing. + * return the mode name associated with a qemu_log_instr_cpu_mode_t for + * printing. + * - bool cpu_log_instr_event_regdump(env, event) + * Builds a register dump for the target, returns true if the register dump + * was not produced and the event should be cancelled. * * - Each target should implement their own register update logging helpers that * call into qemu_log_instr_gpr(), qemu_log_instr_cap() and similar interface @@ -74,10 +78,10 @@ #define _glue_args(...) , ## __VA_ARGS__ #ifdef CONFIG_TCG_LOG_INSTR -#define qemu_ctx_logging_enabled(ctx) unlikely(ctx->base.log_instr_enabled) +#define qemu_ctx_logging_enabled(ctx) unlikely(ctx->base.log_instr_enabled) #define qemu_base_logging_enabled(base) unlikely(base->log_instr_enabled) #else -#define qemu_ctx_logging_enabled(ctx) false +#define qemu_ctx_logging_enabled(ctx) false #define qemu_base_logging_enabled(base) false #endif @@ -85,29 +89,32 @@ * Helper to simplify checking for either instruction logging or * another loglevel enabled */ -#define qemu_log_instr_or_mask_enabled(env, mask) \ - ((unlikely(qemu_loglevel_mask(mask)) || \ - qemu_log_instr_enabled(env)) ? true : false) +#define qemu_log_instr_or_mask_enabled(env, mask) \ + ((unlikely(qemu_loglevel_mask(mask)) || qemu_log_instr_enabled(env)) \ + ? true \ + : false) /* * Helper to simplify emitting a message either to instruction * logging extra text buffer or when another loglevel is enabled */ -#define qemu_log_instr_or_mask_msg(env, mask, msg, ...) do { \ - if (qemu_loglevel_mask(mask)) { \ - qemu_log(msg _glue_args(__VA_ARGS__)); \ - } else if (qemu_log_instr_enabled(env)) { \ - qemu_log_instr_extra(env, msg _glue_args(__VA_ARGS__)); \ - } \ +#define qemu_log_instr_or_mask_msg(env, mask, msg, ...) \ + do { \ + if (qemu_loglevel_mask(mask)) { \ + qemu_log(msg _glue_args(__VA_ARGS__)); \ + } else if (qemu_log_instr_enabled(env)) { \ + qemu_log_instr_extra(env, msg _glue_args(__VA_ARGS__)); \ + } \ } while (0) /* * Helper version of qemu_log_instr_extra that checks whether logging is * enabled. */ -#define qemu_maybe_log_instr_extra(env, msg, ...) do { \ - if (qemu_log_instr_enabled(env)) \ - qemu_log_instr_extra(env, msg _glue_args(__VA_ARGS__)); \ +#define qemu_maybe_log_instr_extra(env, msg, ...) \ + do { \ + if (qemu_log_instr_enabled(env)) \ + qemu_log_instr_extra(env, msg _glue_args(__VA_ARGS__)); \ } while (0) /* @@ -115,10 +122,11 @@ * for the current instruction. * Note that this can be ignored by the output trace format. */ -#define qemu_log_instr_dbg_reg(env, name, value) do { \ - if (qemu_log_instr_enabled(env)) \ - qemu_log_instr_extra(env, " Write %s = " TARGET_FMT_lx "\n", \ - name, value); \ +#define qemu_log_instr_dbg_reg(env, name, value) \ + do { \ + if (qemu_log_instr_enabled(env)) \ + qemu_log_instr_extra(env, " Write %s = " TARGET_FMT_lx "\n", \ + name, value); \ } while (0) /* @@ -126,13 +134,14 @@ * info for the current instruction. * Note that this can be ignored by the output trace format. */ -#define qemu_log_instr_dbg_cap(env, name, value) do { \ - if (qemu_log_instr_enabled(env)) \ - qemu_log_instr_extra( \ - env, " Write %s|" PRINT_CAP_FMTSTR_L1 "\n" \ - " |" PRINT_CAP_FMTSTR_L2 "\n", \ - name, PRINT_CAP_ARGS_L1(value), \ - PRINT_CAP_ARGS_L2(value)); \ +#define qemu_log_instr_dbg_cap(env, name, value) \ + do { \ + if (qemu_log_instr_enabled(env)) \ + qemu_log_instr_extra(env, \ + " Write %s|" PRINT_CAP_FMTSTR_L1 "\n" \ + " |" PRINT_CAP_FMTSTR_L2 "\n", \ + name, PRINT_CAP_ARGS_L1(value), \ + PRINT_CAP_ARGS_L2(value)); \ } while (0) #ifdef CONFIG_TCG_LOG_INSTR @@ -181,15 +190,7 @@ void qemu_log_gen_printf_flush(struct DisasContextBase *base, bool flush_early, bool force_flush); void qemu_log_printf_create_globals(void); -/* - * Request a flush of the TCG when changing loglevel outside of qemu_log_instr. - * TODO(am2419): this should be removed from the interface. - */ -void qemu_log_instr_flush_tcg(bool request_stop); - -/* Helper macro to check for instruction logging enabled */ -#define qemu_log_instr_enabled(env) \ - unlikely(qemu_log_instr_check_enabled((env))) +struct cpu_log_entry; /* * Check whether instruction tracing is enabled. @@ -198,34 +199,38 @@ void qemu_log_instr_flush_tcg(bool request_stop); */ bool qemu_log_instr_check_enabled(CPUArchState *env); +/* Helper macro to check for instruction logging enabled */ +#define qemu_log_instr_enabled(env) \ + unlikely(qemu_log_instr_check_enabled((env))) + /* - * Start instruction tracing. Note that the instruction currently being - * executed will be replaced by a trace start event. + * Register a trace filter for a given CPU. */ -void qemu_log_instr_start(CPUArchState *env, target_ulong pc); +void qemu_log_instr_add_filter(CPUState *env, cpu_log_instr_filter_t filter); /* - * Stop instruction tracing. + * Register a trace filter for a given CPU. */ -void qemu_log_instr_stop(CPUArchState *env, target_ulong pc); +void qemu_log_instr_allcpu_add_filter(cpu_log_instr_filter_t filter); /* - * Log a switch inc CPU modes. - * This will also trigger pause and resume of user-only logging activity, - * depending whether the mode parameter is QEMU_LOG_INSTR_CPU_USER or not. + * Unregister a trace filter for a given CPU. */ -void qemu_log_instr_mode_switch(CPUArchState *env, - qemu_log_instr_cpu_mode_t mode, target_ulong pc); +void qemu_log_instr_remove_filter(CPUState *env, cpu_log_instr_filter_t filter); /* - * Set the given CPU per-CPU log level. + * Unregister a trace filter for a given CPU. */ -void qemu_log_instr_set_level(CPUArchState *env, qemu_log_instr_loglevel_t lvl); +void qemu_log_instr_allcpu_remove_filter(cpu_log_instr_filter_t filter); /* - * Set the per-CPU log level for all the CPUs. + * Log a switch inc CPU modes. + * This will also trigger pause and resume of user-only logging activity, + * depending whether the mode parameter is QEMU_LOG_INSTR_CPU_USER or not. */ -void qemu_log_instr_allcpu_set_level(qemu_log_instr_loglevel_t lvl); +void qemu_log_instr_mode_switch(CPUArchState *env, + qemu_log_instr_cpu_mode_t mode, + target_ulong pc); /* * Emit all buffered instruction logs. @@ -309,16 +314,35 @@ void qemu_log_instr_exception(CPUArchState *env, uint32_t code, /* * Log interrupt event. */ -void qemu_log_instr_interrupt(CPUArchState *env, uint32_t code, target_ulong vector); +void qemu_log_instr_interrupt(CPUArchState *env, uint32_t code, + target_ulong vector); + +/* + * Log extra events. + * XXX we can avoid a copy if we make this return a newly allocated + * log_event_t instead. + */ +void qemu_log_instr_event(CPUArchState *env, log_event_t *evt); + +/* + * Each target must define this function to implement + * register dump events. + */ +bool cpu_log_instr_event_regdump(CPUArchState *env, log_event_t *evt); /* - * Log magic NOP event, we record a function number and 4 arguments. - * Note that we have 6 bytes left in the cvtrace format, we may need - * some trickery to reclaim those. + * Interface to fill register dump log_event_t entries. + * This mirrors the qemu_log_instr_reg/cap/cap_int functions. */ -void qemu_log_instr_evt(CPUArchState *env, uint16_t fn, target_ulong arg0, - target_ulong arg1, target_ulong arg2, - target_ulong arg3); +void qemu_log_instr_event_create_regdump(log_event_t *evt, int nregs); +void qemu_log_instr_event_dump_reg(log_event_t *evt, const char *reg_name, + target_ulong value); +#ifdef TARGET_CHERI +void qemu_log_instr_event_dump_cap(log_event_t *evt, const char *reg_name, + const cap_register_t *value); +void qemu_log_instr_event_dump_cap_int(log_event_t *evt, const char *reg_name, + target_ulong value); +#endif /* * Log extra information as a string. Some logging formats may @@ -327,22 +351,24 @@ void qemu_log_instr_evt(CPUArchState *env, uint16_t fn, target_ulong arg0, void qemu_log_instr_extra(CPUArchState *env, const char *msg, ...); #else /* ! CONFIG_TCG_LOG_INSTR */ -#define qemu_log_instr_enabled(cpu) false -#define qemu_log_instr_start(env, mode, pc) -#define qemu_log_instr_stop(env, mode, pc) -#define qemu_log_instr_mode_switch(...) +#define qemu_log_instr_enabled(cpu) false +#define qemu_log_instr_start(env, mode, pc) +#define qemu_log_instr_stop(env, mode, pc) +#define qemu_log_instr_mode_switch(...) #define qemu_log_instr_flush(env) -#define qemu_log_instr_reg(...) -#define qemu_log_instr_cap(...) -#define qemu_log_instr_mem(...) -#define qemu_log_instr_instr(...) -#define qemu_log_instr_hwtid(...) -#define qemu_log_instr_asid(...) -#define qemu_log_instr_exception(...) -#define qemu_log_instr_interrupt(...) -#define qemu_log_instr_env(...) -#define qemu_log_instr_extra(...) -#define qemu_log_instr_commit(...) +#define qemu_log_instr_reg(...) +#define qemu_log_instr_cap(...) +#define qemu_log_instr_cap_int(...) +#define qemu_log_instr_mem(...) +#define qemu_log_instr_instr(...) +#define qemu_log_instr_hwtid(...) +#define qemu_log_instr_asid(...) +#define qemu_log_instr_exception(...) +#define qemu_log_instr_interrupt(...) +#define qemu_log_instr_env(...) +#define qemu_log_instr_extra(...) +#define qemu_log_instr_event(...) +#define qemu_log_instr_commit(...) #define qemu_log_gen_printf(...) #define qemu_log_gen_printf_flush(base, flush_early, force_flush) #define qemu_log_printf_create_globals(...) diff --git a/include/exec/log_instr_internal.h b/include/exec/log_instr_internal.h new file mode 100644 index 00000000000..8736d715a04 --- /dev/null +++ b/include/exec/log_instr_internal.h @@ -0,0 +1,230 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * Internal TCG instruction logging macros and types. + * This should only be included by the instruction logging backend + * implementation and not from the qemu targets. + */ + +#pragma once + +/* cpu_log_entry flags */ +/* Entry contains a synchronous exception */ +#define LI_FLAG_INTR_TRAP (1 << 0) +/* Entry contains an asynchronous exception */ +#define LI_FLAG_INTR_ASYNC (1 << 1) +#define LI_FLAG_INTR_MASK (LI_FLAG_INTR_TRAP | LI_FLAG_INTR_ASYNC) +/* Entry contains a CPU mode-switch and associated code */ +#define LI_FLAG_MODE_SWITCH (1 << 2) +/* Entry contains instruction data or just events */ +#define LI_FLAG_HAS_INSTR_DATA (1 << 3) + +/* register info flags */ +#define LRI_CAP_REG 1 +#define LRI_HOLDS_CAP 2 + +/* memory op info flags */ +#define LMI_LD 1 +#define LMI_ST 2 +#define LMI_CAP 4 + +#ifndef __cplusplus +/* + * Temporary argument to the log-level switching callbacks. + * This is passed internally to async_run_on_cpu() + */ +typedef struct { + bool global; + qemu_log_instr_loglevel_t next_level; + target_ulong pc; +} qemu_log_next_level_arg_t; + +/* + * Instruction log info associated with each committed log entry. + * This is stored in the per-cpu log cpustate. + */ +typedef struct cpu_log_entry { +#define cpu_log_entry_startzero asid + uint16_t asid; + int flags; + qemu_log_instr_cpu_mode_t next_cpu_mode; + uint32_t intr_code; + target_ulong intr_vector; + target_ulong intr_faultaddr; + + target_ulong pc; + /* Generic instruction opcode buffer */ + int insn_size; + char insn_bytes[TARGET_MAX_INSN_SIZE]; +#define cpu_log_entry_endzero mem + /* + * Array of log_meminfo_t. + * For now we allow multiple accesses to be tied to one instruction. + * Some architectures may have multiple memory accesses + * in the same instruction (e.g. x86-64 pop r/m64, + * vector/matrix instructions, load/store pair). It is unclear + * whether we would treat these as multiple trace "entities". + */ + GArray *mem; + /* Register modifications - array of log_reginfo_t */ + GArray *regs; + /* + * Events associated with the instruction - array of log_event_t. + * Note that events may be present even if the entry does not contain + * valid instruction state. This allows the flexibility of only + * instrumenting a subset of the instructions/events. + */ + GArray *events; + /* Extra text-only log */ + GString *txt_buffer; +} cpu_log_entry_t; + +/* + * Register update info. + * This records a CPU register update occurred during an instruction. + */ +typedef struct log_reginfo { + uint16_t flags; + const char *name; + union { + target_ulong gpr; +#ifdef TARGET_CHERI + cap_register_t cap; +#endif + }; +} log_reginfo_t; + +#define reginfo_is_cap(ri) (ri->flags & LRI_CAP_REG) +#define reginfo_has_cap(ri) (reginfo_is_cap(ri) && (ri->flags & LRI_HOLDS_CAP)) + +/* + * Memory access info. + * This records a memory access occurred during an instruction. + */ +typedef struct log_meminfo { + uint8_t flags; + MemOp op; + target_ulong addr; + union { + uint64_t value; +#ifdef TARGET_CHERI + cap_register_t cap; +#endif + }; +} log_meminfo_t; + +/* + * Callbacks defined by a trace backend implementation. + * These are called to covert instruction tracing events to the corresponding + * binary or text format. + */ +struct trace_backend_hooks { + void (*init)(CPUArchState *env, const char *logfile); + void (*sync)(CPUArchState *env); + void (*pre_commit)(CPUArchState *env, cpu_log_entry_t *entry); + void (*emit_instr)(CPUArchState *env, cpu_log_entry_t *entry); +}; +typedef struct trace_backend_hooks trace_backend_hooks_t; + +/* + * Instruction entry filter function. + * Return false if the entry should be dropped, true otherwise. + */ +typedef bool (*cpu_log_instr_filter_fn_t)(struct cpu_log_entry *entry); + +/* + * Trace debug mode active. This should be constant during execution, + * it is only set via CLI flags before CPU execution. + */ +extern bool trace_debug; + +/* Text backend */ +void init_text_backend(CPUArchState *env, const char *logfile); +void sync_text_backend(CPUArchState *env); +void text_pre_commit_instr(CPUArchState *env, cpu_log_entry_t *entry); +void emit_text_instr(CPUArchState *env, cpu_log_entry_t *entry); +/* CVTrace backend */ +void emit_cvtrace_header(CPUArchState *env); +void emit_cvtrace_entry(CPUArchState *env, cpu_log_entry_t *entry); +#ifdef CONFIG_TRACE_PERFETTO +/* Perfetto backend */ +void init_perfetto_backend(CPUArchState *env, const char *logfile); +void sync_perfetto_backend(CPUArchState *env); +void emit_perfetto_entry(CPUArchState *env, cpu_log_entry_t *entry); +#endif +#ifdef CONFIG_TRACE_PROTOBUF +void init_protobuf_backend(CPUArchState *env, const char *logfile); +void sync_protobuf_backend(CPUArchState *env); +void emit_protobuf_entry(CPUArchState *env, cpu_log_entry_t *entry); +#endif +#ifdef CONFIG_TRACE_JSON +void init_json_backend(CPUArchState *env, const char *logfile); +void sync_json_backend(CPUArchState *env); +void emit_json_entry(CPUArchState *env, cpu_log_entry_t *entry); +#endif + +#ifdef CONFIG_DEBUG_TCG +#define log_assert(x) assert((x)) +#else +#define log_assert(x) +#endif + +/* + * Fetch the log state for a cpu. + */ +static inline cpu_log_instr_state_t *get_cpu_log_state(CPUArchState *env) +{ + return &env_cpu(env)->log_state; +} + +/* Minmum number of per-cpu ring buffer entries */ +#define MIN_ENTRY_BUFFER_SIZE (1 << 16) +#define DEFAULT_ENTRY_BUFFER_SIZE MIN_ENTRY_BUFFER_SIZE + +/* +/* + * Fetch the log entry we are currently populating. + * + * This should only be called on the CPU thread, where instructions are + * recorded. The access to ring_head is not synchronized as it is only possible + * to have concurrent reads while populating the entry. + */ +static inline cpu_log_entry_t *get_cpu_log_entry(CPUArchState *env) +{ + cpu_log_instr_state_t *cpulog = get_cpu_log_state(env); + + return &g_array_index(cpulog->entry_buffer, cpu_log_entry_t, + cpulog->ring_head); +} + +#endif /* __cplusplus */ diff --git a/include/exec/log_instr_perfetto.h b/include/exec/log_instr_perfetto.h new file mode 100644 index 00000000000..c594cdabcb1 --- /dev/null +++ b/include/exec/log_instr_perfetto.h @@ -0,0 +1,165 @@ +/*- + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * Note: This is internal to the C++ perfetto tracing glue code. + */ + +#pragma once + +#ifdef __cplusplus +#include +#include + +/* + * For each CPU we have the following tracks: + * CPU N: track for generic CPU events, contains the following categories: + * - instructions: events related to the instruction stream + * - sched: scheduling events on the CPU or on context-track + * - trap: Contains interrupt and trap events with help from OS-driven events + * - ctrl: Tracing control events (e.g. when tracing is started and stopped) + * Process/Thread/Compartment tracks: + * these are dynamic tracks that are created in response to OS-driven events, + * we rely on the OS to pass the pid/tid/cid triple when relevant. + * Each of these tracks is used to accumulate per-thread and per-compartment + * information. + */ +PERFETTO_DEFINE_CATEGORIES( + perfetto::Category("instructions") + .SetDescription("CPU instructions executed"), + perfetto::Category("memory").SetDescription("Tag and memory load/store"), + perfetto::Category("ctrl").SetDescription("Tracing control events"), + perfetto::Category("trap").SetDescription("CPU trap events"), + perfetto::Category("sched").SetDescription("Scheduling events"), + perfetto::Category("marker").SetDescription( + "Guest trace timestamp markers"), + perfetto::Category("counter").SetDescription("Guest-driven counters"), + perfetto::Category("bb_hit").SetDescription("Basic Block hit counts"), + perfetto::Category("bb_icount").SetDescription("Basic Block instr counts"), + perfetto::Category("br_hit").SetDescription("Branch hit count"), + perfetto::Category("qemu-debug").SetDescription("QEMU debug counters")); +#endif + +/* + * XXX-AM: We can not import directly exec/log_instr_internal.h This is sad as + * we need to generate wrappers to fetch cpu_log_entry fields to fill the trace + * entry protobufs. For now this is somewhat hacky :( + */ +#ifdef __cplusplus +extern "C" { +#endif +/* Opaque handles for cpu_log_entry_t */ +struct cpu_log_entry; +typedef struct cpu_log_entry *cpu_log_entry_handle; +struct log_reginfo; +typedef struct log_reginfo *reg_info_handle; +struct log_meminfo; +typedef struct log_meminfo *mem_info_handle; +typedef void *cap_register_handle; + +void perfetto_init_cpu(int cpu_index, const char *logfile, void **backend_data); +void perfetto_sync_cpu(void *backend_data); +void perfetto_emit_instr(void *backend_data, cpu_log_entry_handle entry_handle); + +/* + * cpu_log_entry getters implemented by the perfetto backend glue code. + * Note: Sadly, the type must be manually be kept in sync with + * log_instr_internal.h + */ +#define CPU_LOG_ENTRY_GETTER_DECL(type, field) \ + type perfetto_log_entry_##field(cpu_log_entry_handle handle) +#define REG_INFO_GETTER_DECL(type, field) \ + type perfetto_reg_info_##field(cpu_log_entry_handle handle, int idx) +#define MEM_INFO_GETTER_DECL(type, field) \ + type perfetto_mem_info_##field(cpu_log_entry_handle handle, int idx) +#define CAPREG_GETTER_DECL(type, field) \ + type perfetto_cap_##field(cap_register_handle handle) +#define TARGET_CAP_DECL(type, field) type perfetto_target_cap_##field() + +#define CPU_LOG_ENTRY_GETTER(type, field) \ + CPU_LOG_ENTRY_GETTER_DECL(type, field) \ + { \ + return (type)(handle->field); \ + } +#define REG_INFO_GETTER(type, field) \ + REG_INFO_GETTER_DECL(type, field) \ + { \ + log_reginfo_t *r = &g_array_index(handle->regs, log_reginfo_t, idx); \ + return (type)(r->field); \ + } +#define MEM_INFO_GETTER(type, field) \ + MEM_INFO_GETTER_DECL(type, field) \ + { \ + log_meminfo_t *m = &g_array_index(handle->mem, log_meminfo_t, idx); \ + return (type)(m->field); \ + } + +CPU_LOG_ENTRY_GETTER_DECL(uint16_t, asid); +CPU_LOG_ENTRY_GETTER_DECL(int, flags); +CPU_LOG_ENTRY_GETTER_DECL(qemu_log_instr_cpu_mode_t, next_cpu_mode); +CPU_LOG_ENTRY_GETTER_DECL(uint32_t, intr_code); +CPU_LOG_ENTRY_GETTER_DECL(uint64_t, intr_vector); +CPU_LOG_ENTRY_GETTER_DECL(uint64_t, intr_faultaddr); +CPU_LOG_ENTRY_GETTER_DECL(uint64_t, pc); +CPU_LOG_ENTRY_GETTER_DECL(int, insn_size); +CPU_LOG_ENTRY_GETTER_DECL(const char *, insn_bytes); +CPU_LOG_ENTRY_GETTER_DECL(int, mem); +CPU_LOG_ENTRY_GETTER_DECL(int, regs); +CPU_LOG_ENTRY_GETTER_DECL(int, events); +CPU_LOG_ENTRY_GETTER_DECL(const char *, txt_buffer); + +log_event_t *perfetto_log_event(cpu_log_entry_handle handle, int idx); + +REG_INFO_GETTER_DECL(uint16_t, flags); +REG_INFO_GETTER_DECL(const char *, name); +REG_INFO_GETTER_DECL(uint64_t, gpr); +REG_INFO_GETTER_DECL(cap_register_handle, cap); + +MEM_INFO_GETTER_DECL(uint8_t, flags); +MEM_INFO_GETTER_DECL(int, op); +MEM_INFO_GETTER_DECL(uint64_t, addr); +MEM_INFO_GETTER_DECL(uint64_t, value); +MEM_INFO_GETTER_DECL(cap_register_handle, cap); + +CAPREG_GETTER_DECL(bool, tag); +CAPREG_GETTER_DECL(bool, sealed); +CAPREG_GETTER_DECL(uint64_t, base); +CAPREG_GETTER_DECL(uint64_t, cursor); +CAPREG_GETTER_DECL(uint64_t, length); +CAPREG_GETTER_DECL(uint32_t, perms); +CAPREG_GETTER_DECL(uint32_t, otype); + +TARGET_CAP_DECL(uint32_t, size); + +#ifdef __cplusplus +} +#endif diff --git a/include/qemu/log_instr.h b/include/qemu/log_instr.h index 1f0afaf5131..8911e945243 100644 --- a/include/qemu/log_instr.h +++ b/include/qemu/log_instr.h @@ -31,6 +31,7 @@ */ #pragma once +#include /* * CPU-independant instruction logging configuration helpers. @@ -46,17 +47,30 @@ #define QEMU_LOG_PRINTF_BUF_DEPTH 32 /* Early flush if buffer gets this full. */ #define QEMU_LOG_PRINTF_FLUSH_BARRIER 32 +/* Max name size for qemu counters and other events */ +#define QEMU_LOG_EVENT_MAX_NAMELEN 64 /* * Instruction logging format */ typedef enum { - QLI_FMT_TEXT = 0, - QLI_FMT_CVTRACE = 1, - QLI_FMT_NOP = 2 -} qemu_log_instr_fmt_t; + QEMU_LOG_INSTR_BACKEND_TEXT = 0, + QEMU_LOG_INSTR_BACKEND_NOP = 1, +#ifdef CONFIG_TRACE_CVTRACE + QEMU_LOG_INSTR_BACKEND_CVTRACE = 2, +#endif +#ifdef CONFIG_TRACE_PERFETTO + QEMU_LOG_INSTR_BACKEND_PERFETTO = 3, +#endif +#ifdef CONFIG_TRACE_PROTOBUF + QEMU_LOG_INSTR_BACKEND_PROTOBUF = 4, +#endif +#ifdef CONFIG_TRACE_JSON + QEMU_LOG_INSTR_BACKEND_JSON = 5, +#endif +} qemu_log_instr_backend_t; -extern qemu_log_instr_fmt_t qemu_log_instr_format; +extern qemu_log_instr_backend_t qemu_log_instr_backend; /* * CPU mode. This unifies the logging codes for CPU mode switches. @@ -76,6 +90,13 @@ typedef enum { QEMU_LOG_INSTR_CPU_MODE_MAX } qemu_log_instr_cpu_mode_t; +/* + * XXX-AM: Consider using protobufs for log events so that they + * are already in a serialized format when they reach the + * perfetto backend. + * How this would affect other formats? + */ + /* * Instruction logging per-CPU log level */ @@ -88,17 +109,129 @@ typedef enum { QEMU_LOG_INSTR_LOGLEVEL_USER = 2, } qemu_log_instr_loglevel_t; -static inline void qemu_log_instr_set_format(qemu_log_instr_fmt_t fmt) -{ - qemu_log_instr_format = fmt; +/* + * Trace event identifiers. + */ +typedef enum { + LOG_EVENT_STATE = 0, + LOG_EVENT_CTX_UPDATE = 1, + LOG_EVENT_MARKER = 2, + LOG_EVENT_REGDUMP = 3, + LOG_EVENT_COUNTER = 4, +} log_event_id_t; + +/* + * Tracing status changed (e.g. trace start/stop) + */ +typedef enum { + LOG_EVENT_STATE_START = 0, + LOG_EVENT_STATE_STOP = 1, + LOG_EVENT_STATE_FLUSH = 2 +} log_event_trace_state_t; + +typedef struct { + log_event_trace_state_t next_state; + qemu_log_instr_loglevel_t level; + uint64_t pc; +} log_event_trace_state_update_t; + +typedef enum { + /* + * Switch context from the current to the new (proc, thread, compartment) ID + */ + LOG_EVENT_CTX_OP_SWITCH = 0 +} log_event_ctx_update_op_t; + +/* + * Context update event. + */ +typedef struct { + log_event_ctx_update_op_t op; /* What changed */ + uint64_t pid; /* Process ID */ + uint64_t tid; /* Thread ID */ + uint64_t cid; /* Compartment ID */ + qemu_log_instr_cpu_mode_t mode; /* CPU mode */ +} log_event_ctx_update_t; + +/* + * Register dump event. + * This is used to emit guest register dumps. The main use case is to + * recover lost state due to pause/unpause of the trace. + */ +typedef struct { + /* + * Register info - array of log_reginfo_t + * Use the qemu_log_instr_event_rdump_* interface to add entries. + */ + GArray *gpr; +} log_event_regdump_t; + +/* + * Counter event. + * This represents an arbitrary named counter. Generally driven from the + * guest OS via NOPs, but can also be generated internally. + */ +typedef struct { + char name[QEMU_LOG_EVENT_MAX_NAMELEN]; + int64_t value; + uint64_t flags; +} log_event_counter_t; + +#define log_event_counter_slot(flags) (flags & 0xffff) +#define log_event_counter_incremental(flags) ((flags >> 32) & 0x01) + +/* + * Trace event. + * This records arbitrary higher-level events associated with instruction + * entries. + * Currently, in order to reduce complexity, the event definitions are + * target-agnostic, and we assume that all targets interested in emitting + * the events will need to implement some logic to fill the data structures + * taking care of any casting necessary. + * This is at the cost of wasting some space for architectures that do not + * have 64bit words. An additional burden is put on the target to perform + * some dynamic allocation for some events. This is sub-optimal but the + * alternative requires extra time to implement and this is good enough + * for now. + */ +typedef struct { + log_event_id_t id; + union { + log_event_trace_state_update_t state; + log_event_ctx_update_t ctx_update; + log_event_regdump_t reg_dump; + uint64_t marker; + log_event_counter_t counter; + }; +} log_event_t; + +void qemu_log_instr_conf_logfile(const char *name); + +#ifdef CONFIG_TRACE_PERFETTO +/* Perfetto backend configuration hooks */ +#ifdef __cplusplus +extern "C" { +#endif +int qemu_log_instr_perfetto_conf_categories(const char *category_list); +void qemu_log_instr_perfetto_enable_interceptor(void); +void qemu_log_instr_perfetto_interceptor_logfile(const char *name); +#ifdef __cplusplus } +#endif +#endif /* CONFIG_TRACE_PERFETTO */ + +#ifndef __cplusplus +/* No visibility in the perfetto tracing backend */ -static inline qemu_log_instr_fmt_t qemu_log_instr_get_format() +static inline void qemu_log_instr_set_backend(qemu_log_instr_backend_t id) { - return qemu_log_instr_format; + qemu_log_instr_backend = id; } -struct cpu_log_instr_info; +static inline qemu_log_instr_backend_t qemu_log_instr_get_backend(void) +{ + return qemu_log_instr_backend; +} typedef union { char charv; @@ -122,6 +255,20 @@ typedef struct { uint64_t valid_entries; /* bitmap of which entries are valid */ } qemu_log_printf_buf_t; +/* + * Per-CPU tracing statistics. + */ +typedef struct qemu_log_instr_stats { + uint64_t entries_emitted; + uint64_t trace_start; + uint64_t trace_stop; +} qemu_log_instr_stats_t; + +#define QEMU_LOG_INSTR_INC_STAT(cpu_state, stat) \ + do { \ + cpu_state->stats.stat++; \ + } while (0) + /* * Per-cpu logging state. */ @@ -137,30 +284,88 @@ typedef struct { /* Per-CPU flags */ int flags; #define QEMU_LOG_INSTR_FLAG_BUFFERED 1 - + /* Trace entry filter functions */ + GArray *filters; /* Ring buffer of log_instr_info */ GArray *instr_info; /* Ring buffer index of the next entry to write */ size_t ring_head; /* Ring buffer index of the first entry to dump */ size_t ring_tail; - + /* Accumulated debug printf buffer */ qemu_log_printf_buf_t qemu_log_printf_buf; + /* Private trace backend state */ + void *backend_data; + /* Statistics for debugging */ + qemu_log_instr_stats_t stats; + /* Ring buffer of cpu_log_entry */ + GArray *entry_buffer; } cpu_log_instr_state_t; +/* + * Handles for instruction filters/callbacks. + * These are used to identify and attach/detach instruction log entry filters, + * the rationale for this is that the filters require access to the private + * instruction log entry record structure and can only be defined within the + * instruction logging core implementation. This solution mimics the trace + * backend handling. + */ +typedef enum { + LOG_INSTR_FILTER_MEM_RANGE = 0, + LOG_FILTER_EVENTS = 1, + LOG_INSTR_FILTER_MAX +} cpu_log_instr_filter_t; + /* * Initialize instruction logging for a cpu. */ void qemu_log_instr_init(CPUState *env); + +/* + * Hook to make sure all tracing buffers are synced on qemu shutdown. + */ +void qemu_log_instr_sync_buffers(void); + +/* + * Global instruction logging hook from qemu tracing commands. + */ int qemu_log_instr_global_switch(int log_flags); /* * Update the ring buffer size. - * Note that this does not guarantee that the existing buffered + * Note that this does not guarantee that the existing buffered * entries will be retained. */ void qemu_log_instr_set_buffer_size(unsigned long buffer_size); +/* + * Set filters to activate from string names. + * This is safe to call during startup as if no CPU exists, we + * will set the filters when the CPU startup occurs. + */ +void qemu_log_instr_set_cli_filters(const char *filter_spec, Error **errp); + +/* + * Add a trace filter during startup. This will be activated on all the CPUs + * that are initialized after the call. + * After the CPUs have been initialized, this will set the filters on all + * existing CPUs. + */ +void qemu_log_instr_add_startup_filter(cpu_log_instr_filter_t filter); + +/* + * Trigger update of the instruction entry filter reusing + * the -dfilter qemu option to limit tracing to only interesting + * memory ranges.. + */ +void qemu_log_instr_mem_filter_update(void); + +/* + * Enable debug statistics recording. + */ +void qemu_log_instr_enable_trace_debug(void); +#endif /* ! __cplusplus */ + #else /* ! CONFIG_TCG_LOG_INSTR */ -#define qemu_log_instr_set_format(fmt) ((void)0) +#define qemu_log_instr_set_backend(id) ((void)0) #endif /* ! CONFIG_TCG_LOG_INSTR */ diff --git a/meson.build b/meson.build index 626e7092fcc..e4db27e6323 100644 --- a/meson.build +++ b/meson.build @@ -1331,7 +1331,7 @@ qapi_gen_depends = [ meson.source_root() / 'scripts/qapi/__init__.py', tracetool = [ python, files('scripts/tracetool.py'), - '--backend=' + config_host['TRACE_BACKENDS'] + '--backend=' + config_host['TRACE_BACKENDS'] ] qemu_version_cmd = [find_program('scripts/qemu-version.sh'), @@ -1514,7 +1514,11 @@ util_ss = util_ss.apply(config_all, strict: false) libqemuutil = static_library('qemuutil', sources: util_ss.sources() + stub_ss.sources() + genh, dependencies: [util_ss.dependencies(), m, glib, socket, malloc]) -qemuutil = declare_dependency(link_with: libqemuutil, + +qemuutil_libs = [libqemuutil] +subdir('trace_extra') + +qemuutil = declare_dependency(link_with: qemuutil_libs, sources: genh + version_res) decodetree = generator(find_program('scripts/decodetree.py'), @@ -2177,6 +2181,9 @@ if config_all.has_key('CONFIG_TCG') summary_info += {'TCG debug enabled': config_host.has_key('CONFIG_DEBUG_TCG')} summary_info += {'TCG interpreter': config_host.has_key('CONFIG_TCG_INTERPRETER')} summary_info += {'TCG instruction logging': config_host.has_key('CONFIG_TCG_LOG_INSTR')} + summary_info += {'TCG instruction logging with google-perfetto': config_host.has_key('CONFIG_TRACE_PERFETTO')} + summary_info += {'TCG instruction logging with protobuf backend': config_host.has_key('CONFIG_TRACE_PROTOBUF')} + summary_info += {'TCG instruction logging with json backend': config_host.has_key('CONFIG_TRACE_JSON')} endif summary_info += {'RVFI-DII': config_host.has_key('CONFIG_RVFI_DII')} summary_info += {'malloc trim support': has_malloc_trim} diff --git a/qemu-options.hx b/qemu-options.hx index 6d4bd843265..db9f3baa2fd 100644 --- a/qemu-options.hx +++ b/qemu-options.hx @@ -4116,11 +4116,63 @@ SRST Set CHERI instruction trace buffer size to the given number of entries ERST -DEF("cheri-trace-format", HAS_ARG, QEMU_OPTION_cheri_trace_format, \ -"-cheri-trace-format [text|cvtrace] Select CHERI trace mode.\n", QEMU_ARCH_ALL) +DEF("cheri-trace-backend", HAS_ARG, QEMU_OPTION_cheri_trace_backend, \ +"-cheri-trace-backend [text|cvtrace|perfetto] Select CHERI trace mode.\n", QEMU_ARCH_ALL) SRST -``-cheri-trace-format type`` - Set CHERI trace format to (text or cvtrace) +``-cheri-trace-backend type`` + Set CHERI trace backend to (text, cvtrace or perfetto) +ERST + +DEF("cheri-trace-logfile", HAS_ARG, QEMU_OPTION_trace_logfile, \ +"-cheri-trace-logfile [logfile] \ + Set log file for TCG instruction traces, defaults to qemu_trace.txt.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-logfile [logfile]`` + Set trace output file. +ERST + +DEF("cheri-trace-perfetto-categories", HAS_ARG, QEMU_OPTION_trace_perfetto_categories, \ +"-cheri-trace-perfetto-categories category[,...] Select categories to trace.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-perfetto-categories category[,...]`` + Select categories of messages to include in the trace (instructions, stats) +ERST + +DEF("cheri-trace-perfetto-interceptor-logfile", HAS_ARG, QEMU_OPTION_trace_perfetto_interceptor_logfile, \ +"-cheri-trace-perfetto-categories category[,...] \ + Set log file for perfetto interceptor, defaults to mem_access.trace.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-perfetto-interceptor-logfile [logfile]`` + Set perfetto interceptor trace output file. +ERST + +DEF("cheri-trace-perfetto-enable-interceptor", 0, QEMU_OPTION_trace_perfetto_enable_interceptor, \ +"-cheri-trace-perfetto-enable-interceptor Enable perfetto interceptor.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-perfetto-enable-interceptor `` + Enable perfetto interceptor, skips normal perfetto tracing service. +ERST + +DEF("cheri-trace-protobuf-logfile", HAS_ARG, QEMU_OPTION_trace_protobuf_logfile, \ +"-cheri-trace-protobuf-logfile [logfile] \ + Set log file for protobuf traces, defaults to qemu_trace.pb.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-protobuf-logfile [logfile]`` + Set protobuf trace output file. +ERST + +DEF("cheri-trace-filters", HAS_ARG, QEMU_OPTION_cheri_trace_filters, \ +"-cheri-trace-filters [event] Select trace filters to use.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-filters name[,...]`` + Set CHERI trace filters to use. Available filters are: events. +ERST + +DEF("cheri-trace-debug", 0, QEMU_OPTION_cheri_trace_debug, \ +"-cheri-trace-debug Enable debug stats.\n", QEMU_ARCH_ALL) +SRST +``-cheri-trace-debug `` + Enable CHERI instruction tracing debugging statistics. ERST DEF("cheri-c2e-on-unrepresentable", 0, QEMU_OPTION_cheri_c2e_on_unrepresentable, \ diff --git a/softmmu/vl.c b/softmmu/vl.c index 742179c13cf..ba7413d9236 100644 --- a/softmmu/vl.c +++ b/softmmu/vl.c @@ -1619,6 +1619,9 @@ void qemu_system_killed(int signal, pid_t pid) void qemu_system_shutdown_request(ShutdownCause reason) { +#ifdef CONFIG_TCG_LOG_INSTR + qemu_log_instr_sync_buffers(); +#endif trace_qemu_system_shutdown_request(reason); replay_shutdown_request(reason); shutdown_requested = reason; @@ -3747,19 +3750,54 @@ void qemu_init(int argc, char **argv, char **envp) } break; #if defined(CONFIG_TCG_LOG_INSTR) - case QEMU_OPTION_cheri_trace_format: + case QEMU_OPTION_cheri_trace_backend: if (strcmp(optarg, "text") == 0) { - qemu_log_instr_set_format(QLI_FMT_TEXT); + qemu_log_instr_set_backend(QEMU_LOG_INSTR_BACKEND_TEXT); +#ifdef CONFIG_TRACE_CVTRACE } else if (strcmp(optarg, "cvtrace") == 0) { - qemu_log_instr_set_format(QLI_FMT_CVTRACE); + qemu_log_instr_set_backend(QEMU_LOG_INSTR_BACKEND_CVTRACE); +#endif + } else if (strcmp(optarg, "nop") == 0) { + qemu_log_instr_set_backend(QEMU_LOG_INSTR_BACKEND_NOP); +#ifdef CONFIG_TRACE_PERFETTO + } else if (strcmp(optarg, "perfetto") == 0) { + qemu_log_instr_set_backend(QEMU_LOG_INSTR_BACKEND_PERFETTO); +#endif +#ifdef CONFIG_TRACE_PROTOBUF + } else if (strcmp(optarg, "protobuf") == 0) { + qemu_log_instr_set_backend(QEMU_LOG_INSTR_BACKEND_PROTOBUF); +#endif +#ifdef CONFIG_TRACE_JSON + } else if (strcmp(optarg, "json") == 0) { + qemu_log_instr_set_backend(QEMU_LOG_INSTR_BACKEND_JSON); +#endif } else { printf("Invalid choice for cheri-trace-format: '%s'\n", optarg); exit(1); } break; + case QEMU_OPTION_trace_logfile: + qemu_log_instr_conf_logfile(optarg); + break; +#ifdef CONFIG_TRACE_PERFETTO + case QEMU_OPTION_trace_perfetto_categories: + qemu_log_instr_perfetto_conf_categories(optarg); + break; + case QEMU_OPTION_trace_perfetto_enable_interceptor: + qemu_log_instr_perfetto_enable_interceptor(); + break; + case QEMU_OPTION_trace_perfetto_interceptor_logfile: + qemu_log_instr_perfetto_interceptor_logfile(optarg); +#endif case QEMU_OPTION_cheri_trace_buffer_size: qemu_log_instr_set_buffer_size(strtoul(optarg, NULL, 0)); break; + case QEMU_OPTION_cheri_trace_filters: + qemu_log_instr_set_cli_filters(optarg, &error_fatal); + break; + case QEMU_OPTION_cheri_trace_debug: + qemu_log_instr_enable_trace_debug(); + break; #endif /* CONFIG_TCG_LOG_INSTR */ #ifdef TARGET_CHERI diff --git a/target/arm/helper.c b/target/arm/helper.c index ee72a1a3c18..c9fe942ee74 100644 --- a/target/arm/helper.c +++ b/target/arm/helper.c @@ -13780,10 +13780,10 @@ void aarch64_sve_change_el(CPUARMState *env, int old_el, } #endif -#ifdef TARGET_CHERI - #ifdef CONFIG_TCG_LOG_INSTR +#ifdef TARGET_CHERI + void HELPER(arm_log_instr)(CPUARMState *env, target_ulong pc, uint32_t opcode) { if (qemu_log_instr_enabled(env)) { @@ -13793,4 +13793,10 @@ void HELPER(arm_log_instr)(CPUARMState *env, target_ulong pc, uint32_t opcode) } #endif + +bool cpu_log_instr_event_regdump(CPUARMState *env, log_event_t *event) +{ + return true; +} + #endif diff --git a/target/i386/helper.c b/target/i386/helper.c index 034f46bcc21..86f56a549f0 100644 --- a/target/i386/helper.c +++ b/target/i386/helper.c @@ -1198,3 +1198,10 @@ void x86_stq_phys(CPUState *cs, hwaddr addr, uint64_t val) address_space_stq(as, addr, val, attrs, NULL); } #endif + +#ifdef CONFIG_TCG_LOG_INSTR +bool cpu_log_instr_event_regdump(CPUX86State *env, log_event_t *event) +{ + return true; +} +#endif diff --git a/target/mips/op_helper_log_instr.c b/target/mips/op_helper_log_instr.c index fcc8d0421ce..f6fdf1f0e5f 100644 --- a/target/mips/op_helper_log_instr.c +++ b/target/mips/op_helper_log_instr.c @@ -100,6 +100,11 @@ void helper_mips_log_instr_drop(CPUMIPSState *env) qemu_log_instr_drop(env); } +bool cpu_log_instr_event_regdump(CPUMIPSState *env, log_event_t *event) +{ + return true; +} + /* * Note: do not check for logging enabled first, as this triggers * user logging start. diff --git a/target/riscv/cpu.h b/target/riscv/cpu.h index 7e43fdadf3f..f42a5e77766 100644 --- a/target/riscv/cpu.h +++ b/target/riscv/cpu.h @@ -737,6 +737,30 @@ static inline const char *cpu_get_mode_name(qemu_log_instr_cpu_mode_t mode) return riscv_cpu_mode_names[mode]; return ""; } + +/* + * Currently this is not required by the instruction logging backend, it + * is used internally in the target to get the correct code for the mode. + */ +static inline qemu_log_instr_cpu_mode_t cpu_priv_to_mode(target_ulong priv) +{ + qemu_log_instr_cpu_mode_t mode; + + switch (priv) { + case PRV_M: + mode = RISCV_LOG_INSTR_CPU_M; + break; + case PRV_S: + mode = RISCV_LOG_INSTR_CPU_S; + break; + case PRV_H: + mode = RISCV_LOG_INSTR_CPU_H; + break; + default: + mode = RISCV_LOG_INSTR_CPU_U; + } + return mode; +} #endif int riscv_csrrw(CPURISCVState *env, int csrno, target_ulong *ret_value, diff --git a/target/riscv/cpu_helper.c b/target/riscv/cpu_helper.c index 4b2518543b1..881c1086853 100644 --- a/target/riscv/cpu_helper.c +++ b/target/riscv/cpu_helper.c @@ -339,22 +339,8 @@ void riscv_cpu_set_mode(CPURISCVState *env, target_ulong newpriv) env->load_res = -1; #ifdef CONFIG_TCG_LOG_INSTR - qemu_log_instr_cpu_mode_t mode; - - switch (newpriv) { - case PRV_M: - mode = RISCV_LOG_INSTR_CPU_M; - break; - case PRV_S: - mode = RISCV_LOG_INSTR_CPU_S; - break; - case PRV_H: - mode = RISCV_LOG_INSTR_CPU_H; - break; - default: - mode = RISCV_LOG_INSTR_CPU_U; - } - qemu_log_instr_mode_switch(env, mode, cpu_get_recent_pc(env)); + qemu_log_instr_mode_switch(env, cpu_priv_to_mode(newpriv), + cpu_get_recent_pc(env)); #endif } diff --git a/target/riscv/helper.h b/target/riscv/helper.h index d167e4b236c..09c54114a85 100644 --- a/target/riscv/helper.h +++ b/target/riscv/helper.h @@ -82,6 +82,7 @@ DEF_HELPER_3(sc_c_cap, tl, env, i32, i32) #ifdef CONFIG_TCG_LOG_INSTR DEF_HELPER_FLAGS_3(riscv_log_gpr_write, TCG_CALL_NO_RWG, void, env, i32, tl) DEF_HELPER_FLAGS_4(riscv_log_instr, TCG_CALL_NO_RWG, void, env, tl, i32, i32) +DEF_HELPER_FLAGS_2(riscv_log_instr_event, TCG_CALL_NO_RWG, void, env, tl) #endif /* Special functions */ diff --git a/target/riscv/insn_trans/trans_rvi.c.inc b/target/riscv/insn_trans/trans_rvi.c.inc index 8c00f3dc9a5..eb44d48d1ea 100644 --- a/target/riscv/insn_trans/trans_rvi.c.inc +++ b/target/riscv/insn_trans/trans_rvi.c.inc @@ -284,6 +284,9 @@ static bool trans_slti(DisasContext *ctx, arg_slti *a) gen_helper_qemu_log_instr_stop(cpu_env, tpc); ctx->base.is_jmp = DISAS_NORETURN; break; + case 0x2f: + gen_helper_riscv_log_instr_event(cpu_env, tpc); + break; } tcg_temp_free(tpc); diff --git a/target/riscv/op_helper_cheri.c b/target/riscv/op_helper_cheri.c index cb115200668..8588b5415e6 100644 --- a/target/riscv/op_helper_cheri.c +++ b/target/riscv/op_helper_cheri.c @@ -156,7 +156,11 @@ void HELPER(cspecialrw)(CPUArchState *env, uint32_t cd, uint32_t cs, { uintptr_t _host_return_address = GETPC(); // Ensure that env->PCC.cursor is correct: - cpu_restore_state(env_cpu(env), _host_return_address, false); + /* + * This breaks -icount because it triggers early deallocation of the TB. + * It seems that it is only required for logging anyway. + */ + /* cpu_restore_state(env_cpu(env), _host_return_address, false); */ assert(index <= 31 && "Bug in translator?"); enum SCRAccessMode mode = scr_info[index].access; diff --git a/target/riscv/op_helper_log_instr.c b/target/riscv/op_helper_log_instr.c index ac933f95b71..5ef6dfe40d7 100644 --- a/target/riscv/op_helper_log_instr.c +++ b/target/riscv/op_helper_log_instr.c @@ -34,12 +34,48 @@ #include "exec/log_instr.h" #include "exec/helper-proto.h" #include "cpu.h" +#ifdef TARGET_CHERI +#include "cheri-helper-utils.h" +#include "cheri-lazy-capregs.h" +#endif + +#ifdef TARGET_CHERI +#define get_gpr_value(env, regnum) get_capreg_cursor(env, regnum) +#else +#define get_gpr_value(env, regnum) (env->gpr[regnum]) +#endif + +/* + * Read a null-terminated guest string without requiring a strlen() in + * the guest. This is probably slower but does not perturb guest call-graph. + */ +static int read_guest_cstring(CPURISCVState *env, target_ulong vaddr, + char *buffer, size_t maxlen) +{ + int ret = 0; + + buffer[maxlen - 1] = '\0'; + while (maxlen > 1) { + ret = cpu_memory_rw_debug(env_cpu(env), vaddr, buffer, 1, false); + if (ret != 0 || *buffer == '\0') { + break; + } + maxlen--; + vaddr++; + buffer++; + } + + return ret; +} void HELPER(riscv_log_gpr_write)(CPURISCVState *env, uint32_t regnum, target_ulong value) { if (qemu_log_instr_enabled(env)) { - // TODO(am2419): should be using qemu_log_isntr_cap_int() when TARGET_CHERI? + /* + * TODO(am2419): should be using qemu_log_isntr_cap_int() when + * TARGET_CHERI? + */ qemu_log_instr_reg(env, riscv_int_regnames[regnum], value); } } @@ -52,3 +88,91 @@ void HELPER(riscv_log_instr)(CPURISCVState *env, target_ulong pc, qemu_log_instr(env, pc, (char *)&opcode, opcode_size); } } + +/* + * Events are triggered by a magic no-op. The arguments for the event + * are passed via the target ABI argument registers. + * There is a maximum of 7 arguments supported. + * void event_noop(event_type, a1, a2, a3, a4, a5, a6, a7) + * + * We access GPRs directly from env to work around the argument limit + * for TCG helpers. + */ +void HELPER(riscv_log_instr_event)(CPURISCVState *env, target_ulong pc) +{ + log_event_t event; + target_ulong vaddr; + int ret; + + event.id = get_gpr_value(env, 10); + + if (qemu_log_instr_enabled(env)) { + switch (event.id) { + case LOG_EVENT_CTX_UPDATE: + event.ctx_update.op = get_gpr_value(env, 11); + event.ctx_update.pid = get_gpr_value(env, 12); + event.ctx_update.tid = get_gpr_value(env, 13); + event.ctx_update.cid = get_gpr_value(env, 14); + event.ctx_update.mode = cpu_priv_to_mode(env->priv); + break; + case LOG_EVENT_MARKER: + event.marker = get_gpr_value(env, 11); + break; + case LOG_EVENT_REGDUMP: + cpu_log_instr_event_regdump(env, &event); + break; + case LOG_EVENT_COUNTER: + vaddr = get_gpr_value(env, 11); + ret = read_guest_cstring(env, vaddr, (char *)event.counter.name, + sizeof(event.counter.name)); + if (ret != 0) { + warn_report("LOG EVENT HELPER: Could not read guest string at" + " vaddr 0x" TARGET_FMT_lx, vaddr); + return; + } + event.counter.value = (int64_t)get_gpr_value(env, 12); + event.counter.flags = get_gpr_value(env, 13); + break; + default: + warn_report("Unsupported event ID for TCG instr logging %d", + event.id); + return; + } + + qemu_log_instr_event(env, &event); + } +} + +/* + * Target-dependent hook to emit register dump events. + * This is automatically called by the tracing subsystem + * when tracing is resumed. + */ +bool cpu_log_instr_event_regdump(CPURISCVState *env, log_event_t *event) +{ + int i; + int nregs; + + event->id = LOG_EVENT_REGDUMP; +#ifdef TARGET_CHERI + nregs = NUM_LAZY_CAP_REGS; +#else + nregs = 32; +#endif + qemu_log_instr_event_create_regdump(event, nregs); + for (i = 0; i < nregs; i++) { +#ifdef TARGET_CHERI + const cap_register_t *value = get_readonly_capreg(env, i); + if (value->cr_tag) + qemu_log_instr_event_dump_cap(event, riscv_int_regnames[i], value); + else + qemu_log_instr_event_dump_cap_int(event, riscv_int_regnames[i], + cap_get_cursor(value)); +#else + target_ulong value = env->gpr[i]; + qemu_log_instr_event_dump_reg(event, riscv_int_regnames[i], value); +#endif + } + + return false; +} diff --git a/trace_extra/cheri-perfetto b/trace_extra/cheri-perfetto new file mode 160000 index 00000000000..9df9ea6d147 --- /dev/null +++ b/trace_extra/cheri-perfetto @@ -0,0 +1 @@ +Subproject commit 9df9ea6d1474e1589240a853a4173dcf094fefed diff --git a/trace_extra/dynamorio b/trace_extra/dynamorio new file mode 160000 index 00000000000..acb883e8d64 --- /dev/null +++ b/trace_extra/dynamorio @@ -0,0 +1 @@ +Subproject commit acb883e8d64d0174f76a2eacf06cdf62b76732af diff --git a/trace_extra/guest_context_tracker.cc b/trace_extra/guest_context_tracker.cc new file mode 100644 index 00000000000..24ee0386af6 --- /dev/null +++ b/trace_extra/guest_context_tracker.cc @@ -0,0 +1,331 @@ +/*- + * Copyright (c) 2021 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#include +#include +#include +#include +#include +#include +#include +#include "trace_extra/guest_context_tracker.hh" + +namespace icl = boost::icl; + +using addr_range = icl::interval; + +namespace cheri +{ + +/* + * Dynamically created tracks and track data. + * The track_state_lock must be held for updating the track_state map. + */ +std::mutex track_state_lock; +std::unordered_map, + tuple_hasher> + track_state_map; + +/* + * Constant mapping of QEMUDebugCounter IDs to counter track names + */ +const std::array debug_counter_names{ + "tb_icount", + "tb_icount_tracing", +}; + +/* Helper to generate unique IDs for dynamic tracks */ +unsigned long gen_track_uuid() +{ + static std::mutex rnd_mutex; + static std::random_device rand_dev; + static std::mt19937_64 rand_gen(rand_dev()); + static std::uniform_int_distribution track_uuid_gen( + 0ul, std::numeric_limits::max()); + + { + const std::lock_guard lock(rnd_mutex); + return track_uuid_gen(rand_gen); + } +} + +std::string ctx_track_name(qemu_ctx_id key) +{ + uint64_t pid = std::get<0>(key); + uint64_t tid = std::get<1>(key); + uint64_t cid = std::get<2>(key); + int mode = std::get<3>(key); + return "CTX " + std::to_string(pid) + ":" + std::to_string(tid) + ":" + + std::to_string(cid) + ":" + std::to_string(mode); +} + +perfetto::protos::pbzero::QEMULogEntryModeSwitch +qemu_cpu_mode_to_trace(qemu_log_instr_cpu_mode_t mode) +{ + // NOTE: We rely on the fact that the protobuf enum ModeSwitch + // uses the same numbering as qemu_log_instr_cpu_mode_t + return static_cast(mode); +} + +qemu_cpu_track::qemu_cpu_track(int id) + : perfetto::Track(gen_track_uuid(), perfetto::Track()), cpu_id(id) +{ +} + +perfetto::protos::gen::TrackDescriptor qemu_cpu_track::Serialize() const +{ + auto desc = Track::Serialize(); + std::string name("CPU " + std::to_string(cpu_id)); + desc.set_name(name); + return desc; +} + +void qemu_cpu_track::Serialize( + perfetto::protos::pbzero::TrackDescriptor *desc) const +{ + auto bytes = Serialize().SerializeAsString(); + desc->AppendRawProtoBytes(bytes.data(), bytes.size()); +} + +perfetto::protos::gen::TrackDescriptor qemu_context_track::Serialize() const +{ + auto desc = Track::Serialize(); + auto cheri_desc = desc.mutable_cheri_context(); + cheri_desc->set_pid(pid); + cheri_desc->set_tid(tid); + cheri_desc->set_cid(cid); + cheri_desc->set_el(mode); + desc.set_name(name); + return desc; +} + +void qemu_context_track::Serialize( + perfetto::protos::pbzero::TrackDescriptor *desc) const +{ + auto bytes = Serialize().SerializeAsString(); + desc->AppendRawProtoBytes(bytes.data(), bytes.size()); +} + +qemu_context_track::qemu_context_track(qemu_ctx_id key) + : perfetto::Track(gen_track_uuid(), perfetto::Track()), + pid(std::get<0>(key)), tid(std::get<1>(key)), cid(std::get<2>(key)), + mode(std::get<3>(key)), name(ctx_track_name(key)) +{ +} + +qemu_ctx_id qemu_context_track::get_id() const +{ + return std::make_tuple(pid, tid, cid, mode); +} + +void qemu_bb_tracker::track_next(cpu_log_entry_handle entry, uint64_t pc) +{ + if (!TRACE_EVENT_CATEGORY_ENABLED("bb_hit") && + !TRACE_EVENT_CATEGORY_ENABLED("br_hit")) { + return; + } + + if (pc == 0) { + pc = perfetto_log_entry_pc(entry); + } + int size = perfetto_log_entry_insn_size(entry); + /* When resuming after reset accept anything as a next instruction */ + if (bb_start == 0) { + bb_start = pc; + bb_icount = 0; + } else if (pc != next_pc && next_pc != 0) { + /* Presume we are branching */ + assert(bb_start != 0 && "PC bb start was not updated"); + assert(last_pc != 0 && "last_pc can not be zero"); + /* Update basic block info */ + bb_map += std::make_pair(addr_range::right_open(bb_start, last_pc), + bb_value(1ul, bb_icount)); + /* Update branch info */ + branch_id bid = std::make_pair(last_pc, pc); + branch_map[bid] += 1; + /* Reset */ + bb_start = pc; + bb_icount = 0; + } + bb_icount += 1; + next_pc = pc + size; + last_pc = pc; +} + +void qemu_bb_tracker::reset(uint64_t pc) +{ + if (!TRACE_EVENT_CATEGORY_ENABLED("bb_hit") && + !TRACE_EVENT_CATEGORY_ENABLED("br_hit")) { + return; + } + + if (bb_start == 0) { + /* Nothing to flush */ + return; + } + /* With pc=0 flush discarding any currently active bb */ + if (pc != 0) { + bb_map += std::make_pair(addr_range::right_open(bb_start, pc), + bb_value(1ul, bb_icount)); + } + bb_start = bb_icount = next_pc = last_pc = 0; + + /* XXX-AM: Somewhat arbitrary tuning constant, depend on the SHM size */ + if (boost::icl::interval_count(bb_map) > 5000 || branch_map.size() > 5000) + flush(); +} + +void qemu_bb_tracker::flush() +{ + for (const auto &keyval : bb_map) { + auto &interval = keyval.first; + TRACE_INTERVAL("bb_hit", track, interval.lower(), interval.upper(), + keyval.second.hit); + TRACE_INTERVAL("bb_icount", track, interval.lower(), interval.upper(), + keyval.second.icount); + } + for (const auto &keyval : branch_map) { + auto &bid = keyval.first; + TRACE_INTERVAL("br_hit", track, std::get<0>(bid), std::get<1>(bid), + keyval.second); + } + bb_map.clear(); + branch_map.clear(); +} + +guest_context_tracker::guest_context_tracker(int cpu_id) : cpu_state(cpu_id) {} + +void guest_context_tracker::mode_update( + cpu_log_entry_handle entry, + perfetto::protos::pbzero::QEMULogEntryModeSwitch new_mode) +{ + if (ctx_state == nullptr) + return; + + auto key = ctx_state->track.get_id(); + std::get<3>(key) = new_mode; + /* Check if we have a track for this mode */ + std::shared_ptr state; + { + std::lock_guard track_state_guard(track_state_lock); + auto it = track_state_map.find(key); + if (it == track_state_map.end()) { + state = std::make_shared(key); + track_state_map.emplace(key, state); + } else { + /* Existing context */ + state = it->second; + } + } + + if (TRACE_EVENT_CATEGORY_ENABLED("bb_hit") || + TRACE_EVENT_CATEGORY_ENABLED("br_hit")) { + if (ctx_state && ctx_state != state) { + /* We are changing context */ + ctx_state->bb_tracker->reset(perfetto_log_entry_pc(entry)); + } + } + ctx_state = state; +} + +void guest_context_tracker::context_update(cpu_log_entry_handle entry, + const log_event_ctx_update_t *evt) +{ + // Currently these are the only ones existing + assert((evt->op == LOG_EVENT_CTX_OP_SWITCH) && "Invalid ctx update op"); + /* + * Find or create the track associated with the new context and set it as + * the current context track on the CPU. This will be used to log + * per-context events. + * XXX-AM: Currently it is assumed that contexts are unique, this is clearly + * not the case with PID/TID reuse and we should do something to detect + * this. This seems mostly relevant only for long-lived traces. + */ + + auto mode = qemu_cpu_mode_to_trace(evt->mode); + /* Fetch the tracks for the new context */ + qemu_ctx_id key = std::make_tuple(evt->pid, evt->tid, evt->cid, mode); + std::shared_ptr state; + { + std::lock_guard track_state_guard(track_state_lock); + auto it = track_state_map.find(key); + if (it == track_state_map.end()) { + state = std::make_shared(key); + track_state_map.emplace(key, state); + } else { + /* Existing context */ + state = it->second; + } + } + + if (TRACE_EVENT_CATEGORY_ENABLED("bb_hit") || + TRACE_EVENT_CATEGORY_ENABLED("br_hit")) { + if (ctx_state && ctx_state != state) { + /* We are changing context */ + ctx_state->bb_tracker->reset(perfetto_log_entry_pc(entry)); + } + } + ctx_state = state; +} + +void guest_context_tracker::flush_all_ctx_data(uint64_t pc) +{ + /* Flush per-CPU and current context stats */ + if (TRACE_EVENT_CATEGORY_ENABLED("bb_hit") || + TRACE_EVENT_CATEGORY_ENABLED("br_hit")) { + cpu_state.bb_tracker->reset(pc); + cpu_state.bb_tracker->flush(); + if (ctx_state) { + ctx_state->bb_tracker->reset(pc); + ctx_state->bb_tracker->flush(); + } + std::lock_guard track_state_guard(track_state_lock); + for (auto id_and_state : track_state_map) { + qemu_bb_tracker *bb_tracker = id_and_state.second->bb_tracker.get(); + if (bb_tracker != ctx_state->bb_tracker.get()) { + bb_tracker->reset(0); + bb_tracker->flush(); + } + } + } +} + +qemu_fallback_state *guest_context_tracker::get_cpu_state() +{ + return &cpu_state; +} + +qemu_tracker_state *guest_context_tracker::get_ctx_state() +{ + if (ctx_state) + return ctx_state.get(); + else + return &cpu_state; +} + +} // namespace cheri diff --git a/trace_extra/guest_context_tracker.hh b/trace_extra/guest_context_tracker.hh new file mode 100644 index 00000000000..357d36c7417 --- /dev/null +++ b/trace_extra/guest_context_tracker.hh @@ -0,0 +1,273 @@ +/*- + * Copyright (c) 2021 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#pragma once + +#include +#include +#include +#include +#include +#include +#include +#include +#include "qemu/log_instr.h" +#include "exec/log_instr_perfetto.h" + +#include + +#include "tuple_index.hh" +#include "trace_extra/trace_counters.hh" + +namespace cheri +{ + +using cpu_mode_type = perfetto::protos::pbzero::QEMULogEntryModeSwitch; +/* (pid, tid, cid, mode) */ +using qemu_ctx_id = std::tuple; + +/* + * Generate a unique track ID. + * The ID is guaranteed to be unique within a qemu run, but not with + * respect to other data sources. + */ +unsigned long gen_track_uuid(); + +perfetto::protos::pbzero::QEMULogEntryModeSwitch +qemu_cpu_mode_to_trace(qemu_log_instr_cpu_mode_t mode); + +extern const std::array + debug_counter_names; + +/* + * Custom track representing a QEMU guest context. + */ +struct qemu_context_track : public perfetto::Track { + const uint64_t pid; + const uint64_t tid; + const uint64_t cid; + const cpu_mode_type mode; + const std::string name; + + qemu_ctx_id get_id() const; + perfetto::protos::gen::TrackDescriptor Serialize() const; + void Serialize(perfetto::protos::pbzero::TrackDescriptor *desc) const; + qemu_context_track(qemu_ctx_id key); +}; + +/* + * Custom track representing a QEMU vcpu. + */ +struct qemu_cpu_track : public perfetto::Track { + const int cpu_id; + + perfetto::protos::gen::TrackDescriptor Serialize() const; + void Serialize(perfetto::protos::pbzero::TrackDescriptor *desc) const; + qemu_cpu_track(int id); +}; + +/* + * Effective basic block execution tracker. + * This tracks the execution of ranges of code not interrupted by branches. + * Note that these are 'effective', in the sense that a measured range may + * contain branch instructions but the branch is never taken. + * Interrupts will cause spurious block detection. + */ +class qemu_bb_tracker +{ + using branch_id = std::tuple; + + struct bb_value { + uint64_t hit; + uint64_t icount; + + bb_value() : hit(0), icount(0) {} + bb_value(uint64_t h, uint64_t i) : hit(h), icount(i) {} + bb_value(const bb_value &o) = default; + + bb_value operator+(const bb_value &o) const + { + return bb_value(hit + o.hit, icount + o.icount); + } + + bb_value &operator+=(const bb_value &o) + { + hit += o.hit; + icount += o.icount; + return *this; + } + + bool operator==(const bb_value &o) const + { + return hit == o.hit && icount == o.icount; + } + }; + /* + * Histogram of basic-block ranges with associated # hits and instruction + * count + */ + boost::icl::interval_map bb_map; + /* + * Branch map (src, target) -> # hits + */ + std::unordered_map> branch_map; + + /* + * Interval track on which we emit data. + */ + perfetto::IntervalTrack track; + uint64_t last_pc; + uint64_t next_pc; + uint64_t bb_start; + uint64_t bb_icount; + + public: + qemu_bb_tracker(perfetto::Track &context_track, const char *name) + : track(gen_track_uuid(), name, context_track), last_pc(0), next_pc(0), + bb_start(0) + { + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); + } + virtual ~qemu_bb_tracker() + { + perfetto::TrackEvent::EraseTrackDescriptor(track); + } + + void track_next(cpu_log_entry_handle entry, uint64_t pc = 0); + void reset(uint64_t pc); + void flush(); +}; + +/* + * Common CPU and context data. + */ +struct qemu_tracker_state { + std::unique_ptr bb_tracker; + std::unique_ptr counters; + + virtual perfetto::Track *get_track() = 0; + virtual ~qemu_tracker_state() = default; +}; + +struct qemu_context_state : public qemu_tracker_state { + qemu_context_track track; + + qemu_context_state(qemu_ctx_id id) : track(id) + { + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); + + bb_tracker = + std::make_unique(track, track.name.c_str()); + counters = std::make_unique(track); + } + + ~qemu_context_state() + { + perfetto::TrackEvent::EraseTrackDescriptor(track); + } + + perfetto::Track *get_track() + { + return &track; + } +}; + +struct qemu_fallback_state : public qemu_tracker_state { + qemu_cpu_track track; + + qemu_fallback_state(int id) : track(id) + { + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); + + bb_tracker = std::make_unique(track, "CPU track"); + counters = std::make_unique(track); + } + + ~qemu_fallback_state() + { + perfetto::TrackEvent::EraseTrackDescriptor(track); + } + + perfetto::CounterTrack + get_debug_counter_track(QEMUDebugCounter counter_index) + { + return perfetto::CounterTrack( + debug_counter_names[counter_index].c_str(), track); + } + + perfetto::Track *get_track() + { + return &track; + } +}; + +/* + * Track current guest context associated to a CPU. + * This allows to charge events to the correct context by recording + * what is currently active on a CPU. + * There is one guest_context_tracker per virtual CPU. + * We manage the following tracks for each CPU: + * - A global CPU N track, for events charged to a CPU from an unknown context + * or where the context is not relevant. + * - Each new process in the system gets allocated a new perfetto::ProcessTrack + * TODO: Currently there is no way to notify when the PID is discarded. + * - Each new thread in the system gets allocated a new perfetto::ThreadTrack + * and the corresponding process as parent. + * - TODO Each new compartment ID gets allocated a new + * perfetto::CheriCompartmentTrack. Note that compartment tracks are not + * associated to a single thread, instead multiple threads may record events + * there. Each new context can have associated data that is charged to that + * context and only emitted to the track periodically. This is to avoid + * generating too much data if it can be aggregated. Other options could be to + * avoid the track subsystem and use a custom perfetto data source with + * respective changes in the trace processor. + * TODO: + * - The context shoud include information on address space + */ +class guest_context_tracker +{ + /* CPU tracks and fallback data */ + qemu_fallback_state cpu_state; + /* Currently active context data */ + std::shared_ptr ctx_state; + + public: + guest_context_tracker(int cpu_id); + void context_update(cpu_log_entry_handle, + const log_event_ctx_update_t *evt); + void mode_update(cpu_log_entry_handle entry, + perfetto::protos::pbzero::QEMULogEntryModeSwitch new_mode); + void flush_all_ctx_data(uint64_t pc); + qemu_fallback_state *get_cpu_state(); + qemu_tracker_state *get_ctx_state(); +}; + +} // namespace cheri diff --git a/trace_extra/memory_interceptor.cc b/trace_extra/memory_interceptor.cc new file mode 100644 index 00000000000..f948d87d136 --- /dev/null +++ b/trace_extra/memory_interceptor.cc @@ -0,0 +1,96 @@ +/*- + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2022 Mingle Chen + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under Defense Advanced Research Projects Agency (DARPA) + * Contract No. HR001122C0110 ("ETC"). + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +#include "trace_extra/memory_interceptor.hh" + +DynamorioTraceInterceptor::ThreadLocalState::ThreadLocalState( + ThreadLocalStateArgs &) +{ +} + +io::filtering_ostream DynamorioTraceInterceptor::mem_logfile; + +void DynamorioTraceInterceptor::OnTracePacket(InterceptorContext context) +{ + perfetto::protos::pbzero::TracePacket::Decoder packet( + context.packet_data.data, context.packet_data.size); + if (packet.has_track_event()) { + perfetto::protos::pbzero::TrackEvent::Decoder track_event( + packet.track_event()); + if (track_event.has_qemu()) { + perfetto::protos::pbzero::QEMUEventInfo::Decoder qemu( + track_event.qemu()); + // create trace_entry_t compatible with drcachesim + if (qemu.has_instr()) { + perfetto::protos::pbzero::QEMULogEntry::Decoder instr( + qemu.instr()); + if (instr.has_pc() && instr.has_opcode_obj()) { + perfetto::protos::pbzero::Opcode::Decoder opcode( + instr.opcode_obj()); + if (opcode.has_size()) { + trace_entry_t entry; + entry.type = TRACE_TYPE_INSTR; + entry.addr = reinterpret_cast(instr.pc()); + entry.size = opcode.size(); + mem_logfile.write((char *)(&entry), sizeof(entry)); + } + } + if (instr.has_mem()) { + for (auto iter = instr.mem(); iter; iter++) { + perfetto::protos::pbzero::QEMULogEntryMem::Decoder mem( + *iter); + trace_entry_t trace; + trace.addr = reinterpret_cast(mem.addr()); + trace.size = mem.size(); + switch (mem.op()) { + case perfetto::protos::pbzero:: + QEMULogEntryMem_MemOp_LOAD: + case perfetto::protos::pbzero:: + QEMULogEntryMem_MemOp_CLOAD: + trace.type = TRACE_TYPE_READ; + break; + case perfetto::protos::pbzero:: + QEMULogEntryMem_MemOp_STORE: + case perfetto::protos::pbzero:: + QEMULogEntryMem_MemOp_CSTORE: + trace.type = TRACE_TYPE_WRITE; + break; + default: + break; + } + mem_logfile.write((char *)&trace, sizeof(trace)); + } + } + } + } + } +} diff --git a/trace_extra/memory_interceptor.hh b/trace_extra/memory_interceptor.hh new file mode 100644 index 00000000000..b2f985d8e95 --- /dev/null +++ b/trace_extra/memory_interceptor.hh @@ -0,0 +1,68 @@ +/*- + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2022 Mingle Chen + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under Defense Advanced Research Projects Agency (DARPA) + * Contract No. HR001122C0110 ("ETC"). + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +#pragma once +#include +#include +#include "dynamorio/clients/drcachesim/common/trace_entry.h" +#include +#include + +using namespace std; +namespace io = boost::iostreams; + +class DynamorioTraceInterceptor + : public perfetto::Interceptor +{ + + public: + static io::filtering_ostream mem_logfile; + ~DynamorioTraceInterceptor() override = default; + + struct ThreadLocalState + : public perfetto::InterceptorBase::ThreadLocalState { + ThreadLocalState(ThreadLocalStateArgs &); + + ~ThreadLocalState() override = default; + }; + + // This function is called for each intercepted trace packet. |context| + // contains information about the trace packet as well as other state + // tracked by the interceptor (e.g., see ThreadLocalState). + // + // Intercepted trace data is provided in the form of serialized protobuf + // bytes, accessed through the |context.packet_data| field. + // + // Warning: this function can be called on any thread at any time. See + // below for how to safely access shared interceptor data from here. + static void OnTracePacket(InterceptorContext context); +}; diff --git a/trace_extra/meson.build b/trace_extra/meson.build new file mode 100644 index 00000000000..8f8dbbfb6b4 --- /dev/null +++ b/trace_extra/meson.build @@ -0,0 +1,37 @@ +fs = import('fs') + +qemutrace_ss = ss.source_set() + +if config_all.has_key('CONFIG_TCG_LOG_INSTR') and config_all.has_key('CONFIG_TRACE_PERFETTO') + qemutrace_ss.add(dependency('boost', modules: ['filesystem', 'system', 'iostreams'])) + qemutrace_ss.add(files('trace_perfetto.cc', 'guest_context_tracker.cc', 'trace_counters.cc', 'memory_interceptor.cc', + 'cheri-perfetto/sdk/perfetto.cc')) +endif + +qemutrace_ss = qemutrace_ss.apply(config_all, strict: false) +libqemutrace = static_library('qemutrace', + sources: qemutrace_ss.sources(), + dependencies: qemutrace_ss.dependencies(), + include_directories: ['cheri-perfetto/sdk'], + cpp_args: ['-DCONFIG_TCG_LOG_INSTR', + '-DQEMU_PERFETTO']) + +qemuutil_libs += libqemutrace + +if config_all.has_key('CONFIG_TCG_LOG_INSTR') and config_all.has_key('CONFIG_TRACE_PROTOBUF') + proc_protoc = find_program('protoc') + proto_path = meson.current_source_dir() / 'cheri-perfetto/protos/perfetto/trace/track_event' + protobuf_backend_files = files(proto_path / 'qemu_log_entry.proto') + output_files = [] + foreach f : protobuf_backend_files + fpath = '@0@'.format(f) + output_files += fs.replace_suffix(fs.name(fpath), '.pb-c.c') + output_files += fs.replace_suffix(fs.name(fpath), '.pb-c.h') + endforeach + gen_protos = custom_target('protobuf_backend_protos', + input: protobuf_backend_files, + output: output_files, + command: [proc_protoc, '--proto_path=@0@'.format(proto_path), '--c_out=@OUTDIR@', '@INPUT@'], + depend_files: protobuf_backend_files) + specific_ss.add(gen_protos) +endif diff --git a/trace_extra/qemu_perfetto.h b/trace_extra/qemu_perfetto.h new file mode 100644 index 00000000000..96bd80f5a13 --- /dev/null +++ b/trace_extra/qemu_perfetto.h @@ -0,0 +1,46 @@ +/* + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +#ifndef TRACE_PERFETTO_H +#define TRACE_PERFETTO_H + +#ifdef __cplusplus +extern "C" { +#endif + +bool perfetto_init(int cpu_id, void **backend_data); + +#ifdef __cplusplus +} /* extern C */ +#endif + +#endif /* TRACE_PERFETTO_H */ diff --git a/trace_extra/trace_counters.cc b/trace_extra/trace_counters.cc new file mode 100644 index 00000000000..4bcd00e5c47 --- /dev/null +++ b/trace_extra/trace_counters.cc @@ -0,0 +1,166 @@ +/*- + * Copyright (c) 2022 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#include "trace_extra/trace_counters.hh" +#include "trace_extra/guest_context_tracker.hh" + +namespace cheri +{ + +namespace +{ +/* + * Global counter state. + */ +qemu_counters_state global_counters; + +} // namespace + +qemu_counter_track::qemu_counter_track(uint64_t uuid_, qemu_counter_id id, + perfetto::Track parent) + : perfetto::Track(uuid_, parent), name(std::get<0>(id)), + slot(std::get<1>(id)) +{ +} + +perfetto::protos::gen::TrackDescriptor qemu_counter_track::Serialize() const +{ + auto desc = Track::Serialize(); + /* TODO process custom trace descriptor in trace processor */ + desc.set_name(name + ":" + std::to_string(slot)); + auto *counter_desc = desc.mutable_counter(); + /* TODO fill counter descriptor with optional data */ + return desc; +} + +void qemu_counter_track::Serialize( + perfetto::protos::pbzero::TrackDescriptor *desc) const +{ + auto bytes = Serialize().SerializeAsString(); + desc->AppendRawProtoBytes(bytes.data(), bytes.size()); +} + +qemu_counter::qemu_counter(qemu_counter_id id, int64_t reset, + perfetto::Track parent) + : track(gen_track_uuid(), id, parent), value(reset) +{ + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); +} + +qemu_counter::~qemu_counter() +{ + perfetto::TrackEvent::EraseTrackDescriptor(track); +} + +void qemu_counter::emit(int64_t sample) const +{ + PERFETTO_INTERNAL_TRACK_EVENT( + "counter", /*name=*/nullptr, + perfetto::protos::pbzero::TrackEvent::TYPE_COUNTER, track, + [&](perfetto::EventContext ctx) { + auto *event = ctx.event(); + event->set_counter_value(value); + }); +} + +bool qemu_counters_state::try_set(qemu_counter_id id, int64_t value) +{ + std::shared_lock lock(mutex); + auto it = counters.find(id); + if (it != counters.end()) { + it->second->value = value; + it->second->emit(value); + return false; + } + return true; +} + +boost::optional qemu_counters_state::try_fetch_add(qemu_counter_id id, + int64_t value) +{ + std::shared_lock lock(mutex); + auto it = counters.find(id); + if (it != counters.end()) { + value = it->second->value.fetch_add(value); + it->second->emit(value); + return value; + } + return boost::none; +} + +void qemu_counters_state::set(qemu_counter_id id, int64_t value) +{ + if (try_set(id, value)) { + /* Upgrade lock for insert */ + std::unique_lock lock(mutex); + auto it = counters.find(id); + if (it == counters.end()) { + auto counter = + std::make_unique(id, value, parent_track); + auto emplaced = counters.emplace(id, std::move(counter)); + it = emplaced.first; + } else { + it->second->value = value; + } + it->second->emit(value); + } +} + +int64_t qemu_counters_state::inc(qemu_counter_id id, int64_t value) +{ + auto result = try_fetch_add(id, value); + if (!result) { + /* Upgrade lock for insert */ + std::unique_lock lock(mutex); + auto it = counters.find(id); + if (it == counters.end()) { + auto counter = + std::make_unique(id, value, parent_track); + auto emplaced = counters.emplace(id, std::move(counter)); + it = emplaced.first; + } else { + value = it->second->value.fetch_add(value); + } + it->second->emit(value); + return value; + } + return result.value(); +} + +void global_counter_inc_emit(qemu_counter_id id, int64_t value) +{ + global_counters.inc(id, value); +} + +void global_counter_set_emit(qemu_counter_id id, int64_t value) +{ + global_counters.set(id, value); +} + +} // namespace cheri diff --git a/trace_extra/trace_counters.hh b/trace_extra/trace_counters.hh new file mode 100644 index 00000000000..50d9a27ac9a --- /dev/null +++ b/trace_extra/trace_counters.hh @@ -0,0 +1,116 @@ +/*- + * Copyright (c) 2022 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#pragma once + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "trace_extra/tuple_index.hh" + +namespace cheri +{ + +/* (counter_name, counter_slot) */ +using qemu_counter_id = std::tuple; + +/* + * Custom track representing a dynamically allocated counter. + * This is very similar to perfetto::CounterTrack but sadly it can not + * be subclassed cleanly, does not support dynamic naming and does not yet + * support incremental counters. + */ +class qemu_counter_track : public perfetto::Track +{ + const std::string name; + const unsigned int slot; + + public: + void Serialize(perfetto::protos::pbzero::TrackDescriptor *) const; + perfetto::protos::gen::TrackDescriptor Serialize() const; + qemu_counter_track(uint64_t uuid_, qemu_counter_id id, + perfetto::Track parent); +}; + +struct qemu_counter { + qemu_counter_track track; + std::atomic value; + + void emit(int64_t sample) const; + qemu_counter(qemu_counter_id id, int64_t reset, perfetto::Track parent); + qemu_counter(const qemu_counter &other) = delete; + ~qemu_counter(); +}; + +/* + * Manage blocks of named counters. + * This can be reused at multiple levels: there is a global set of counters + * for events that are common to the system, a per-cpu set of counters that + * emit on the CPU tracks and a per-context set of counters that are context + * switched by the context manager and emit on the per-context counter tracks. + */ +class qemu_counters_state +{ + /* + * The lock only protects find, insert, remove. Value updates are done + * with atomics, so we do not need to get an exclusive lock to update + * counter values. + */ + perfetto::Track parent_track; + std::shared_timed_mutex mutex; + std::unordered_map, + tuple_hasher> + counters; + + bool try_set(qemu_counter_id id, int64_t value); + boost::optional try_fetch_add(qemu_counter_id id, int64_t value); + + public: + qemu_counters_state() : parent_track(perfetto::Track()) {} + qemu_counters_state(perfetto::Track track) : parent_track(track) {} + + /* Set counter value or create new counter, emit the counter value */ + void set(qemu_counter_id id, int64_t value); + /* Increment counter value or create new counter, emit the counter value */ + int64_t inc(qemu_counter_id id, int64_t value); +}; + +/* Increment counter and emit value to trace, for incremental counter handling + */ +void global_counter_inc_emit(qemu_counter_id id, int64_t value); +/* Set counter value and emit, for absolute counter handling */ +void global_counter_set_emit(qemu_counter_id id, int64_t value); + +} // namespace cheri diff --git a/trace_extra/trace_perfetto.cc b/trace_extra/trace_perfetto.cc new file mode 100644 index 00000000000..3caf0fcab49 --- /dev/null +++ b/trace_extra/trace_perfetto.cc @@ -0,0 +1,566 @@ +/*- + * SPDX-License-Identifier: BSD-2-Clause + * + * Copyright (c) 2021 Alfredo Mazzinghi + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +/* + * QEMU instruction logging bridge to the perfetto framework. + */ +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +// #include "qemu/cpu-defs.h" +#include "qemu/log_instr.h" +#include "exec/log_instr_internal.h" +#include "exec/log_instr_perfetto.h" +#include "trace_extra/trace_counters.hh" +#include "trace_extra/guest_context_tracker.hh" + +#include "trace_extra/memory_interceptor.hh" + +PERFETTO_TRACK_EVENT_STATIC_STORAGE(); + +namespace fs = boost::filesystem; + +namespace +{ +using namespace cheri; + +/* Tracing session pointer */ +std::unique_ptr session; + +/* perfetto logfile */ +fs::path logfile("qemu_trace.pb"); + +/* perfetto interceptor trace file */ +string mem_logfile_name = "mem_access.trace.gz"; + +/* enable perfetto interceptor */ +bool enable_interceptor = false; + +/* category strings */ +std::vector categories; + +/* Global scheduling event track */ +std::unique_ptr sched_track; + +/* MO_SIZE from MemOp in /include/exec/memop.h */ +constexpr int MO_SIZE = 3; + +/* + * Private per-CPU state. + */ +struct perfetto_backend_data { + // Per-CPU control track. This records tracing control events. + perfetto::Track ctrl_track; + // Tracker that resolves the current context scheduled on a CPU + cheri::guest_context_tracker ctx_tracker; + /* + * Cached copy of the logging activation status. + * It is easier to keep a cached copy here than exposing the loglevel_active + * flag to the C++ interface. + */ + bool loglevel_active; + + perfetto_backend_data(int cpu_id) + : ctrl_track(perfetto::Track::Global(cheri::gen_track_uuid())), + ctx_tracker(cpu_id) + + { + std::string track_name("CPU " + std::to_string(cpu_id) + " ctrl"); + + auto desc = ctrl_track.Serialize(); + desc.set_name(track_name); + perfetto::TrackEvent::SetTrackDescriptor(ctrl_track, desc); + } +}; +/* + * Initialize perfetto tracing. + * + * Create the following data sources for qemu events: + * - Track events data source + * * XXX-AM: should use in process on UNIX only + * Should allow flags/options to control backend type, buffer sizes and + * other things + */ +bool perfetto_start_tracing(void) +{ + + perfetto::TracingInitArgs args; + perfetto::TraceConfig cfg; + perfetto::protos::gen::TrackEventConfig track_cfg; + + args.backends |= perfetto::kInProcessBackend; + + perfetto::Tracing::Initialize(args); + perfetto::TrackEvent::Register(); + + if (enable_interceptor) { + DynamorioTraceInterceptor::mem_logfile.push(io::gzip_compressor()); + DynamorioTraceInterceptor::mem_logfile.push( + io::file_descriptor_sink(mem_logfile_name)); + + // drcachesim needs a header in the file, so we create it here + trace_entry_t header{ .type = TRACE_TYPE_HEADER, + .size = 0, + .addr = TRACE_ENTRY_VERSION }; + DynamorioTraceInterceptor::mem_logfile.write((char *)&header, + sizeof(header)); + + // dub thread and pid as we only have one process one thread for now + trace_entry_t thread{ .type = TRACE_TYPE_THREAD, .size = 4, .addr = 1 }; + trace_entry_t pid{ .type = TRACE_TYPE_PID, .size = 4, .addr = 1 }; + + // dub timestamp and cpuid + trace_entry_t timestamp{ .type = TRACE_TYPE_MARKER, + .size = TRACE_MARKER_TYPE_TIMESTAMP, + .addr = 0 }; + trace_entry_t cpuid{ .type = TRACE_TYPE_MARKER, + .size = TRACE_MARKER_TYPE_CPU_ID, + .addr = 0 }; + + DynamorioTraceInterceptor::mem_logfile.write((char *)&thread, + sizeof(thread)); + DynamorioTraceInterceptor::mem_logfile.write((char *)&pid, sizeof(pid)); + DynamorioTraceInterceptor::mem_logfile.write((char *)×tamp, + sizeof(timestamp)); + DynamorioTraceInterceptor::mem_logfile.write((char *)&cpuid, + sizeof(cpuid)); + + perfetto::InterceptorDescriptor interceptor_desc; + interceptor_desc.set_name("console"); + DynamorioTraceInterceptor::Register(interceptor_desc); + } + + cfg.add_buffers()->set_size_kb(1 << 19); // 512MiB + cfg.set_flush_period_ms(5000); + cfg.set_file_write_period_ms(1000); + fs::remove(logfile); + cfg.set_write_into_file(true); + cfg.set_output_path(logfile.string()); + auto *ds_cfg = cfg.add_data_sources()->mutable_config(); + ds_cfg->set_name("track_event"); + track_cfg.add_disabled_categories("*"); + for (auto &category : categories) { + track_cfg.add_enabled_categories(category); + } + ds_cfg->set_track_event_config_raw(track_cfg.SerializeAsString()); + if (enable_interceptor) { + // redirect to interceptor + ds_cfg->mutable_interceptor_config()->set_name("console"); + } + + auto *producer_cfg = cfg.add_producers(); + producer_cfg->set_producer_name("qemu-tcg"); + producer_cfg->set_shm_size_kb(1 << 15); // 32MiB (the current max allowed) + + session = perfetto::Tracing::NewTrace(); + + session->Setup(cfg); + session->StartBlocking(); + + /* + * XXX there something wrong with initialization as we still emit a QEMU + * process and thread tracks. Would be nice to avoid that. + */ + + perfetto::ProcessTrack qemu_proc = perfetto::ProcessTrack::Current(); + auto desc = qemu_proc.Serialize(); + desc.mutable_process()->set_process_name("qemu"); + perfetto::TrackEvent::SetTrackDescriptor(qemu_proc, desc); + + sched_track.reset(new perfetto::Track(cheri::gen_track_uuid())); + desc = sched_track->Serialize(); + desc.set_name("Scheduler ctrl"); + perfetto::TrackEvent::SetTrackDescriptor(*sched_track, desc); + return true; +} + +void perfetto_tracing_stop(void) +{ + // NOTE: This is not sufficient for flushing the buffers, we currently + // also need to call the buffer sync function for each CPU on the exit path. + session->FlushBlocking(); + session->StopBlocking(); + if (enable_interceptor) { + // add footer to tracing file + trace_entry_t footer; + footer.type = TRACE_TYPE_FOOTER; + footer.size = 0; + footer.addr = 0; + DynamorioTraceInterceptor::mem_logfile.write((char *)&footer, + sizeof(footer)); + io::close(DynamorioTraceInterceptor::mem_logfile); + } +} + +void trace_cap_register(perfetto::protos::pbzero::QEMULogEntryCapability *cap, + cap_register_handle chandle) +{ + cap->set_valid(perfetto_cap_tag(chandle)); + cap->set_sealed(perfetto_cap_sealed(chandle)); + cap->set_cap_base(perfetto_cap_base(chandle)); + cap->set_cap_length(perfetto_cap_length(chandle)); + cap->set_cap_cursor(perfetto_cap_cursor(chandle)); + cap->set_perms(perfetto_cap_perms(chandle)); + cap->set_otype(perfetto_cap_otype(chandle)); +} + +/* + * Handle tracing control event. Returns true if the event changes the trace + * enable state (i.e. start or stop). + */ +bool process_state_event(perfetto_backend_data *data, + cpu_log_entry_handle entry, log_event_t *evt) +{ + bool has_startstop_event = false; + auto *state = data->ctx_tracker.get_ctx_state(); + + switch (evt->state.next_state) { + case LOG_EVENT_STATE_FLUSH: + TRACE_EVENT_INSTANT("ctrl", "flush", data->ctrl_track); + data->ctx_tracker.flush_all_ctx_data(evt->state.pc); + perfetto::TrackEvent::Flush(); + break; + case LOG_EVENT_STATE_START: + state->bb_tracker->track_next(entry, evt->state.pc); + TRACE_EVENT_BEGIN("ctrl", "tracing", data->ctrl_track); + has_startstop_event = true; + break; + case LOG_EVENT_STATE_STOP: + state->bb_tracker->reset(evt->state.pc); + TRACE_EVENT_END("ctrl", data->ctrl_track); + has_startstop_event = true; + break; + default: + assert(false && "Invalid state event"); + } + return has_startstop_event; +} + +/* + * Handle context switch events + */ +void process_context_event(perfetto_backend_data *data, + cpu_log_entry_handle entry, log_event_t *evt) +{ + + /* Swap current context. */ + if (evt->ctx_update.op == LOG_EVENT_CTX_OP_SWITCH) { + data->ctx_tracker.context_update(entry, &evt->ctx_update); + } +} + +/* + * Handle trace markers. + * These are always emitted on the CPU tracks. + */ +void process_marker_event(perfetto_backend_data *data, log_event_t *evt) +{ + auto *cpu_state = data->ctx_tracker.get_cpu_state(); + + TRACE_EVENT_INSTANT("marker", "guest", *cpu_state->get_track(), + [&](perfetto::EventContext ctx) { + auto *qemu_arg = ctx.event()->set_qemu(); + qemu_arg->set_marker(evt->marker); + }); +} + +/* + * Handle counters. + */ +void process_counter_event(perfetto_backend_data *data, log_event_t *evt) +{ + qemu_counter_id cnt_id = std::make_tuple( + evt->counter.name, log_event_counter_slot(evt->counter.flags)); + if (log_event_counter_incremental(evt->counter.flags)) { + global_counter_inc_emit(cnt_id, evt->counter.value); + } else { + global_counter_set_emit(cnt_id, evt->counter.value); + } +} + +void process_events(perfetto_backend_data *data, cpu_log_entry_handle entry) +{ + int nevents = perfetto_log_entry_events(entry); + bool has_startstop_event = false; + + /* + * Note: LOG_EVENT_STATE events are emitted even when tracing is disabled. + * The rest of the events should only be emitted when tracing is active. + */ + for (int i = 0; i < nevents; i++) { + log_event_t *evt = perfetto_log_event(entry, i); + switch (evt->id) { + case LOG_EVENT_STATE: + has_startstop_event = process_state_event(data, entry, evt); + break; + case LOG_EVENT_CTX_UPDATE: + process_context_event(data, entry, evt); + break; + case LOG_EVENT_MARKER: + process_marker_event(data, evt); + break; + case LOG_EVENT_REGDUMP: + break; + case LOG_EVENT_COUNTER: + process_counter_event(data, evt); + break; + default: + assert(false && "Invalid event identifier"); + } + } + + if (perfetto_log_entry_flags(entry) & LI_FLAG_MODE_SWITCH) { + auto mode = cheri::qemu_cpu_mode_to_trace( + perfetto_log_entry_next_cpu_mode(entry)); + data->ctx_tracker.mode_update(entry, mode); + } + + /* + * If we have instruction data, we assume that tracing is enabled and run + * extra stats gathering to track the executed instruction PC in the stats + * histograms. This avoids having to keep a shadow copy of the tracing state + * in the backend. + */ + if (!has_startstop_event && + (perfetto_log_entry_flags(entry) & LI_FLAG_HAS_INSTR_DATA) != 0) { + auto *state = data->ctx_tracker.get_ctx_state(); + state->bb_tracker->track_next(entry); + } +} + +void process_instr(perfetto_backend_data *data, cpu_log_entry_handle entry) +{ + auto *state = data->ctx_tracker.get_ctx_state(); + + /* + * XXX-AM: instead of having one big instruction record, we may have + * different messages for optional parts of the instruction message, on the + * same track/category: e.g. mode swtich, interrupt information and modified + * registers? + */ + TRACE_EVENT_INSTANT( + "instructions", "stream", *state->get_track(), + [&](perfetto::EventContext ctx) { + auto *qemu_arg = ctx.event()->set_qemu(); + auto *instr = qemu_arg->set_instr(); + auto flags = perfetto_log_entry_flags(entry); + + /* + * Populate protobuf from internal qemu structure. + * XXX-AM: It would be very nice if we could somehow skip this step + * and have the qemu internal representation be protobuf-based, so + * that here we only have to embed the qemu-specific packet + * into the track_event. Ideally this would save us all this copying + * around of the event data but I have no clue about the + * implications for the stability of the C/C++ protobuf-generated + * structures or whether we can embed the qemu portion of the packet + * already in the serialized wire-format (which should be stable by + * design). This can probably be done via + * protozero::Message::AppendScatteredBytes(). + */ + assert(flags & LI_FLAG_HAS_INSTR_DATA); + const char *bytes = perfetto_log_entry_insn_bytes(entry); + int size = perfetto_log_entry_insn_size(entry); + int nitems; + + /* Due to perfetto limitations, use the opcode message for now */ +#ifdef NOTYET + instr->set_opcode((const uint8_t *)bytes, size); +#else + if (size <= sizeof(uint64_t)) { + uint64_t value; + memcpy(&value, bytes, size); + auto *opcode = instr->set_opcode_obj(); + opcode->set_value(value); + opcode->set_size(size); + } else { + // Throw an error or something + assert(false && "Not reached"); + } +#endif + + instr->set_pc(perfetto_log_entry_pc(entry)); + + nitems = perfetto_log_entry_regs(entry); + for (int i = 0; i < nitems; i++) { + auto flags = perfetto_reg_info_flags(entry, i); + auto *reginfo = instr->add_reg(); + reginfo->set_name(perfetto_reg_info_name(entry, i)); + if ((flags & LRI_CAP_REG) && (flags & LRI_HOLDS_CAP)) { + cap_register_handle cap_handle = + perfetto_reg_info_cap(entry, i); + auto *capinfo = reginfo->set_cap_value(); + trace_cap_register(capinfo, cap_handle); + } else { + reginfo->set_int_value(perfetto_reg_info_gpr(entry, i)); + } + } + nitems = perfetto_log_entry_mem(entry); + for (int i = 0; i < nitems; i++) { + auto flags = perfetto_mem_info_flags(entry, i); + auto *meminfo = instr->add_mem(); + meminfo->set_addr(perfetto_mem_info_addr(entry, i)); + + switch (flags) { + case LMI_LD: + meminfo->set_op( + perfetto::protos::pbzero::QEMULogEntryMem::LOAD); + break; + case LMI_LD | LMI_CAP: + meminfo->set_op( + perfetto::protos::pbzero::QEMULogEntryMem::CLOAD); + break; + case LMI_ST: + meminfo->set_op( + perfetto::protos::pbzero::QEMULogEntryMem::STORE); + break; + case LMI_ST | LMI_CAP: + meminfo->set_op( + perfetto::protos::pbzero::QEMULogEntryMem::CSTORE); + break; + default: + assert(false && "Invalid meminfo flag"); + } + if (flags & LMI_CAP) { + auto *capinfo = meminfo->set_cap_value(); + cap_register_handle cap_handle = + perfetto_reg_info_cap(entry, i); + trace_cap_register(capinfo, cap_handle); + // set cap size + meminfo->set_size(perfetto_target_cap_size()); + } else { + meminfo->set_int_value(perfetto_mem_info_value(entry, i)); + meminfo->set_size( + 1 << (perfetto_mem_info_op(entry, i) & MO_SIZE)); + } + } + + if (flags & LI_FLAG_INTR_MASK) { + // interrupt + auto *exc = instr->set_exception(); + if (flags & LI_FLAG_INTR_TRAP) + exc->set_type( + perfetto::protos::pbzero::QEMULogEntryExcType::TRAP); + else { + exc->set_type( + perfetto::protos::pbzero::QEMULogEntryExcType::INTR); + } + exc->set_code(perfetto_log_entry_intr_code(entry)); + } + if (flags & LI_FLAG_MODE_SWITCH) { + auto mode = cheri::qemu_cpu_mode_to_trace( + perfetto_log_entry_next_cpu_mode(entry)); + instr->set_mode_code(mode); + } + }); +} + +} // namespace + +extern "C" void +qemu_log_instr_perfetto_conf_categories(const char *category_str) +{ + std::string strspec(category_str); + int pos; + + while ((pos = strspec.find(',', 0)) != std::string::npos) { + categories.push_back(strspec.substr(0, pos)); + strspec = strspec.substr(pos + 1); + } + if (strspec.size()) + categories.push_back(strspec); +} + +extern "C" void qemu_log_instr_perfetto_interceptor_logfile(const char *name) +{ + mem_logfile_name = name; +} + +extern "C" void qemu_log_instr_perfetto_enable_interceptor() +{ + enable_interceptor = true; +} +/* + * Initialize perfetto tracing. + * + * Start tracing thread when first called. + */ +extern "C" void perfetto_init_cpu(int cpu_index, const char *logfile_path, + void **backend_data) +{ + static std::once_flag init_flag; + + std::call_once(init_flag, [&]() { + logfile = logfile_path; + atexit(perfetto_tracing_stop); + perfetto_start_tracing(); + }); + + // XXX-AM: The backend data is currently missing a cleanup hook, so it + // leaks. This is not a big issue as it should be live until the qemu + // process terminates. + *backend_data = new perfetto_backend_data(cpu_index); +} + +/* + * This is required because of how perfetto TraceSession::Flush works, + * see comment on this method for more details. + * We need to flush the data source directly to see the last packet. + */ +extern "C" void perfetto_sync_cpu(void *backend_data) +{ + perfetto::TrackEvent::Flush(); +} + +extern "C" void perfetto_emit_instr(void *backend_data, + cpu_log_entry_handle entry) +{ + auto *data = reinterpret_cast(backend_data); + auto flags = perfetto_log_entry_flags(entry); + + /* Process events first to react to START/STOP tracing events if needed */ + process_events(data, entry); + if (flags & LI_FLAG_HAS_INSTR_DATA) { + process_instr(data, entry); + } +} diff --git a/trace_extra/tuple_index.hh b/trace_extra/tuple_index.hh new file mode 100644 index 00000000000..07e5b40bfb2 --- /dev/null +++ b/trace_extra/tuple_index.hh @@ -0,0 +1,55 @@ +/*- + * Copyright (c) 2021 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#pragma once + +#include +#include +#include +#include + +namespace cheri +{ +template struct is_tuple_impl : std::false_type { +}; +template +struct is_tuple_impl> : std::true_type { +}; +template struct is_tuple : is_tuple_impl> { +}; + +template struct tuple_hasher; + +template +struct tuple_hasher::value>::type> { + std::size_t operator()(const T &tuple) const + { + return boost::hash_value(tuple); + } +}; +} // namespace cheri diff --git a/util/fdmon-io_uring.c b/util/fdmon-io_uring.c index 1461dfa4074..cb3e057b2f5 100644 --- a/util/fdmon-io_uring.c +++ b/util/fdmon-io_uring.c @@ -179,7 +179,7 @@ static void add_poll_remove_sqe(AioContext *ctx, AioHandler *node) { struct io_uring_sqe *sqe = get_sqe(ctx); - io_uring_prep_poll_remove(sqe, node); + io_uring_prep_poll_remove(sqe, (uintptr_t)node); } /* Add a timeout that self-cancels when another cqe becomes ready */ diff --git a/util/log.c b/util/log.c index 9705a2570a9..101c9f2f97e 100644 --- a/util/log.c +++ b/util/log.c @@ -35,6 +35,25 @@ int qemu_loglevel; static int log_append = 0; GArray *debug_regions; +#ifdef CONFIG_TCG_LOG_INSTR +__attribute__((weak)) int qemu_log_instr_global_switch(int log_flags); +__attribute__((weak)) int qemu_log_instr_global_switch(int log_flags) +{ + /* Real implementation in accel/tcg/log_instr.c. */ + warn_report("Calling no-op %s\r", __func__); + return log_flags; +} + +__attribute__((weak)) void qemu_log_instr_add_startup_filter( + cpu_log_instr_filter_t); +__attribute__((weak)) +void qemu_log_instr_add_startup_filter(cpu_log_instr_filter_t f) +{ + /* Real implementation in accel/tcg/log_instr.c */ + warn_report("Calling no-op %s\r", __func__); +} +#endif + /* Return the number of characters emitted. */ int qemu_log(const char *fmt, ...) { @@ -75,13 +94,6 @@ static void qemu_logfile_free(QemuLogFile *logfile) static bool log_uses_own_buffers; -__attribute__((weak)) int qemu_log_instr_global_switch(int log_flags); -__attribute__((weak)) int qemu_log_instr_global_switch(int log_flags) -{ - /* Real implementation in accel/tcg/log_instr.c. */ - return log_flags; -} - /* enable or disable low levels log */ void qemu_set_log_internal(int log_flags) { @@ -286,6 +298,9 @@ void qemu_set_dfilter_ranges(const char *filter_spec, Error **errp) } out: g_strfreev(ranges); +#ifdef CONFIG_TCG_LOG_INSTR + qemu_log_instr_add_startup_filter(LOG_INSTR_FILTER_MEM_RANGE); +#endif } /* fflush() the log file */