On Mon, 2025-12-01 at 10:36 +0000, Alex Bennée wrote: > Ilya Leoshkevich <[email protected]> writes: > > > On Sun, 2025-11-30 at 20:03 +0100, Ilya Leoshkevich wrote: > > > On Sun, 2025-11-30 at 19:32 +0100, Ilya Leoshkevich wrote: > > > > On Sun, 2025-11-30 at 16:47 +0000, Alex Bennée wrote: > > > > > Ilya Leoshkevich <[email protected]> writes: > > > > > > > > > > > On Fri, 2025-11-28 at 18:25 +0100, Ilya Leoshkevich wrote: > > > > > > > On Fri, 2025-11-28 at 14:39 +0100, Thomas Huth wrote: > > > > > > > > From: Thomas Huth <[email protected]> > > > > > > > > > > > > > > > > We just have to make sure that we can set the > > > > > > > > endianness to > > > > > > > > big > > > > > > > > endian, > > > > > > > > then we can also run this test on s390x. > > > > > > > > > > > > > > > > Signed-off-by: Thomas Huth <[email protected]> > > > > > > > > --- > > > > > > > > Marked as RFC since it depends on the fix for this bug > > > > > > > > (so > > > > > > > > it > > > > > > > > cannot > > > > > > > > be merged yet): > > > > > > > > > > > > > > > > https://lore.kernel.org/qemu-devel/[email protected] > > > > > > > > / > > > > > > > > > > > > > > > > tests/functional/reverse_debugging.py | 4 +++- > > > > > > > > tests/functional/s390x/meson.build | 1 + > > > > > > > > tests/functional/s390x/test_reverse_debug.py | 21 > > > > > > > > ++++++++++++++++++++ > > > > > > > > 3 files changed, 25 insertions(+), 1 deletion(-) > > > > > > > > create mode 100755 > > > > > > > > tests/functional/s390x/test_reverse_debug.py > > > > > > > > > > > > > > Reviewed-by: Ilya Leoshkevich <[email protected]> > > > > > > > > > > > > > > > > > > > > > I have a simple fix which helps with your original > > > > > > > report, > > > > > > > but > > > > > > > not > > > > > > > with this test. I'm still investigating. > > > > > > > > > > > > > > --- a/target/s390x/machine.c > > > > > > > +++ b/target/s390x/machine.c > > > > > > > @@ -52,6 +52,14 @@ static int cpu_pre_save(void *opaque) > > > > > > > kvm_s390_vcpu_interrupt_pre_save(cpu); > > > > > > > } > > > > > > > > > > > > > > + if (tcg_enabled()) { > > > > > > > + /* > > > > > > > + * Ensure symmetry with cpu_post_load() with > > > > > > > respect > > > > > > > to > > > > > > > + * CHECKPOINT_CLOCK_VIRTUAL. > > > > > > > + */ > > > > > > > + tcg_s390_tod_updated(CPU(cpu), RUN_ON_CPU_NULL); > > > > > > > + } > > > > > > > + > > > > > > > return 0; > > > > > > > } > > > > > > > > > > > > Interestingly enough, this patch fails only under load, > > > > > > e.g., > > > > > > if > > > > > > I > > > > > > run > > > > > > make check -j"$(nproc)" or if I run your test in isolation, > > > > > > but > > > > > > with > > > > > > stress-ng cpu in background. The culprit appears to be: > > > > > > > > > > > > s390_tod_load() > > > > > > qemu_s390_tod_set() > > > > > > async_run_on_cpu(tcg_s390_tod_updated) > > > > > > > > > > > > Depending on the system load, this additional > > > > > > tcg_s390_tod_updated() > > > > > > may or may not end up being called during > > > > > > handle_backward(). If > > > > > > it > > > > > > does, we get an infinite loop again, because now we need > > > > > > two > > > > > > checkpoints. > > > > > > > > > > > > I have a feeling that this code may be violating some > > > > > > record- > > > > > > replay > > > > > > requirement, but I can't quite put my finger on it. For > > > > > > example, > > > > > > async_run_on_cpu() does not sound like something > > > > > > deterministic, > > > > > > but > > > > > > then again it just queues work for rr_cpu_thread_fn(), > > > > > > which is > > > > > > supposed to be deterministic. > > > > > > > > > > The the async_run_on_cpu is called from the vcpu thread in > > > > > response > > > > > to a > > > > > deterministic event at a known point in time it should be > > > > > fine. > > > > > If > > > > > it > > > > > came from another thread that is not synchronised via > > > > > replay_lock > > > > > then > > > > > things will go wrong. > > > > > > > > > > But this is a VM load save helper? > > > > > > > > Yes, and it's called from the main thread. Either during > > > > initialization, or as a reaction to GDB packets. > > > > > > > > Here is the call stack: > > > > > > > > qemu_loadvm_state() > > > > qemu_loadvm_state_main() > > > > qemu_loadvm_section_start_full() > > > > vmstate_load() > > > > vmstate_load_state() > > > > cpu_post_load() > > > > tcg_s390_tod_updated() > > > > update_ckc_timer() > > > > timer_mod() > > > > s390_tod_load() > > > > qemu_s390_tod_set() # via tdc->set() > > > > async_run_on_cpu(tcg_s390_tod_updated) > > > > > > > > So you think we may have to take the replay lock around > > > > load_snapshot()? So that all async_run_on_cpu() calls it makes > > > > end > > > > up > > > > being handled by the vCPU thread deterministically. > > > > > > To answer my own question: apparently this is already the case; > > > at > > > least, the following does not cause any fallout: > > > > > > diff --git a/include/system/replay.h b/include/system/replay.h > > > index 6859df09580..e1cd9b2f900 100644 > > > --- a/include/system/replay.h > > > +++ b/include/system/replay.h > > > @@ -60,6 +60,7 @@ extern char *replay_snapshot; > > > > > > void replay_mutex_lock(void); > > > void replay_mutex_unlock(void); > > > +bool replay_mutex_locked(void); > > > > > > static inline void replay_unlock_guard(void *unused) > > > { > > > diff --git a/migration/savevm.c b/migration/savevm.c > > > index 62cc2ce25cb..ba945d3a1ea 100644 > > > --- a/migration/savevm.c > > > +++ b/migration/savevm.c > > > @@ -3199,6 +3199,8 @@ bool save_snapshot(const char *name, bool > > > overwrite, const char *vmstate, > > > uint64_t vm_state_size; > > > g_autoptr(GDateTime) now = g_date_time_new_now_local(); > > > > > > + g_assert(replay_mutex_locked()); > > > + > > > GLOBAL_STATE_CODE(); > > > > > > if (!migrate_can_snapshot(errp)) { > > > @@ -3390,6 +3392,8 @@ bool load_snapshot(const char *name, const > > > char > > > *vmstate, > > > int ret; > > > MigrationIncomingState *mis = > > > migration_incoming_get_current(); > > > > > > + g_assert(replay_mutex_locked()); > > > + > > > if (!migrate_can_snapshot(errp)) { > > > return false; > > > } > > > diff --git a/replay/replay-internal.h b/replay/replay-internal.h > > > index 75249b76936..30825a0753e 100644 > > > --- a/replay/replay-internal.h > > > +++ b/replay/replay-internal.h > > > @@ -124,7 +124,6 @@ void replay_get_array_alloc(uint8_t **buf, > > > size_t > > > *size); > > > * synchronisation between vCPU and main-loop threads. */ > > > > > > void replay_mutex_init(void); > > > -bool replay_mutex_locked(void); > > > > > > /*! Checks error status of the file. */ > > > void replay_check_error(void); > > > > I believe now I at least understand what the race is about: > > > > - cpu_post_load() fires the TOD timer immediately. > > > > - s390_tod_load() schedules work for firing the TOD timer. > > Is this a duplicate of work then? Could we just rely on one or the > other? If you drop the cpu_post_load() tweak then the vmstate load > helper should still ensure everything works right?
Getting rid of it fixes the problem and makes sense anyway. > > - If rr loop sees work and then timer, we get one timer callback. > > > > - If rr loop sees timer and then work, we get two timer callbacks. > > If the timer is armed we should expect at least to execute a few > instructions before triggering the timer, unless it was armed ready > expired. Yes, it is armed expired. Isn't it a deficiency in record-replay that work and timers are not ordered relative to each other? Can't it bite us somewhere else? > > - Record and replay may diverge due to this race. > > > > - In this particular case divergence makes rr loop spin: it sees > > that > > TOD timer has expired, but cannot invoke its callback, because > > there > > is no recorded CHECKPOINT_CLOCK_VIRTUAL. > > > > - The order in which rr loop sees work and timer depends on whether > > and when rr loop wakes up during load_snapshot(). > > > > - rr loop may wake up after the main thread kicks the CPU and drops > > the BQL, which may happen if it calls, e.g., > > qemu_cond_wait_bql().
