| Message ID | 36d316bf3e8b0aca778c5e8d1acde39a7f361946.1733063076.git.neither@nut.email (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | tcg-plugins: add hooks for discontinuities | expand |
On 12/2/24 11:41, Julian Ganz wrote: > We recently introduced plugin API for the registration of callbacks for > discontinuity events, specifically for interrupts, exceptions and host > call events. The callback receives, among other information, the VCPU > index and the PC after the event. This change introduces a test plugin > asserting that particular behaviour. > --- > tests/tcg/plugins/discons.c | 95 +++++++++++++++++++++++++++++++++++ > tests/tcg/plugins/meson.build | 2 +- > 2 files changed, 96 insertions(+), 1 deletion(-) > create mode 100644 tests/tcg/plugins/discons.c > > diff --git a/tests/tcg/plugins/discons.c b/tests/tcg/plugins/discons.c > new file mode 100644 > index 0000000000..54e52f563a > --- /dev/null > +++ b/tests/tcg/plugins/discons.c > @@ -0,0 +1,95 @@ > +/* > + * Copyright (C) 2024, Julian Ganz <neither@nut.email> > + * > + * License: GNU GPL, version 2 or later. > + * See the COPYING file in the top-level directory. > + */ Would be nice to include a description of the plugin here. > +#include <stdio.h> > + > +#include <qemu-plugin.h> > + > +QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION; > + > +struct cpu_state { > + uint64_t next_pc; > + bool has_next; > +}; > + > +static struct qemu_plugin_scoreboard *states; > + > +static bool abort_on_mismatch; > + > +static void vcpu_discon(qemu_plugin_id_t id, unsigned int vcpu_index, > + enum qemu_plugin_discon_type type, uint64_t from_pc, > + uint64_t to_pc) > +{ > + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); > + state->next_pc = to_pc; > + state->has_next = true; > +} > + > +static void insn_exec(unsigned int vcpu_index, void *userdata) > +{ > + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); > + uint64_t pc = (uint64_t) userdata; > + GString* report; > + > + if (state->has_next) { > + if (state->next_pc != pc) { > + report = g_string_new("Trap target PC mismatch\n"); > + g_string_append_printf(report, > + "Expected: %"PRIx64"\nEncountered: %" > + PRIx64"\n", > + state->next_pc, pc); > + qemu_plugin_outs(report->str); > + if (abort_on_mismatch) { > + g_abort(); > + } > + g_string_free(report, true); > + } > + state->has_next = false; > + } > +} When booting an arm64 vm, I get this message: Trap target PC mismatch Expected: 23faf3a80 Encountered: 23faf3a84 From what I understand, it means that the next_pc we have is incorrect. > + > +static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb) > +{ > + size_t i; > + size_t n_insns = qemu_plugin_tb_n_insns(tb); > + > + for (i = 0; i < n_insns; i++) { > + struct qemu_plugin_insn * insn = qemu_plugin_tb_get_insn(tb, i); > + uint64_t pc = qemu_plugin_insn_vaddr(insn); > + qemu_plugin_register_vcpu_insn_exec_cb(insn, insn_exec, > + QEMU_PLUGIN_CB_NO_REGS, > + (void*) pc); > + } > +}> + > +QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id, > + const qemu_info_t *info, > + int argc, char **argv) > +{ > + int i; > + > + for (i = 0; i < argc; i++) { > + char *opt = argv[i]; > + g_auto(GStrv) tokens = g_strsplit(opt, "=", 2); > + if (g_strcmp0(tokens[0], "abort") == 0) { > + if (!qemu_plugin_bool_parse(tokens[0], tokens[1], &abort_on_mismatch)) { > + fprintf(stderr, "boolean argument parsing failed: %s\n", opt); > + return -1; > + } > + } else { > + fprintf(stderr, "option parsing failed: %s\n", opt); > + return -1; > + } > + } > + > + states = qemu_plugin_scoreboard_new(sizeof(struct cpu_state)); > + > + qemu_plugin_register_vcpu_discon_cb(id, QEMU_PLUGIN_DISCON_ALL, > + vcpu_discon); > + qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans); > + > + return 0; > +} > diff --git a/tests/tcg/plugins/meson.build b/tests/tcg/plugins/meson.build > index f847849b1b..f057238da1 100644 > --- a/tests/tcg/plugins/meson.build > +++ b/tests/tcg/plugins/meson.build > @@ -1,6 +1,6 @@ > t = [] > if get_option('plugins') > - foreach i : ['bb', 'empty', 'inline', 'insn', 'mem', 'syscall'] > + foreach i : ['bb', 'discons', 'empty', 'inline', 'insn', 'mem', 'syscall'] > if host_os == 'windows' > t += shared_module(i, files(i + '.c') + '../../../contrib/plugins/win32_linker.c', > include_directories: '../../../include/qemu',
Hi Pierrick, December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: > On 12/2/24 11:41, Julian Ganz wrote: > > > +/* > > + * Copyright (C) 2024, Julian Ganz <neither@nut.email> > > + * > > + * License: GNU GPL, version 2 or later. > > + * See the COPYING file in the top-level directory. > > + */ > > > Would be nice to include a description of the plugin here. Agreed. I'll include one next time. > When booting an arm64 vm, I get this message: > Trap target PC mismatch > Expected: 23faf3a80 > Encountered: 23faf3a84 > > From what I understand, it means that the next_pc we have is incorrect. Yes, this is indeed incorrect, and also a perfect example why this test plugin exists. There are likely other errors lurking in target specific code. Did you happen to also log interrupts? Do you remember what image you used? Btw: this also illustrates another issue I have with from_pc: we can test the behavior for to_pc, but doing this meaningfully for from_pc via a plugin is next to impossible because the instruction it points to is not observable via an exec callback. At least not in the general case, even not if we only consider a single type of event. Regards, Julian Ganz
On 12/5/24 05:10, Julian Ganz wrote: > Hi Pierrick, > > December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: >> On 12/2/24 11:41, Julian Ganz wrote: >> >>> +/* >>> + * Copyright (C) 2024, Julian Ganz <neither@nut.email> >>> + * >>> + * License: GNU GPL, version 2 or later. >>> + * See the COPYING file in the top-level directory. >>> + */ >>> >> Would be nice to include a description of the plugin here. > > Agreed. I'll include one next time. > >> When booting an arm64 vm, I get this message: >> Trap target PC mismatch >> Expected: 23faf3a80 >> Encountered: 23faf3a84 >> >> From what I understand, it means that the next_pc we have is incorrect. > > Yes, this is indeed incorrect, and also a perfect example why this test > plugin exists. There are likely other errors lurking in target specific > code. Did you happen to also log interrupts? Do you remember what image > you used? I used exactly this: ./build/qemu-system-aarch64 -plugin ./build/tests/tcg/plugins/libdiscons.so -smp 4 -M virt -d plugin -m 8G -device virtio-blk-pci,drive=root -drive if=none,id=root,file=./debianaarch64.img -M virt -cpu max,pauth=off -drive if=pflash,readonly=on,file=/usr/share/AAVMF/AAVMF_CODE.fd -drive if=pflash,file=./AAVMF_VARS.fd The arm64 image is a vanilla debian stable I installed. AAVMF* files come from qemu-efi-aarch64 debian package. > > Btw: this also illustrates another issue I have with from_pc: we can > test the behavior for to_pc, but doing this meaningfully for from_pc > via a plugin is next to impossible because the instruction it points to > is not observable via an exec callback. At least not in the general > case, even not if we only consider a single type of event. > We can store the next_expected pc for each instruction (from current_instruction + insn_length), and we should be able to compare that with the expected from_pc. This is mostly what contrib/plugins/cflow.c does. With that, we can test from_pc. > Regards, > Julian Ganz
Hi Pierrick, December 5, 2024 at 6:30 PM, "Pierrick Bouvier" wrote: > On 12/5/24 05:10, Julian Ganz wrote: > > December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: > > > Trap target PC mismatch > > > Expected: 23faf3a80 > > > Encountered: 23faf3a84 > > > > > > From what I understand, it means that the next_pc we have is incorrect. > > > > > Yes, this is indeed incorrect, and also a perfect example why this test > > plugin exists. There are likely other errors lurking in target specific > > code. Did you happen to also log interrupts? Do you remember what image > > you used? > > > I used exactly this: > > ./build/qemu-system-aarch64 -plugin ./build/tests/tcg/plugins/libdiscons.so -smp 4 -M virt -d plugin -m 8G -device virtio-blk-pci,drive=root -drive if=none,id=root,file=./debianaarch64.img -M virt -cpu max,pauth=off -drive if=pflash,readonly=on,file=/usr/share/AAVMF/AAVMF_CODE.fd -drive if=pflash,file=./AAVMF_VARS.fd > > The arm64 image is a vanilla debian stable I installed. > AAVMF* files come from qemu-efi-aarch64 debian package. Thanks! I will have a closer look and include a fix in the next iteration. > > Btw: this also illustrates another issue I have with from_pc: we can > > test the behavior for to_pc, but doing this meaningfully for from_pc > > via a plugin is next to impossible because the instruction it points to > > is not observable via an exec callback. At least not in the general > > case, even not if we only consider a single type of event. > > > We can store the next_expected pc for each instruction (from current_instruction + insn_length), and we should be able to compare that with the expected from_pc. > This is mostly what contrib/plugins/cflow.c does. > > With that, we can test from_pc. I'm not confident that this will work reliably for branch, jump and other "interesting" instructions. But I can have a closer look at the cflow plugin and try to figure out how that plugin handles those cases. Regards, Julian Ganz
On 12/5/24 13:22, Julian Ganz wrote: > Hi Pierrick, > > December 5, 2024 at 6:30 PM, "Pierrick Bouvier" wrote: >> On 12/5/24 05:10, Julian Ganz wrote: >>> December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: >>>> Trap target PC mismatch >>>> Expected: 23faf3a80 >>>> Encountered: 23faf3a84 >>>> >>>> From what I understand, it means that the next_pc we have is incorrect. >>>> >>> Yes, this is indeed incorrect, and also a perfect example why this test >>> plugin exists. There are likely other errors lurking in target specific >>> code. Did you happen to also log interrupts? Do you remember what image >>> you used? >>> >> I used exactly this: >> >> ./build/qemu-system-aarch64 -plugin ./build/tests/tcg/plugins/libdiscons.so -smp 4 -M virt -d plugin -m 8G -device virtio-blk-pci,drive=root -drive if=none,id=root,file=./debianaarch64.img -M virt -cpu max,pauth=off -drive if=pflash,readonly=on,file=/usr/share/AAVMF/AAVMF_CODE.fd -drive if=pflash,file=./AAVMF_VARS.fd >> >> The arm64 image is a vanilla debian stable I installed. >> AAVMF* files come from qemu-efi-aarch64 debian package. > > Thanks! I will have a closer look and include a fix in the next iteration. > >>> Btw: this also illustrates another issue I have with from_pc: we can >>> test the behavior for to_pc, but doing this meaningfully for from_pc >>> via a plugin is next to impossible because the instruction it points to >>> is not observable via an exec callback. At least not in the general >>> case, even not if we only consider a single type of event. >>> >> We can store the next_expected pc for each instruction (from current_instruction + insn_length), and we should be able to compare that with the expected from_pc. >> This is mostly what contrib/plugins/cflow.c does. >> >> With that, we can test from_pc. > > I'm not confident that this will work reliably for branch, jump and > other "interesting" instructions. But I can have a closer look at the > cflow plugin and try to figure out how that plugin handles those cases. > It won't work for latest instructions in a tb (because we don't know what will be the next one), but should be good for all the others cases. > Regards, > Julian Ganz
Hi Pierrick, December 5, 2024 at 11:28 PM, "Pierrick Bouvier" wrote: > On 12/5/24 13:22, Julian Ganz wrote: > > December 5, 2024 at 6:30 PM, "Pierrick Bouvier" wrote: > > > We can store the next_expected pc for each instruction (from current_instruction + insn_length), and we should be able to compare that with the expected from_pc. > > > This is mostly what contrib/plugins/cflow.c does. > > > > > > With that, we can test from_pc. > > > > > I'm not confident that this will work reliably for branch, jump and > > other "interesting" instructions. But I can have a closer look at the > > cflow plugin and try to figure out how that plugin handles those cases. > > > It won't work for latest instructions in a tb (because we don't know what will be the next one), but should be good for all the others cases. IIUC qemu will schedule interrupts "opportunistically" between tb executions. If that's the case we'll observe interrupts exclusively after the last instruction in a tb. That strikes me as a serious limitation. Regards, Julian Ganz
On 12/6/24 00:42, Julian Ganz wrote: > Hi Pierrick, > > December 5, 2024 at 11:28 PM, "Pierrick Bouvier" wrote: >> On 12/5/24 13:22, Julian Ganz wrote: >>> December 5, 2024 at 6:30 PM, "Pierrick Bouvier" wrote: >>>> We can store the next_expected pc for each instruction (from current_instruction + insn_length), and we should be able to compare that with the expected from_pc. >>>> This is mostly what contrib/plugins/cflow.c does. >>>> >>>> With that, we can test from_pc. >>>> >>> I'm not confident that this will work reliably for branch, jump and >>> other "interesting" instructions. But I can have a closer look at the >>> cflow plugin and try to figure out how that plugin handles those cases. >>> >> It won't work for latest instructions in a tb (because we don't know what will be the next one), but should be good for all the others cases. > > IIUC qemu will schedule interrupts "opportunistically" between tb > executions. If that's the case we'll observe interrupts exclusively > after the last instruction in a tb. That strikes me as a serious > limitation. > To reuse fancy vocabulary, maybe we should have a distinction between inferable interruptions (interrupt instruction) and uninferable interrupts, triggered by an external event. In the latter, it *might* be acceptable to not provide a from_pc (let's say a value 0), because there is no useful information in itself, except creating random edges in the control flow graph, which we don't want to do. What do you think of it? > Regards, > Julian Ganz
On 12/6/24 13:02, Pierrick Bouvier wrote: > On 12/6/24 00:42, Julian Ganz wrote: >> Hi Pierrick, >> >> December 5, 2024 at 11:28 PM, "Pierrick Bouvier" wrote: >>> On 12/5/24 13:22, Julian Ganz wrote: >>>> December 5, 2024 at 6:30 PM, "Pierrick Bouvier" wrote: >>>>> We can store the next_expected pc for each instruction (from current_instruction + >>>>> insn_length), and we should be able to compare that with the expected from_pc. >>>>> This is mostly what contrib/plugins/cflow.c does. >>>>> >>>>> With that, we can test from_pc. >>>>> >>>> I'm not confident that this will work reliably for branch, jump and >>>> other "interesting" instructions. But I can have a closer look at the >>>> cflow plugin and try to figure out how that plugin handles those cases. >>>> >>> It won't work for latest instructions in a tb (because we don't know what will be the >>> next one), but should be good for all the others cases. >> >> IIUC qemu will schedule interrupts "opportunistically" between tb >> executions. If that's the case we'll observe interrupts exclusively >> after the last instruction in a tb. That strikes me as a serious >> limitation. >> > > To reuse fancy vocabulary, maybe we should have a distinction between inferable > interruptions (interrupt instruction) and uninferable interrupts, triggered by an external > event. > > In the latter, it *might* be acceptable to not provide a from_pc (let's say a value 0), > because there is no useful information in itself, except creating random edges in the > control flow graph, which we don't want to do. > > What do you think of it? I think you both are over-complicating things. Always, env->pc (or whatever) within cc->cpu_exec_interrupt *is* where the interrupt is recognized, and *is* where the discontinuity occurs. Report that. Just because some device interrupts are deferred to the end of the TB, that makes no difference. There is no "right" answer for timing between execution and asynchronous interrupts. r~
On 12/6/24 11:42, Richard Henderson wrote: > On 12/6/24 13:02, Pierrick Bouvier wrote: >> On 12/6/24 00:42, Julian Ganz wrote: >>> Hi Pierrick, >>> >>> December 5, 2024 at 11:28 PM, "Pierrick Bouvier" wrote: >>>> On 12/5/24 13:22, Julian Ganz wrote: >>>>> December 5, 2024 at 6:30 PM, "Pierrick Bouvier" wrote: >>>>>> We can store the next_expected pc for each instruction (from current_instruction + >>>>>> insn_length), and we should be able to compare that with the expected from_pc. >>>>>> This is mostly what contrib/plugins/cflow.c does. >>>>>> >>>>>> With that, we can test from_pc. >>>>>> >>>>> I'm not confident that this will work reliably for branch, jump and >>>>> other "interesting" instructions. But I can have a closer look at the >>>>> cflow plugin and try to figure out how that plugin handles those cases. >>>>> >>>> It won't work for latest instructions in a tb (because we don't know what will be the >>>> next one), but should be good for all the others cases. >>> >>> IIUC qemu will schedule interrupts "opportunistically" between tb >>> executions. If that's the case we'll observe interrupts exclusively >>> after the last instruction in a tb. That strikes me as a serious >>> limitation. >>> >> >> To reuse fancy vocabulary, maybe we should have a distinction between inferable >> interruptions (interrupt instruction) and uninferable interrupts, triggered by an external >> event. >> >> In the latter, it *might* be acceptable to not provide a from_pc (let's say a value 0), >> because there is no useful information in itself, except creating random edges in the >> control flow graph, which we don't want to do. >> >> What do you think of it? > > I think you both are over-complicating things. > > Always, env->pc (or whatever) within cc->cpu_exec_interrupt *is* where the interrupt is > recognized, and *is* where the discontinuity occurs. Report that. > Do we have an architecture agnostic pc representation, or do we have to add this for every target in {arch}_cpu_exec_interrupt? Beyond the scope of interruptions, are we guaranteed this instruction pointer (per arch) is always updated between instructions? Any corner cases? > Just because some device interrupts are deferred to the end of the TB, that makes no > difference. There is no "right" answer for timing between execution and asynchronous > interrupts. > > > r~
On 12/6/24 14:40, Pierrick Bouvier wrote: > Do we have an architecture agnostic pc representation, or do we have to add this for every > target in {arch}_cpu_exec_interrupt? We have CPUClass.get_pc, which is almost certainly what you want. The call to TCGCPUOps.cpu_exec_interrupt is only a hint that an interrupt might be ready: interrupts can still be masked, etc. From the current bool return value you can tell if a discontinuity actually occurred. But if you want to categorize that event in any way you need to update each architecture. You could simplify such updates by changing the return type from bool to an enum. While you would have to simultaneously update all targets for the change in function signature, if you select enumerators such that 0 -> no-op and 1 -> uncategorized, then you can also tell if a target has been updated. Because this is still C, the current return true/false statements will Just Work. :-) On the other hand, the previous patches to add plugin calls to each cpu_exec_interrupt are in the end approximately the same level of difficulty, and is more straightforward, so YMMV. > Beyond the scope of interruptions, are we guaranteed this instruction pointer (per arch) > is always updated between instructions? Any corner cases? Not "between instructions" or even "between TB". But you are guaranteed that pc is updated by the time we get to cpu_handle_interrupt, where cpu_exec_interrupt is called. r~
Hi Richard, December 6, 2024 at 8:42 PM, "Richard Henderson" wrote: > On 12/6/24 13:02, Pierrick Bouvier wrote: > > On 12/6/24 00:42, Julian Ganz wrote: > > > IIUC qemu will schedule interrupts "opportunistically" between tb > > > executions. If that's the case we'll observe interrupts exclusively > > > after the last instruction in a tb. That strikes me as a serious > > > limitation. > > > > > To reuse fancy vocabulary, maybe we should have a distinction between inferable > interruptions (interrupt instruction) and uninferable interrupts, triggered by an external > event. > > In the latter, it *might* be acceptable to not provide a from_pc (let's say a value 0), > because there is no useful information in itself, except creating random edges in the > control flow graph, which we don't want to do. > > What do you think of it? > > > I think you both are over-complicating things. > > Always, env->pc (or whatever) within cc->cpu_exec_interrupt *is* where the interrupt is recognized, and *is* where the discontinuity occurs. Report that. Glad to hear. This means what I naïvely did for most targets should be correct at least in this regard. Regards, Julian
Hi Richard, December 6, 2024 at 11:56 PM, "Richard Henderson" wrote: > On 12/6/24 14:40, Pierrick Bouvier wrote: > > > > > Do we have an architecture agnostic pc representation, or do we have to add this for every > target in {arch}_cpu_exec_interrupt? > > > We have CPUClass.get_pc, which is almost certainly what you want. I was wondering about this but honestly failed to do so until the current series was done. I'll definitely use this for to_pc in the next iteration. I'll still need to gather from_pc "manually", but that's ok. > The call to TCGCPUOps.cpu_exec_interrupt is only a hint that an interrupt might be ready: interrupts can still be masked, etc. > > From the current bool return value you can tell if a discontinuity actually occurred. But if you want to categorize that event in any way you need to update each architecture. > > You could simplify such updates by changing the return type from bool to an enum. While you would have to simultaneously update all targets for the change in function signature, if you select enumerators such that 0 -> no-op and 1 -> uncategorized, then you can also tell if a target has been updated. Because this is still C, the current return true/false statements will Just Work. :-) > > On the other hand, the previous patches to add plugin calls to each cpu_exec_interrupt are in the end approximately the same level of difficulty, and is more straightforward, so YMMV. Good to hear. I think I'll stick to the current setup. It likely also probably makes things easier or less awkward if the API is extended to cover things like branches and jumps in the future. Regards, Julian
Hi Pierrick, December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: > On 12/2/24 11:41, Julian Ganz wrote: > > +static void insn_exec(unsigned int vcpu_index, void *userdata) > > +{ > > + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); > > + uint64_t pc = (uint64_t) userdata; > > + GString* report; > > + > > + if (state->has_next) { > > + if (state->next_pc != pc) { > > + report = g_string_new("Trap target PC mismatch\n"); > > + g_string_append_printf(report, > > + "Expected: %"PRIx64"\nEncountered: %" > > + PRIx64"\n", > > + state->next_pc, pc); > > + qemu_plugin_outs(report->str); > > + if (abort_on_mismatch) { > > + g_abort(); > > + } > > + g_string_free(report, true); > > + } > > + state->has_next = false; > > + } > > +} > > > When booting an arm64 vm, I get this message: > Trap target PC mismatch > Expected: 23faf3a80 > Encountered: 23faf3a84 A colleague of mine went to great lengths trying to track and reliably reproduce this. We think that it's something amiss with the existing instruction exec callback infrastructure. So... it's not something I'll be addressing with the next iteration as it's out of scope. We'll probably continue looking into it, though. The mismatch is reported perfectly normal and boring exceptions and interrupts with no indication of any differences to other (not reported) events that fire on a regular basis. Apparently, once in a blue moon (relatively speaking), for the first instruction of a handler (even though it is definitely executed and qemu does print a trace-line for that instruction): | Trace 0: 0x7fffa0b03900 [00104004/000000023fde73b4/00000021/ff020200] | Trace 0: 0x7fffa02d9580 [00104004/000000023fde72b8/00000021/ff020200] | Trace 0: 0x7fffa02dfc40 [00104004/000000023fde7338/00000021/ff020200] | Trace 0: 0x7fffa0b03d00 [00104004/000000023fde73d4/00000021/ff020200] | Trace 0: 0x7fffa0b03e80 [00104004/000000023fde73d8/00000021/ff020200] | Trace 0: 0x7fffa0b04140 [00104004/000000023fde7408/00000021/ff020200] | Trace 0: 0x7fffa02dd6c0 [00104004/000000023fde70b8/00000021/ff020200] | Trace 0: 0x7fffa02dd800 [00104004/000000023fde7b90/00000021/ff020200] | cpu_io_recompile: rewound execution of TB to 000000023fde7b90 | Taking exception 5 [IRQ] on CPU 0 | ...from EL1 to EL1 | ...with ESR 0x0/0x3800000 | ...with SPSR 0x20000305 | ...with ELR 0x23fde7b90 | ...to EL1 PC 0x23fd77a80 PSTATE 0x23c5 | Trace 0: 0x7fffa13a8340 [00104004/000000023fd77a80/00000021/ff021201] | Trace 0: 0x7fffa13a8480 [00104004/000000023fd77a84/00000021/ff020200] | Trap target PC mismatch CPU 0 | Expected: 23fd77a80 | Encountered: 23fd77a84 | warning: 44 ./nptl/pthread_kill.c: No such file or directory | Couldn't get registers: No such process. It does show up with both single-core and multi-core VMs, so that at least eliminates some possibilities. Maybe :/ The issue is nasty to reproduce in a way that allows any meaningful investigation. It usually involves sifting through many GBs of Qemu logs for maybe one occurance. We could add another testing/dummy plugin that just prints the PC for _any_ instruction executed and have a skript check for non-alternating Trace-lines from Qemu and that Plugin. But then we're talking nearly double the amount of Lines to look through with probably little additional information. Regards, Julian
Hi Julian, On 12/20/24 03:47, Julian Ganz wrote: > Hi Pierrick, > > December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: >> On 12/2/24 11:41, Julian Ganz wrote: >>> +static void insn_exec(unsigned int vcpu_index, void *userdata) >>> +{ >>> + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); >>> + uint64_t pc = (uint64_t) userdata; >>> + GString* report; >>> + >>> + if (state->has_next) { >>> + if (state->next_pc != pc) { >>> + report = g_string_new("Trap target PC mismatch\n"); >>> + g_string_append_printf(report, >>> + "Expected: %"PRIx64"\nEncountered: %" >>> + PRIx64"\n", >>> + state->next_pc, pc); >>> + qemu_plugin_outs(report->str); >>> + if (abort_on_mismatch) { >>> + g_abort(); >>> + } >>> + g_string_free(report, true); >>> + } >>> + state->has_next = false; >>> + } >>> +} >>> >> When booting an arm64 vm, I get this message: >> Trap target PC mismatch >> Expected: 23faf3a80 >> Encountered: 23faf3a84 > > A colleague of mine went to great lengths trying to track and reliably > reproduce this. We think that it's something amiss with the existing > instruction exec callback infrastructure. So... it's not something I'll > be addressing with the next iteration as it's out of scope. We'll > probably continue looking into it, though. > > The mismatch is reported perfectly normal and boring exceptions and > interrupts with no indication of any differences to other (not reported) > events that fire on a regular basis. Apparently, once in a blue moon > (relatively speaking), for the first instruction of a handler (even > though it is definitely executed and qemu does print a trace-line for > that instruction): > > | Trace 0: 0x7fffa0b03900 [00104004/000000023fde73b4/00000021/ff020200] > | Trace 0: 0x7fffa02d9580 [00104004/000000023fde72b8/00000021/ff020200] > | Trace 0: 0x7fffa02dfc40 [00104004/000000023fde7338/00000021/ff020200] > | Trace 0: 0x7fffa0b03d00 [00104004/000000023fde73d4/00000021/ff020200] > | Trace 0: 0x7fffa0b03e80 [00104004/000000023fde73d8/00000021/ff020200] > | Trace 0: 0x7fffa0b04140 [00104004/000000023fde7408/00000021/ff020200] > | Trace 0: 0x7fffa02dd6c0 [00104004/000000023fde70b8/00000021/ff020200] > | Trace 0: 0x7fffa02dd800 [00104004/000000023fde7b90/00000021/ff020200] > | cpu_io_recompile: rewound execution of TB to 000000023fde7b90 > | Taking exception 5 [IRQ] on CPU 0 > | ...from EL1 to EL1 > | ...with ESR 0x0/0x3800000 > | ...with SPSR 0x20000305 > | ...with ELR 0x23fde7b90 > | ...to EL1 PC 0x23fd77a80 PSTATE 0x23c5 > | Trace 0: 0x7fffa13a8340 [00104004/000000023fd77a80/00000021/ff021201] > | Trace 0: 0x7fffa13a8480 [00104004/000000023fd77a84/00000021/ff020200] > | Trap target PC mismatch CPU 0 > | Expected: 23fd77a80 > | Encountered: 23fd77a84 > | warning: 44 ./nptl/pthread_kill.c: No such file or directory > | Couldn't get registers: No such process. > > It does show up with both single-core and multi-core VMs, so that at > least eliminates some possibilities. Maybe :/ > > The issue is nasty to reproduce in a way that allows any meaningful > investigation. It usually involves sifting through many GBs of Qemu logs > for maybe one occurance. We could add another testing/dummy plugin that > just prints the PC for _any_ instruction executed and have a skript > check for non-alternating Trace-lines from Qemu and that Plugin. But > then we're talking nearly double the amount of Lines to look through > with probably little additional information. > Thanks for the investigation. I could reproduce this with this command line: ./build/qemu-system-aarch64 -M virt -plugin ./build/tests/tcg/plugins/libdiscons.so,abort=on -m 8G -device virtio-blk-pci,drive=root -drive if=none,id=root,file=/home/user/.work/images/debianaarch64.img -M virt -cpu max,pauth=off -drive if=pflash,readonly=on,file=/usr/share/AAVMF/AAVMF_CODE.fd -drive if=pflash,file=/home/user/.work/images/AAVMF_VARS.fd -d plugin,in_asm,op -D crash.log # -d plugin,in_asm,op allows to dump asm of every translated block, plugin output (for discon plugin), and tcg op generated. It reliably crashes with a single address. Looking at the debug output (crash.log): ---------------- IN: 0x23faf3a80: d108c3ff sub sp, sp, #0x230 # => This bb has a single instruction as input OP: # this is the TB instrumentation ld_i32 loc0,env,$0xfffffffffffffff8 brcond_i32 loc0,$0x0,lt,$L0 st8_i32 $0x1,env,$0xfffffffffffffffc ---- 0000000000000a80 0000000000000000 0000000000000000 # => we can see that there is no call_plugin, looks like instrumentation # is not applied sub_i64 sp,sp,$0x230 add_i64 pc,pc,$0x4 goto_tb $0x1 exit_tb $0x7f7eedd355c1 set_label $L0 exit_tb $0x7f7eedd355c3 ---------------- IN: 0x23faf3a84: a9b007e0 stp x0, x1, [sp, #-0x100]! 0x23faf3a88: a9010fe2 stp x2, x3, [sp, #0x10] ... OP: ld_i32 loc0,env,$0xfffffffffffffff8 brcond_i32 loc0,$0x0,lt,$L0 st8_i32 $0x0,env,$0xfffffffffffffffc ---- 0000000000000a84 0000000000000000 0000000000000000 # instruction is correctly applied call plugin(0x7f7eec96d530),$0x1,$0,$0x0,$0x23faf3a84 mov_i64 loc2,sp ... Trap target PC mismatch Expected: 23faf3a80 Encountered: 23faf3a84 The thing interesting here is that we can notice that 23faf3a80 is a translation block with a single instruction, and we can see that instrumentation is not applied for this instruction (call_plugin is not present). Overall, it really looks like a bug on QEMU side, where we miss instrumenting something. I'll take a look. You can ignore this for now. > Regards, > Julian
On 12/20/24 13:17, Pierrick Bouvier wrote: > Hi Julian, > > On 12/20/24 03:47, Julian Ganz wrote: >> Hi Pierrick, >> >> December 5, 2024 at 12:33 AM, "Pierrick Bouvier" wrote: >>> On 12/2/24 11:41, Julian Ganz wrote: >>>> +static void insn_exec(unsigned int vcpu_index, void *userdata) >>>> +{ >>>> + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); >>>> + uint64_t pc = (uint64_t) userdata; >>>> + GString* report; >>>> + >>>> + if (state->has_next) { >>>> + if (state->next_pc != pc) { >>>> + report = g_string_new("Trap target PC mismatch\n"); >>>> + g_string_append_printf(report, >>>> + "Expected: %"PRIx64"\nEncountered: %" >>>> + PRIx64"\n", >>>> + state->next_pc, pc); >>>> + qemu_plugin_outs(report->str); >>>> + if (abort_on_mismatch) { >>>> + g_abort(); >>>> + } >>>> + g_string_free(report, true); >>>> + } >>>> + state->has_next = false; >>>> + } >>>> +} >>>> >>> When booting an arm64 vm, I get this message: >>> Trap target PC mismatch >>> Expected: 23faf3a80 >>> Encountered: 23faf3a84 >> >> A colleague of mine went to great lengths trying to track and reliably >> reproduce this. We think that it's something amiss with the existing >> instruction exec callback infrastructure. So... it's not something I'll >> be addressing with the next iteration as it's out of scope. We'll >> probably continue looking into it, though. >> >> The mismatch is reported perfectly normal and boring exceptions and >> interrupts with no indication of any differences to other (not reported) >> events that fire on a regular basis. Apparently, once in a blue moon >> (relatively speaking), for the first instruction of a handler (even >> though it is definitely executed and qemu does print a trace-line for >> that instruction): >> >> | Trace 0: 0x7fffa0b03900 [00104004/000000023fde73b4/00000021/ff020200] >> | Trace 0: 0x7fffa02d9580 [00104004/000000023fde72b8/00000021/ff020200] >> | Trace 0: 0x7fffa02dfc40 [00104004/000000023fde7338/00000021/ff020200] >> | Trace 0: 0x7fffa0b03d00 [00104004/000000023fde73d4/00000021/ff020200] >> | Trace 0: 0x7fffa0b03e80 [00104004/000000023fde73d8/00000021/ff020200] >> | Trace 0: 0x7fffa0b04140 [00104004/000000023fde7408/00000021/ff020200] >> | Trace 0: 0x7fffa02dd6c0 [00104004/000000023fde70b8/00000021/ff020200] >> | Trace 0: 0x7fffa02dd800 [00104004/000000023fde7b90/00000021/ff020200] >> | cpu_io_recompile: rewound execution of TB to 000000023fde7b90 >> | Taking exception 5 [IRQ] on CPU 0 >> | ...from EL1 to EL1 >> | ...with ESR 0x0/0x3800000 >> | ...with SPSR 0x20000305 >> | ...with ELR 0x23fde7b90 >> | ...to EL1 PC 0x23fd77a80 PSTATE 0x23c5 >> | Trace 0: 0x7fffa13a8340 [00104004/000000023fd77a80/00000021/ff021201] >> | Trace 0: 0x7fffa13a8480 [00104004/000000023fd77a84/00000021/ff020200] >> | Trap target PC mismatch CPU 0 >> | Expected: 23fd77a80 >> | Encountered: 23fd77a84 >> | warning: 44 ./nptl/pthread_kill.c: No such file or directory >> | Couldn't get registers: No such process. >> >> It does show up with both single-core and multi-core VMs, so that at >> least eliminates some possibilities. Maybe :/ >> >> The issue is nasty to reproduce in a way that allows any meaningful >> investigation. It usually involves sifting through many GBs of Qemu logs >> for maybe one occurance. We could add another testing/dummy plugin that >> just prints the PC for _any_ instruction executed and have a skript >> check for non-alternating Trace-lines from Qemu and that Plugin. But >> then we're talking nearly double the amount of Lines to look through >> with probably little additional information. >> > > Thanks for the investigation. > I could reproduce this with this command line: > ./build/qemu-system-aarch64 -M virt -plugin > ./build/tests/tcg/plugins/libdiscons.so,abort=on -m 8G -device > virtio-blk-pci,drive=root -drive > if=none,id=root,file=/home/user/.work/images/debianaarch64.img -M virt > -cpu max,pauth=off -drive > if=pflash,readonly=on,file=/usr/share/AAVMF/AAVMF_CODE.fd -drive > if=pflash,file=/home/user/.work/images/AAVMF_VARS.fd -d plugin,in_asm,op > -D crash.log > > # -d plugin,in_asm,op allows to dump asm of every translated block, > plugin output (for discon plugin), and tcg op generated. > > It reliably crashes with a single address. > Looking at the debug output (crash.log): > ---------------- > IN: > 0x23faf3a80: d108c3ff sub sp, sp, #0x230 > # => This bb has a single instruction as input > > OP: > # this is the TB instrumentation > ld_i32 loc0,env,$0xfffffffffffffff8 > brcond_i32 loc0,$0x0,lt,$L0 > st8_i32 $0x1,env,$0xfffffffffffffffc > > ---- 0000000000000a80 0000000000000000 0000000000000000 > # => we can see that there is no call_plugin, looks like instrumentation > # is not applied > sub_i64 sp,sp,$0x230 > add_i64 pc,pc,$0x4 > goto_tb $0x1 > exit_tb $0x7f7eedd355c1 > set_label $L0 > exit_tb $0x7f7eedd355c3 > > ---------------- > IN: > 0x23faf3a84: a9b007e0 stp x0, x1, [sp, #-0x100]! > 0x23faf3a88: a9010fe2 stp x2, x3, [sp, #0x10] > ... > > OP: > ld_i32 loc0,env,$0xfffffffffffffff8 > brcond_i32 loc0,$0x0,lt,$L0 > st8_i32 $0x0,env,$0xfffffffffffffffc > > ---- 0000000000000a84 0000000000000000 0000000000000000 > # instruction is correctly applied > call plugin(0x7f7eec96d530),$0x1,$0,$0x0,$0x23faf3a84 > mov_i64 loc2,sp > ... > > Trap target PC mismatch > Expected: 23faf3a80 > Encountered: 23faf3a84 > > The thing interesting here is that we can notice that 23faf3a80 is a > translation block with a single instruction, and we can see that > instrumentation is not applied for this instruction (call_plugin is not > present). > > Overall, it really looks like a bug on QEMU side, where we miss > instrumenting something. I'll take a look. You can ignore this for now. > It seems like we have a problem to identify tb as mem_only. This was introduced to prevent double instrumentation of some memory access (touching MMIO), but it seems that as a result, we skip some instructions sometimes. I need to dig into this further, but for now, you should be able to workaround this on your side with this patch: diff --git a/plugins/api.c b/plugins/api.c index 24ea64e2de5..6cb9d81a0a2 100644 --- a/plugins/api.c +++ b/plugins/api.c @@ -92,6 +92,7 @@ void qemu_plugin_register_vcpu_exit_cb(qemu_plugin_id_t id, static bool tb_is_mem_only(void) { + return false; return tb_cflags(tcg_ctx->gen_tb) & CF_MEMI_ONLY; } >> Regards, >> Julian > Regards, Pierrick
diff --git a/tests/tcg/plugins/discons.c b/tests/tcg/plugins/discons.c new file mode 100644 index 0000000000..54e52f563a --- /dev/null +++ b/tests/tcg/plugins/discons.c @@ -0,0 +1,95 @@ +/* + * Copyright (C) 2024, Julian Ganz <neither@nut.email> + * + * License: GNU GPL, version 2 or later. + * See the COPYING file in the top-level directory. + */ +#include <stdio.h> + +#include <qemu-plugin.h> + +QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION; + +struct cpu_state { + uint64_t next_pc; + bool has_next; +}; + +static struct qemu_plugin_scoreboard *states; + +static bool abort_on_mismatch; + +static void vcpu_discon(qemu_plugin_id_t id, unsigned int vcpu_index, + enum qemu_plugin_discon_type type, uint64_t from_pc, + uint64_t to_pc) +{ + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); + state->next_pc = to_pc; + state->has_next = true; +} + +static void insn_exec(unsigned int vcpu_index, void *userdata) +{ + struct cpu_state *state = qemu_plugin_scoreboard_find(states, vcpu_index); + uint64_t pc = (uint64_t) userdata; + GString* report; + + if (state->has_next) { + if (state->next_pc != pc) { + report = g_string_new("Trap target PC mismatch\n"); + g_string_append_printf(report, + "Expected: %"PRIx64"\nEncountered: %" + PRIx64"\n", + state->next_pc, pc); + qemu_plugin_outs(report->str); + if (abort_on_mismatch) { + g_abort(); + } + g_string_free(report, true); + } + state->has_next = false; + } +} + +static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb) +{ + size_t i; + size_t n_insns = qemu_plugin_tb_n_insns(tb); + + for (i = 0; i < n_insns; i++) { + struct qemu_plugin_insn * insn = qemu_plugin_tb_get_insn(tb, i); + uint64_t pc = qemu_plugin_insn_vaddr(insn); + qemu_plugin_register_vcpu_insn_exec_cb(insn, insn_exec, + QEMU_PLUGIN_CB_NO_REGS, + (void*) pc); + } +} + +QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id, + const qemu_info_t *info, + int argc, char **argv) +{ + int i; + + for (i = 0; i < argc; i++) { + char *opt = argv[i]; + g_auto(GStrv) tokens = g_strsplit(opt, "=", 2); + if (g_strcmp0(tokens[0], "abort") == 0) { + if (!qemu_plugin_bool_parse(tokens[0], tokens[1], &abort_on_mismatch)) { + fprintf(stderr, "boolean argument parsing failed: %s\n", opt); + return -1; + } + } else { + fprintf(stderr, "option parsing failed: %s\n", opt); + return -1; + } + } + + states = qemu_plugin_scoreboard_new(sizeof(struct cpu_state)); + + qemu_plugin_register_vcpu_discon_cb(id, QEMU_PLUGIN_DISCON_ALL, + vcpu_discon); + qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans); + + return 0; +} diff --git a/tests/tcg/plugins/meson.build b/tests/tcg/plugins/meson.build index f847849b1b..f057238da1 100644 --- a/tests/tcg/plugins/meson.build +++ b/tests/tcg/plugins/meson.build @@ -1,6 +1,6 @@ t = [] if get_option('plugins') - foreach i : ['bb', 'empty', 'inline', 'insn', 'mem', 'syscall'] + foreach i : ['bb', 'discons', 'empty', 'inline', 'insn', 'mem', 'syscall'] if host_os == 'windows' t += shared_module(i, files(i + '.c') + '../../../contrib/plugins/win32_linker.c', include_directories: '../../../include/qemu',