| 1 | /* |
| 2 | * Copyright (C) 2021, Alexandre Iooss <erdnaxe@crans.org> |
| 3 | * |
| 4 | * Log instruction execution with memory access and register changes |
| 5 | * |
| 6 | * License: GNU GPL, version 2 or later. |
| 7 | * See the COPYING file in the top-level directory. |
| 8 | */ |
| 9 | #include <glib.h> |
| 10 | #include <inttypes.h> |
| 11 | #include <stdio.h> |
| 12 | #include <stdlib.h> |
| 13 | #include <string.h> |
| 14 | #include <unistd.h> |
| 15 | |
| 16 | #include <qemu-plugin.h> |
| 17 | |
| 18 | typedef struct { |
| 19 | struct qemu_plugin_register *handle; |
| 20 | GByteArray *last; |
| 21 | GByteArray *new; |
| 22 | const char *name; |
| 23 | } Register; |
| 24 | |
| 25 | typedef struct CPU { |
| 26 | /* Store last executed instruction on each vCPU as a GString */ |
| 27 | GString *last_exec; |
| 28 | /* Ptr array of Register */ |
| 29 | GPtrArray *registers; |
| 30 | } CPU; |
| 31 | |
| 32 | QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION; |
| 33 | |
| 34 | /* |
| 35 | * Per-vCPU state stored in a qemu_plugin_scoreboard. The scoreboard manages |
| 36 | * per-vCPU storage automatically, eliminating the need for manual array |
| 37 | * growth, locks, or pointer-stability workarounds. |
| 38 | */ |
| 39 | static struct qemu_plugin_scoreboard *cpus; |
| 40 | |
| 41 | static GPtrArray *imatches; |
| 42 | static GArray *amatches; |
| 43 | static GPtrArray *rmatches; |
| 44 | static bool disas_assist; |
| 45 | static GMutex add_reg_name_lock; |
| 46 | static GPtrArray *all_reg_names; |
| 47 | |
| 48 | /** |
| 49 | * Add memory read or write information to current instruction log |
| 50 | */ |
| 51 | static void vcpu_mem(unsigned int cpu_index, qemu_plugin_meminfo_t info, |
| 52 | uint64_t vaddr, void *udata) |
| 53 | { |
| 54 | CPU *c = qemu_plugin_scoreboard_find(cpus, cpu_index); |
| 55 | GString *s = c->last_exec; |
| 56 | |
| 57 | /* Find vCPU in array */ |
| 58 | |
| 59 | /* Indicate type of memory access */ |
| 60 | if (qemu_plugin_mem_is_store(info)) { |
| 61 | g_string_append(s, ", store"); |
| 62 | } else { |
| 63 | g_string_append(s, ", load"); |
| 64 | } |
| 65 | |
| 66 | /* If full system emulation log physical address and device name */ |
| 67 | struct qemu_plugin_hwaddr *hwaddr = qemu_plugin_get_hwaddr(info, vaddr); |
| 68 | if (hwaddr) { |
| 69 | uint64_t addr = qemu_plugin_hwaddr_phys_addr(hwaddr); |
| 70 | const char *name = qemu_plugin_hwaddr_device_name(hwaddr); |
| 71 | g_string_append_printf(s, ", 0x%08"PRIx64", %s", addr, name); |
| 72 | } else { |
| 73 | g_string_append_printf(s, ", 0x%08"PRIx64, vaddr); |
| 74 | } |
| 75 | } |
| 76 | |
| 77 | /** |
| 78 | * Log instruction execution, outputting the last one. |
| 79 | * |
| 80 | * vcpu_insn_exec() is a copy and paste of vcpu_insn_exec_with_regs() |
| 81 | * without the checking of register values when we've attempted to |
| 82 | * optimise with disas_assist. |
| 83 | */ |
| 84 | static void insn_check_regs(CPU *cpu) |
| 85 | { |
| 86 | for (int n = 0; n < cpu->registers->len; n++) { |
| 87 | Register *reg = cpu->registers->pdata[n]; |
| 88 | bool success = false; |
| 89 | int sz = 0; |
| 90 | |
| 91 | g_byte_array_set_size(reg->new, 0); |
| 92 | success = qemu_plugin_read_register(reg->handle, reg->new); |
| 93 | g_assert(success); |
| 94 | sz = reg->new->len; |
| 95 | g_assert(sz == reg->last->len); |
| 96 | |
| 97 | if (memcmp(reg->last->data, reg->new->data, sz)) { |
| 98 | GByteArray *temp = reg->last; |
| 99 | g_string_append_printf(cpu->last_exec, ", %s -> 0x", reg->name); |
| 100 | /* TODO: handle BE properly */ |
| 101 | for (int i = sz - 1; i >= 0; i--) { |
| 102 | g_string_append_printf(cpu->last_exec, "%02x", |
| 103 | reg->new->data[i]); |
| 104 | } |
| 105 | reg->last = reg->new; |
| 106 | reg->new = temp; |
| 107 | } |
| 108 | } |
| 109 | } |
| 110 | |
| 111 | /* Log last instruction while checking registers */ |
| 112 | static void vcpu_insn_exec_with_regs(unsigned int cpu_index, void *udata) |
| 113 | { |
| 114 | CPU *cpu = qemu_plugin_scoreboard_find(cpus, cpu_index); |
| 115 | |
| 116 | /* Print previous instruction in cache */ |
| 117 | if (cpu->last_exec->len) { |
| 118 | if (cpu->registers) { |
| 119 | insn_check_regs(cpu); |
| 120 | } |
| 121 | |
| 122 | g_string_append_c(cpu->last_exec, '\n'); |
| 123 | qemu_plugin_outs(cpu->last_exec->str); |
| 124 | } |
| 125 | |
| 126 | /* Store new instruction in cache */ |
| 127 | /* vcpu_mem will add memory access information to last_exec */ |
| 128 | g_string_printf(cpu->last_exec, "%u, ", cpu_index); |
| 129 | g_string_append(cpu->last_exec, (char *)udata); |
| 130 | } |
| 131 | |
| 132 | /* Log last instruction while checking registers, ignore next */ |
| 133 | static void vcpu_insn_exec_only_regs(unsigned int cpu_index, void *udata) |
| 134 | { |
| 135 | CPU *cpu = qemu_plugin_scoreboard_find(cpus, cpu_index); |
| 136 | |
| 137 | /* Print previous instruction in cache */ |
| 138 | if (cpu->last_exec->len) { |
| 139 | if (cpu->registers) { |
| 140 | insn_check_regs(cpu); |
| 141 | } |
| 142 | |
| 143 | g_string_append_c(cpu->last_exec, '\n'); |
| 144 | qemu_plugin_outs(cpu->last_exec->str); |
| 145 | } |
| 146 | |
| 147 | /* reset */ |
| 148 | cpu->last_exec->len = 0; |
| 149 | } |
| 150 | |
| 151 | /* Log last instruction without checking regs, setup next */ |
| 152 | static void vcpu_insn_exec(unsigned int cpu_index, void *udata) |
| 153 | { |
| 154 | CPU *cpu = qemu_plugin_scoreboard_find(cpus, cpu_index); |
| 155 | |
| 156 | /* Print previous instruction in cache */ |
| 157 | if (cpu->last_exec->len) { |
| 158 | g_string_append_c(cpu->last_exec, '\n'); |
| 159 | qemu_plugin_outs(cpu->last_exec->str); |
| 160 | } |
| 161 | |
| 162 | /* Store new instruction in cache */ |
| 163 | /* vcpu_mem will add memory access information to last_exec */ |
| 164 | g_string_printf(cpu->last_exec, "%u, ", cpu_index); |
| 165 | g_string_append(cpu->last_exec, (char *)udata); |
| 166 | } |
| 167 | |
| 168 | /** |
| 169 | * On translation block new translation |
| 170 | * |
| 171 | * QEMU convert code by translation block (TB). By hooking here we can then hook |
| 172 | * a callback on each instruction and memory access. |
| 173 | */ |
| 174 | static void vcpu_tb_trans(struct qemu_plugin_tb *tb, void *userdata) |
| 175 | { |
| 176 | struct qemu_plugin_insn *insn; |
| 177 | bool skip = (imatches || amatches); |
| 178 | bool check_regs_this = rmatches; |
| 179 | bool check_regs_next = false; |
| 180 | |
| 181 | size_t n_insns = qemu_plugin_tb_n_insns(tb); |
| 182 | for (size_t i = 0; i < n_insns; i++) { |
| 183 | char *insn_disas; |
| 184 | uint64_t insn_vaddr; |
| 185 | |
| 186 | /* |
| 187 | * `insn` is shared between translations in QEMU, copy needed data here. |
| 188 | * `output` is never freed as it might be used multiple times during |
| 189 | * the emulation lifetime. |
| 190 | * We only consider the first 32 bits of the instruction, this may be |
| 191 | * a limitation for CISC architectures. |
| 192 | */ |
| 193 | insn = qemu_plugin_tb_get_insn(tb, i); |
| 194 | insn_disas = qemu_plugin_insn_disas(insn); |
| 195 | insn_vaddr = qemu_plugin_insn_vaddr(insn); |
| 196 | |
| 197 | /* |
| 198 | * If we are filtering we better check out if we have any |
| 199 | * hits. The skip "latches" so we can track memory accesses |
| 200 | * after the instruction we care about. Also enable register |
| 201 | * checking on the next instruction. |
| 202 | */ |
| 203 | if (skip && imatches) { |
| 204 | int j; |
| 205 | for (j = 0; j < imatches->len && skip; j++) { |
| 206 | char *m = g_ptr_array_index(imatches, j); |
| 207 | if (g_str_has_prefix(insn_disas, m)) { |
| 208 | skip = false; |
| 209 | check_regs_next = rmatches; |
| 210 | } |
| 211 | } |
| 212 | } |
| 213 | |
| 214 | if (skip && amatches) { |
| 215 | int j; |
| 216 | for (j = 0; j < amatches->len && skip; j++) { |
| 217 | uint64_t v = g_array_index(amatches, uint64_t, j); |
| 218 | if (v == insn_vaddr) { |
| 219 | skip = false; |
| 220 | } |
| 221 | } |
| 222 | } |
| 223 | |
| 224 | /* |
| 225 | * Check the disassembly to see if a register we care about |
| 226 | * will be affected by this instruction. This relies on the |
| 227 | * dissembler doing something sensible for the registers we |
| 228 | * care about. |
| 229 | */ |
| 230 | if (disas_assist && rmatches) { |
| 231 | check_regs_next = false; |
| 232 | g_auto(GStrv) args = g_strsplit_set(insn_disas, " \t", 2); |
| 233 | if (args && args[1]) { |
| 234 | for (int n = 0; n < all_reg_names->len; n++) { |
| 235 | const gchar *reg = g_ptr_array_index(all_reg_names, n); |
| 236 | if (g_strrstr(args[1], reg)) { |
| 237 | check_regs_next = true; |
| 238 | skip = false; |
| 239 | break; |
| 240 | } |
| 241 | } |
| 242 | } |
| 243 | } |
| 244 | |
| 245 | /* |
| 246 | * We now have 3 choices: |
| 247 | * |
| 248 | * - Log insn |
| 249 | * - Log insn while checking registers |
| 250 | * - Don't log this insn but check if last insn changed registers |
| 251 | */ |
| 252 | |
| 253 | if (skip) { |
| 254 | if (check_regs_this) { |
| 255 | qemu_plugin_register_vcpu_insn_exec_cb(insn, |
| 256 | vcpu_insn_exec_only_regs, |
| 257 | QEMU_PLUGIN_CB_R_REGS, |
| 258 | NULL); |
| 259 | } |
| 260 | } else { |
| 261 | uint32_t insn_opcode = 0; |
| 262 | qemu_plugin_insn_data(insn, &insn_opcode, sizeof(insn_opcode)); |
| 263 | |
| 264 | char *output = g_strdup_printf("0x%"PRIx64", 0x%"PRIx32", \"%s\"", |
| 265 | insn_vaddr, insn_opcode, insn_disas); |
| 266 | |
| 267 | /* Register callback on memory read or write */ |
| 268 | qemu_plugin_register_vcpu_mem_cb(insn, vcpu_mem, |
| 269 | QEMU_PLUGIN_CB_NO_REGS, |
| 270 | QEMU_PLUGIN_MEM_RW, NULL); |
| 271 | |
| 272 | /* Register callback on instruction */ |
| 273 | if (check_regs_this) { |
| 274 | qemu_plugin_register_vcpu_insn_exec_cb( |
| 275 | insn, vcpu_insn_exec_with_regs, |
| 276 | QEMU_PLUGIN_CB_R_REGS, |
| 277 | output); |
| 278 | } else { |
| 279 | qemu_plugin_register_vcpu_insn_exec_cb( |
| 280 | insn, vcpu_insn_exec, |
| 281 | QEMU_PLUGIN_CB_NO_REGS, |
| 282 | output); |
| 283 | } |
| 284 | |
| 285 | /* reset skip */ |
| 286 | skip = (imatches || amatches); |
| 287 | } |
| 288 | |
| 289 | /* set regs for next */ |
| 290 | if (disas_assist && rmatches) { |
| 291 | check_regs_this = check_regs_next; |
| 292 | } |
| 293 | |
| 294 | g_free(insn_disas); |
| 295 | } |
| 296 | } |
| 297 | |
| 298 | static Register *init_vcpu_register(qemu_plugin_reg_descriptor *desc) |
| 299 | { |
| 300 | Register *reg = g_new0(Register, 1); |
| 301 | g_autofree gchar *lower = g_utf8_strdown(desc->name, -1); |
| 302 | bool success = false; |
| 303 | |
| 304 | reg->handle = desc->handle; |
| 305 | reg->name = g_intern_string(lower); |
| 306 | reg->last = g_byte_array_new(); |
| 307 | reg->new = g_byte_array_new(); |
| 308 | |
| 309 | /* read the initial value */ |
| 310 | success = qemu_plugin_read_register(reg->handle, reg->last); |
| 311 | g_assert(success); |
| 312 | return reg; |
| 313 | } |
| 314 | |
| 315 | /* |
| 316 | * g_pattern_match_string has been deprecated in Glib since 2.70 and |
| 317 | * will complain about it if you try to use it. Fortunately the |
| 318 | * signature of both functions is the same making it easy to work |
| 319 | * around. |
| 320 | */ |
| 321 | static inline |
| 322 | gboolean g_pattern_spec_match_string_qemu(GPatternSpec *pspec, |
| 323 | const gchar *string) |
| 324 | { |
| 325 | #if GLIB_CHECK_VERSION(2, 70, 0) |
| 326 | return g_pattern_spec_match_string(pspec, string); |
| 327 | #else |
| 328 | return g_pattern_match_string(pspec, string); |
| 329 | #endif |
| 330 | }; |
| 331 | #define g_pattern_spec_match_string(p, s) g_pattern_spec_match_string_qemu(p, s) |
| 332 | |
| 333 | static GPtrArray *registers_init(int vcpu_index) |
| 334 | { |
| 335 | g_autoptr(GPtrArray) registers = g_ptr_array_new(); |
| 336 | g_autoptr(GArray) reg_list = qemu_plugin_get_registers(); |
| 337 | |
| 338 | if (rmatches && reg_list->len) { |
| 339 | /* |
| 340 | * Go through each register in the complete list and |
| 341 | * see if we want to track it. |
| 342 | */ |
| 343 | for (int r = 0; r < reg_list->len; r++) { |
| 344 | qemu_plugin_reg_descriptor *rd = &g_array_index( |
| 345 | reg_list, qemu_plugin_reg_descriptor, r); |
| 346 | for (int p = 0; p < rmatches->len; p++) { |
| 347 | g_autoptr(GPatternSpec) pat = g_pattern_spec_new(rmatches->pdata[p]); |
| 348 | g_autofree gchar *rd_lower = g_utf8_strdown(rd->name, -1); |
| 349 | if (g_pattern_spec_match_string(pat, rd->name) || |
| 350 | g_pattern_spec_match_string(pat, rd_lower)) { |
| 351 | Register *reg = init_vcpu_register(rd); |
| 352 | g_ptr_array_add(registers, reg); |
| 353 | |
| 354 | /* we need a list of regnames at TB translation time */ |
| 355 | if (disas_assist) { |
| 356 | g_mutex_lock(&add_reg_name_lock); |
| 357 | if (!g_ptr_array_find(all_reg_names, reg->name, NULL)) { |
| 358 | g_ptr_array_add(all_reg_names, (gpointer)reg->name); |
| 359 | } |
| 360 | g_mutex_unlock(&add_reg_name_lock); |
| 361 | } |
| 362 | } |
| 363 | } |
| 364 | } |
| 365 | } |
| 366 | |
| 367 | return registers->len ? g_steal_pointer(®isters) : NULL; |
| 368 | } |
| 369 | |
| 370 | /* |
| 371 | * Initialise a new vcpu/thread with: |
| 372 | * - last_exec tracking data |
| 373 | * - list of tracked registers |
| 374 | * - initial value of registers |
| 375 | */ |
| 376 | static void vcpu_init(unsigned int vcpu_index, void *userdata) |
| 377 | { |
| 378 | CPU *c = qemu_plugin_scoreboard_find(cpus, vcpu_index); |
| 379 | c->last_exec = g_string_new(NULL); |
| 380 | c->registers = registers_init(vcpu_index); |
| 381 | } |
| 382 | |
| 383 | /** |
| 384 | * On vCPU exit, flush the last cached instruction for this vCPU. |
| 385 | * |
| 386 | * The one-instruction-delay pattern stores each instruction in last_exec and |
| 387 | * only prints it when the *next* callback fires. When a thread exits via |
| 388 | * syscall (e.g. ecall/exit), no subsequent callback fires for that vCPU and |
| 389 | * the final instruction is silently dropped. Flushing here guarantees it is |
| 390 | * written before the vCPU is torn down. |
| 391 | */ |
| 392 | static void vcpu_exit(unsigned int vcpu_index, void *udata) |
| 393 | { |
| 394 | CPU *c = qemu_plugin_scoreboard_find(cpus, vcpu_index); |
| 395 | if (c->last_exec && c->last_exec->len) { |
| 396 | g_string_append_c(c->last_exec, '\n'); |
| 397 | qemu_plugin_outs(c->last_exec->str); |
| 398 | g_string_truncate(c->last_exec, 0); |
| 399 | } |
| 400 | } |
| 401 | |
| 402 | /** |
| 403 | * On plugin exit, flush any remaining cached instructions and free state. |
| 404 | */ |
| 405 | static void plugin_exit(void *p) |
| 406 | { |
| 407 | int n = qemu_plugin_num_vcpus(); |
| 408 | for (int i = 0; i < n; i++) { |
| 409 | CPU *c = qemu_plugin_scoreboard_find(cpus, i); |
| 410 | if (c->last_exec && c->last_exec->len) { |
| 411 | g_string_append_c(c->last_exec, '\n'); |
| 412 | qemu_plugin_outs(c->last_exec->str); |
| 413 | } |
| 414 | } |
| 415 | qemu_plugin_scoreboard_free(cpus); |
| 416 | } |
| 417 | |
| 418 | /* Add a match to the array of matches */ |
| 419 | static void parse_insn_match(char *match) |
| 420 | { |
| 421 | if (!imatches) { |
| 422 | imatches = g_ptr_array_new(); |
| 423 | } |
| 424 | g_ptr_array_add(imatches, g_strdup(match)); |
| 425 | } |
| 426 | |
| 427 | static void parse_vaddr_match(char *match) |
| 428 | { |
| 429 | uint64_t v = g_ascii_strtoull(match, NULL, 16); |
| 430 | |
| 431 | if (!amatches) { |
| 432 | amatches = g_array_new(false, true, sizeof(uint64_t)); |
| 433 | } |
| 434 | g_array_append_val(amatches, v); |
| 435 | } |
| 436 | |
| 437 | /* |
| 438 | * We have to wait until vCPUs are started before we can check the |
| 439 | * patterns find anything. |
| 440 | */ |
| 441 | static void add_regpat(char *regpat) |
| 442 | { |
| 443 | if (!rmatches) { |
| 444 | rmatches = g_ptr_array_new(); |
| 445 | } |
| 446 | g_ptr_array_add(rmatches, g_strdup(regpat)); |
| 447 | } |
| 448 | |
| 449 | /** |
| 450 | * Install the plugin |
| 451 | */ |
| 452 | QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id, |
| 453 | const qemu_info_t *info, int argc, |
| 454 | char **argv) |
| 455 | { |
| 456 | /* Initialize scoreboard to cache per-vCPU instruction state. */ |
| 457 | cpus = qemu_plugin_scoreboard_new(sizeof(CPU)); |
| 458 | |
| 459 | for (int i = 0; i < argc; i++) { |
| 460 | char *opt = argv[i]; |
| 461 | g_auto(GStrv) tokens = g_strsplit(opt, "=", 2); |
| 462 | if (g_strcmp0(tokens[0], "ifilter") == 0) { |
| 463 | parse_insn_match(tokens[1]); |
| 464 | } else if (g_strcmp0(tokens[0], "afilter") == 0) { |
| 465 | parse_vaddr_match(tokens[1]); |
| 466 | } else if (g_strcmp0(tokens[0], "reg") == 0) { |
| 467 | add_regpat(tokens[1]); |
| 468 | } else if (g_strcmp0(tokens[0], "rdisas") == 0) { |
| 469 | if (!qemu_plugin_bool_parse(tokens[0], tokens[1], &disas_assist)) { |
| 470 | fprintf(stderr, "boolean argument parsing failed: %s\n", opt); |
| 471 | return -1; |
| 472 | } |
| 473 | all_reg_names = g_ptr_array_new(); |
| 474 | } else { |
| 475 | fprintf(stderr, "option parsing failed: %s\n", opt); |
| 476 | return -1; |
| 477 | } |
| 478 | } |
| 479 | |
| 480 | /* Register init, translation block and exit callbacks */ |
| 481 | qemu_plugin_register_vcpu_init_cb(id, vcpu_init, NULL); |
| 482 | qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans, NULL); |
| 483 | qemu_plugin_register_vcpu_exit_cb(id, vcpu_exit, NULL); |
| 484 | qemu_plugin_register_atexit_cb(id, plugin_exit, NULL); |
| 485 | |
| 486 | return 0; |
| 487 | } |