* Peter Xu (pet...@redhat.com) wrote: > On Tue, Mar 21, 2023 at 08:24:37PM +0000, Dr. David Alan Gilbert wrote: > > Hi Peter's, > > Peter M pointed me to a seg in a migration test in CI; I can reproduce > > it: > > * On an s390 host > > How easy to reproduce?
Pretty much every time when run as: make check -j 4 > > * only as part of a make check - running migration-test by itself > > doesn't trigger for me. > > * It looks like it's postcopy preempt > > > > (gdb) bt full > > #0 iov_size (iov=iov@entry=0x2aa00e60670, iov_cnt=<optimized out>) at > > ../util/iov.c:88 > > len = 13517923312037845750 > > i = 17305 > > #1 0x000002aa004d068c in qemu_fflush (f=0x2aa00e58630) at > > ../migration/qemu-file.c:307 > > local_error = 0x0 > > #2 0x000002aa004d0e04 in qemu_fflush (f=<optimized out>) at > > ../migration/qemu-file.c:297 > > #3 0x000002aa00613962 in postcopy_preempt_shutdown_file > > (s=s@entry=0x2aa00d1b4e0) at ../migration/ram.c:4657 > > #4 0x000002aa004e12b4 in migration_completion (s=0x2aa00d1b4e0) at > > ../migration/migration.c:3469 > > ret = <optimized out> > > current_active_state = 5 > > must_precopy = 0 > > can_postcopy = 0 > > in_postcopy = true > > pending_size = 0 > > __func__ = "migration_iteration_run" > > iter_state = <optimized out> > > s = 0x2aa00d1b4e0 > > thread = <optimized out> > > setup_start = <optimized out> > > thr_error = <optimized out> > > urgent = <optimized out> > > #5 migration_iteration_run (s=0x2aa00d1b4e0) at > > ../migration/migration.c:3882 > > must_precopy = 0 > > can_postcopy = 0 > > in_postcopy = true > > pending_size = 0 > > __func__ = "migration_iteration_run" > > iter_state = <optimized out> > > s = 0x2aa00d1b4e0 > > thread = <optimized out> > > setup_start = <optimized out> > > thr_error = <optimized out> > > urgent = <optimized out> > > #6 migration_thread (opaque=opaque@entry=0x2aa00d1b4e0) at > > ../migration/migration.c:4124 > > iter_state = <optimized out> > > s = 0x2aa00d1b4e0 > > --Type <RET> for more, q to quit, c to continue without paging-- > > thread = <optimized out> > > setup_start = <optimized out> > > thr_error = <optimized out> > > urgent = <optimized out> > > #7 0x000002aa00819b8c in qemu_thread_start (args=<optimized out>) at > > ../util/qemu-thread-posix.c:541 > > __cancel_buf = > > {__cancel_jmp_buf = {{__cancel_jmp_buf = {{__gregs = > > {4396782422080, 4393751543808, 4397299389454, 4396844235904, 2929182727824, > > 2929182933488, 4396843986792, 4397299389455, 33679382915066768, > > 33678512846981306}, __fpregs = {4396774031360, 8392704, 2929182933488, 0, > > 4396782422272, 2929172491858, 4396774031360, 1}}}, __mask_was_saved = 0}}, > > __pad = {0x3ffb4a77a60, 0x0, 0x0, 0x0}} > > __cancel_routine = 0x2aa00819bf0 <qemu_thread_atexit_notify> > > __not_first_call = <optimized out> > > start_routine = 0x2aa004e08f0 <migration_thread> > > arg = 0x2aa00d1b4e0 > > r = <optimized out> > > #8 0x000003ffb7b1e2e6 in start_thread () at /lib64/libc.so.6 > > #9 0x000003ffb7aafdbe in thread_start () at /lib64/libc.so.6 > > > > It looks like it's in the preempt test: > > > > (gdb) where > > #0 0x000003ffb17a0126 in __pthread_kill_implementation () from > > /lib64/libc.so.6 > > #1 0x000003ffb1750890 in raise () from /lib64/libc.so.6 > > #2 0x000003ffb172a340 in abort () from /lib64/libc.so.6 > > #3 0x000002aa0041c130 in qtest_check_status (s=<optimized out>) at > > ../tests/qtest/libqtest.c:194 > > #4 0x000003ffb1a3b5de in g_hook_list_invoke () from /lib64/libglib-2.0.so.0 > > #5 <signal handler called> > > #6 0x000003ffb17a0126 in __pthread_kill_implementation () from > > /lib64/libc.so.6 > > #7 0x000003ffb1750890 in raise () from /lib64/libc.so.6 > > #8 0x000003ffb172a340 in abort () from /lib64/libc.so.6 > > #9 0x000002aa00420318 in qmp_fd_receive (fd=<optimized out>) at > > ../tests/qtest/libqmp.c:80 > > #10 0x000002aa0041d5ee in qtest_qmp_receive_dict (s=0x2aa01eb2700) at > > ../tests/qtest/libqtest.c:713 > > #11 qtest_qmp_receive (s=0x2aa01eb2700) at ../tests/qtest/libqtest.c:701 > > #12 qtest_vqmp (s=s@entry=0x2aa01eb2700, fmt=fmt@entry=0x2aa00487100 "{ > > 'execute': 'query-migrate' }", ap=ap@entry=0x3ffc247cc68) > > at ../tests/qtest/libqtest.c:765 > > #13 0x000002aa00413f1e in wait_command (who=who@entry=0x2aa01eb2700, > > command=command@entry=0x2aa00487100 "{ 'execute': 'query-migrate' }") > > at ../tests/qtest/migration-helpers.c:73 > > #14 0x000002aa00414078 in migrate_query (who=who@entry=0x2aa01eb2700) at > > ../tests/qtest/migration-helpers.c:139 > > #15 migrate_query_status (who=who@entry=0x2aa01eb2700) at > > ../tests/qtest/migration-helpers.c:161 > > #16 0x000002aa00414480 in check_migration_status (ungoals=0x0, > > goal=0x2aa00495c7e "completed", who=0x2aa01eb2700) at > > ../tests/qtest/migration-helpers.c:177 > > #17 wait_for_migration_status (who=0x2aa01eb2700, goal=<optimized out>, > > ungoals=0x0) at ../tests/qtest/migration-helpers.c:202 > > #18 0x000002aa0041300e in migrate_postcopy_complete > > (from=from@entry=0x2aa01eb2700, to=to@entry=0x2aa01eb3000, > > args=args@entry=0x3ffc247cf48) > > at ../tests/qtest/migration-test.c:1137 > > #19 0x000002aa004131a4 in test_postcopy_common (args=0x3ffc247cf48) at > > ../tests/qtest/migration-test.c:1162 > > #20 test_postcopy_preempt () at ../tests/qtest/migration-test.c:1178 > > > > Looking at the iov and file it's garbage; so it makes me think this is > > something like a flush on a closed file. > > I didn't figure out how that could be closed, but I think there's indeed a > possible race that the qemufile can be accessed by both the return path > thread and the migration thread concurrently, while qemufile is not thread > safe on that. > > What postcopy_preempt_shutdown_file() does was: the src uses this EOS to > kick the dest QEMU preempt thread out of the migration and shut it off. > After some thought I think this is unnecessary complexity, since postcopy > should end at the point where dest received all the data, then it sends a > SHUT to src. So potentially it's not good to have dest relying on anything > from src to shutdown anything (the preempt thread here) because it's the > dest qemu that makes the final decision to finish. Ideally the preempt > thread on dest should be able to shutdown itself. > > The trick here is preempt thread will block at read() (aka, recvmsg()) at > the channel at that time and the only way to kick it out from that is a > shutdown() on dest. I attached a patch did it. I'm not 100% sure whether > it'll already resolve our problem but worth trying. This also made me > notice we forgot to enable SHUTDOWN feature on tls server when I was > running the patch 1 with qtest, so two patches needed. Well, it seems to fix it: Tested-by: Dr. David Alan Gilbert <dgilb...@redhat.com> Will this break interaction with an old qemu that's still waiting for the EOS? Dave > -- > Peter Xu > From 0e317fa78e9671c119f6be78a0e0a36201517dc2 Mon Sep 17 00:00:00 2001 > From: Peter Xu <pet...@redhat.com> > Date: Tue, 21 Mar 2023 19:58:42 -0400 > Subject: [PATCH 1/2] io: tls: Inherit QIO_CHANNEL_FEATURE_SHUTDOWN on server > side > > TLS iochannel will inherit io_shutdown() from the master ioc, however we > missed to do that on the server side. > > This will e.g. allow qemu_file_shutdown() to work on dest QEMU too for > migration. > > Signed-off-by: Peter Xu <pet...@redhat.com> > --- > io/channel-tls.c | 3 +++ > 1 file changed, 3 insertions(+) > > diff --git a/io/channel-tls.c b/io/channel-tls.c > index 5a7a3d48d6..9805dd0a3f 100644 > --- a/io/channel-tls.c > +++ b/io/channel-tls.c > @@ -74,6 +74,9 @@ qio_channel_tls_new_server(QIOChannel *master, > ioc = QIO_CHANNEL_TLS(object_new(TYPE_QIO_CHANNEL_TLS)); > > ioc->master = master; > + if (qio_channel_has_feature(master, QIO_CHANNEL_FEATURE_SHUTDOWN)) { > + qio_channel_set_feature(QIO_CHANNEL(ioc), > QIO_CHANNEL_FEATURE_SHUTDOWN); > + } > object_ref(OBJECT(master)); > > ioc->session = qcrypto_tls_session_new( > -- > 2.39.1 > > From 73b267c17e689d0dafbde1d93c0125b81a43184e Mon Sep 17 00:00:00 2001 > From: Peter Xu <pet...@redhat.com> > Date: Tue, 21 Mar 2023 19:11:22 -0400 > Subject: [PATCH 2/2] migration: Fix potential race on postcopy_qemufile_src > > postcopy_qemufile_src object should be owned by one thread, either the main > thread (e.g. when at the beginning, or at the end of migration), or by the > return path thread (when during a preempt enabled postcopy migration). If > that's not the case the access to the object might be racy. > > postcopy_preempt_shutdown_file() can be potentially racy, because it's > called at the end phase of migration on the main thread, however during > which the return path thread hasn't yet been recycled; the recycle happens > in await_return_path_close_on_source() which is after this point. > > It means, logically it's posslbe the main thread and the return path thread > are both operating on the same qemufile. While I don't think qemufile is > thread safe at all. > > postcopy_preempt_shutdown_file() used to be needed because that's where we > send EOS to dest so that dest can safely shutdown the preempt thread. > > To avoid the possible race, remove this only place that a race can happen. > Instead we figure out another way to safely close the preempt thread on > dest. > > The core idea during postcopy on deciding "when to stop" is that dest will > send a postcopy SHUT message to src, telling src that all data is there. > Hence to shut the dest preempt thread maybe better to do it directly on > dest node. > > This patch proposed such a way that we change postcopy_prio_thread_created > into PreemptThreadStatus, so that we kick the preempt thread on dest qemu > by a sequence of: > > mis->preempt_thread_status = PREEMPT_THREAD_QUIT; > qemu_file_shutdown(mis->postcopy_qemufile_dst); > > While here shutdown() is probably so far the easiest way to kick preempt > thread from a blocked qemu_get_be64(). Then it reads preempt_thread_status > to make sure it's not a network failure but a willingness to quit the > thread. > > We could have avoided that extra status but just rely on migration status. > The problem is postcopy_ram_incoming_cleanup() is just called early enough > so we're still during POSTCOPY_ACTIVE no matter what.. So just make it > simple to have the status introduced. > > Fixes: 36f62f11e4 ("migration: Postcopy preemption preparation on channel > creation") > Signed-off-by: Peter Xu <pet...@redhat.com> > --- > migration/migration.c | 7 ------- > migration/migration.h | 13 ++++++++++++- > migration/postcopy-ram.c | 20 +++++++++++++++----- > migration/ram.c | 6 ------ > migration/ram.h | 1 - > 5 files changed, 27 insertions(+), 20 deletions(-) > > diff --git a/migration/migration.c b/migration/migration.c > index ae2025d9d8..bbc36100de 100644 > --- a/migration/migration.c > +++ b/migration/migration.c > @@ -3459,16 +3459,9 @@ static void migration_completion(MigrationState *s) > } > } else if (s->state == MIGRATION_STATUS_POSTCOPY_ACTIVE) { > trace_migration_completion_postcopy_end(); > - > qemu_mutex_lock_iothread(); > qemu_savevm_state_complete_postcopy(s->to_dst_file); > qemu_mutex_unlock_iothread(); > - > - /* Shutdown the postcopy fast path thread */ > - if (migrate_postcopy_preempt()) { > - postcopy_preempt_shutdown_file(s); > - } > - > trace_migration_completion_postcopy_end_after_complete(); > } else { > goto fail; > diff --git a/migration/migration.h b/migration/migration.h > index 2da2f8a164..7228163cc8 100644 > --- a/migration/migration.h > +++ b/migration/migration.h > @@ -65,6 +65,12 @@ typedef struct { > bool all_zero; > } PostcopyTmpPage; > > +typedef enum { > + PREEMPT_THREAD_NONE = 0, > + PREEMPT_THREAD_CREATED, > + PREEMPT_THREAD_QUIT, > +} PreemptThreadStatus; > + > /* State for the incoming migration */ > struct MigrationIncomingState { > QEMUFile *from_src_file; > @@ -124,7 +130,12 @@ struct MigrationIncomingState { > QemuSemaphore postcopy_qemufile_dst_done; > /* Postcopy priority thread is used to receive postcopy requested pages > */ > QemuThread postcopy_prio_thread; > - bool postcopy_prio_thread_created; > + /* > + * Always set by the main vm load thread only, but can be read by the > + * postcopy preempt thread. "volatile" makes sure all reads will be > + * uptodate across cores. > + */ > + volatile PreemptThreadStatus preempt_thread_status; > /* > * Used to sync between the ram load main thread and the fast ram load > * thread. It protects postcopy_qemufile_dst, which is the postcopy > diff --git a/migration/postcopy-ram.c b/migration/postcopy-ram.c > index 41c0713650..263bab75ec 100644 > --- a/migration/postcopy-ram.c > +++ b/migration/postcopy-ram.c > @@ -568,9 +568,14 @@ int postcopy_ram_incoming_cleanup(MigrationIncomingState > *mis) > { > trace_postcopy_ram_incoming_cleanup_entry(); > > - if (mis->postcopy_prio_thread_created) { > + if (mis->preempt_thread_status == PREEMPT_THREAD_CREATED) { > + /* Notify the fast load thread to quit */ > + mis->preempt_thread_status = PREEMPT_THREAD_QUIT; > + if (mis->postcopy_qemufile_dst) { > + qemu_file_shutdown(mis->postcopy_qemufile_dst); > + } > qemu_thread_join(&mis->postcopy_prio_thread); > - mis->postcopy_prio_thread_created = false; > + mis->preempt_thread_status = PREEMPT_THREAD_NONE; > } > > if (mis->have_fault_thread) { > @@ -1203,7 +1208,7 @@ int postcopy_ram_incoming_setup(MigrationIncomingState > *mis) > */ > postcopy_thread_create(mis, &mis->postcopy_prio_thread, "fault-fast", > postcopy_preempt_thread, > QEMU_THREAD_JOINABLE); > - mis->postcopy_prio_thread_created = true; > + mis->preempt_thread_status = PREEMPT_THREAD_CREATED; > } > > trace_postcopy_ram_enable_notify(); > @@ -1652,6 +1657,11 @@ static void > postcopy_pause_ram_fast_load(MigrationIncomingState *mis) > trace_postcopy_pause_fast_load_continued(); > } > > +static bool preempt_thread_should_run(MigrationIncomingState *mis) > +{ > + return mis->preempt_thread_status != PREEMPT_THREAD_QUIT; > +} > + > void *postcopy_preempt_thread(void *opaque) > { > MigrationIncomingState *mis = opaque; > @@ -1671,11 +1681,11 @@ void *postcopy_preempt_thread(void *opaque) > > /* Sending RAM_SAVE_FLAG_EOS to terminate this thread */ > qemu_mutex_lock(&mis->postcopy_prio_thread_mutex); > - while (1) { > + while (preempt_thread_should_run(mis)) { > ret = ram_load_postcopy(mis->postcopy_qemufile_dst, > RAM_CHANNEL_POSTCOPY); > /* If error happened, go into recovery routine */ > - if (ret) { > + if (ret && preempt_thread_should_run(mis)) { > postcopy_pause_ram_fast_load(mis); > } else { > /* We're done */ > diff --git a/migration/ram.c b/migration/ram.c > index 96e8a19a58..8c316ffed2 100644 > --- a/migration/ram.c > +++ b/migration/ram.c > @@ -4651,12 +4651,6 @@ static int ram_resume_prepare(MigrationState *s, void > *opaque) > return 0; > } > > -void postcopy_preempt_shutdown_file(MigrationState *s) > -{ > - qemu_put_be64(s->postcopy_qemufile_src, RAM_SAVE_FLAG_EOS); > - qemu_fflush(s->postcopy_qemufile_src); > -} > - > static SaveVMHandlers savevm_ram_handlers = { > .save_setup = ram_save_setup, > .save_live_iterate = ram_save_iterate, > diff --git a/migration/ram.h b/migration/ram.h > index 81cbb0947c..93b071a1a7 100644 > --- a/migration/ram.h > +++ b/migration/ram.h > @@ -96,7 +96,6 @@ int64_t ramblock_recv_bitmap_send(QEMUFile *file, > const char *block_name); > int ram_dirty_bitmap_reload(MigrationState *s, RAMBlock *rb); > bool ramblock_page_is_discarded(RAMBlock *rb, ram_addr_t start); > -void postcopy_preempt_shutdown_file(MigrationState *s); > void *postcopy_preempt_thread(void *opaque); > > /* ram cache */ > -- > 2.39.1 > -- Dr. David Alan Gilbert / dgilb...@redhat.com / Manchester, UK