On Tue, 8 Mar 2022 at 18:47, Dr. David Alan Gilbert <dgilb...@redhat.com> wrote: > > * Philippe Mathieu-Daudé (philippe.mathieu.da...@gmail.com) wrote: > > I'm seeing an error on the s390x runner: > > > > ▶ 26/547 ERROR:../tests/qtest/migration-test.c:276:check_guests_ram: > > assertion failed: (bad == 0) ERROR > > > > 26/547 qemu:qtest+qtest-i386 / qtest-i386/migration-test ERROR > > 78.87s killed by signal 6 SIGABRT > > > > https://app.travis-ci.com/gitlab/qemu-project/qemu/jobs/562515884#L7848 > > Yeh, thuth mentioned that, it seems to only be s390 which is odd. > I'm not seeing anything obviously architecture dependent in that set, or > for that matter that plays with the ram migration stream much. > Is this reliable enough that someone with a tame s390 could bisect?
Didn't see a SIGABRT, but here's a gdb backtrace of a hang in the migration test on s390 host. I have also observed the migration test hanging on macos host, so I don't think this is s390-specific. Process tree: migration-test(455775)-+-qemu-system-i38(456194) |-qemu-system-i38(456200) `-qemu-system-i38(456266) =========================================================== PROCESS: 455775 linux1 455775 312266 5 14:36 pts/0 00:07:19 ./tests/qtest/migration-test -tap -k [New LWP 455776] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/s390x-linux-gnu/libthread_db.so.1". __libc_read (nbytes=1, buf=0x3ffe69fd816, fd=4) at ../sysdeps/unix/sysv/linux/read.c:26 26 ../sysdeps/unix/sysv/linux/read.c: No such file or directory. Thread 2 (Thread 0x3ff9c7ff900 (LWP 455776)): #0 syscall () at ../sysdeps/unix/sysv/linux/s390/s390-64/syscall.S:37 #1 0x000002aa1e8d24ca in qemu_futex_wait (f=0x2aa1e920cbc <rcu_call_ready_event>, val=4294967295) at /home/linux1/qemu/include/qemu/futex.h:29 #2 0x000002aa1e8d276e in qemu_event_wait (ev=0x2aa1e920cbc <rcu_call_ready_event>) at ../../util/qemu-thread-posix.c:481 #3 0x000002aa1e8e6ce2 in call_rcu_thread (opaque=0x0) at ../../util/rcu.c:261 #4 0x000002aa1e8d2998 in qemu_thread_start (args=0x2aa200e51e0) at ../../util/qemu-thread-posix.c:556 #5 0x000003ff9ca87e66 in start_thread (arg=0x3ff9c7ff900) at pthread_create.c:477 #6 0x000003ff9c97cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 1 (Thread 0x3ff9ce75430 (LWP 455775)): #0 __libc_read (nbytes=1, buf=0x3ffe69fd816, fd=4) at ../sysdeps/unix/sysv/linux/read.c:26 #1 __libc_read (fd=<optimized out>, buf=0x3ffe69fd816, nbytes=1) at ../sysdeps/unix/sysv/linux/read.c:24 #2 0x000002aa1e894652 in qmp_fd_receive (fd=4) at ../../tests/qtest/libqtest.c:613 #3 0x000002aa1e894816 in qtest_qmp_receive_dict (s=0x2aa200f6a20) at ../../tests/qtest/libqtest.c:648 #4 0x000002aa1e894782 in qtest_qmp_receive (s=0x2aa200f6a20) at ../../tests/qtest/libqtest.c:636 #5 0x000002aa1e894ede in qtest_vqmp (s=0x2aa200f6a20, fmt=0x2aa1e8f140c "{ 'execute': 'query-migrate' }", ap=0x3ffe69fdb80) at ../../tests/qtest/libqtest.c:749 #6 0x000002aa1e891ac0 in wait_command (who=0x2aa200f6a20, command=0x2aa1e8f140c "{ 'execute': 'query-migrate' }") at ../../tests/qtest/migration-helpers.c:63 #7 0x000002aa1e891de8 in migrate_query (who=0x2aa200f6a20) at ../../tests/qtest/migration-helpers.c:107 #8 0x000002aa1e891e1a in migrate_query_status (who=0x2aa200f6a20) at ../../tests/qtest/migration-helpers.c:116 #9 0x000002aa1e891ef6 in check_migration_status (who=0x2aa200f6a20, goal=0x2aa1e8f0f0e "cancelled", ungoals=0x0) at ../../tests/qtest/migration-helpers.c:132 #10 0x000002aa1e892150 in wait_for_migration_status (who=0x2aa200f6a20, goal=0x2aa1e8f0f0e "cancelled", ungoals=0x0) at ../../tests/qtest/migration-helpers.c:156 #11 0x000002aa1e8910fa in test_multifd_tcp_cancel () at ../../tests/qtest/migration-test.c:1379 #12 0x000003ff9cc7e608 in ?? () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #13 0x000003ff9cc7e392 in ?? () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #14 0x000003ff9cc7e392 in ?? () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #15 0x000003ff9cc7e392 in ?? () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #16 0x000003ff9cc7e392 in ?? () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #17 0x000003ff9cc7eada in g_test_run_suite () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #18 0x000003ff9cc7eb10 in g_test_run () from /lib/s390x-linux-gnu/libglib-2.0.so.0 #19 0x000002aa1e891578 in main (argc=2, argv=0x3ffe69fece8) at ../../tests/qtest/migration-test.c:1491 [Inferior 1 (process 455775) detached] =========================================================== PROCESS: 456194 linux1 456194 455775 85 14:39 pts/0 01:54:06 ./qemu-system-i386 -qtest unix:/tmp/qtest-455775.sock -qtest-log /dev/null -chardev socket,path=/tmp/qtest-455775.qmp,id=char0 -mon chardev=char0,mode=control -display none -accel kvm -accel tcg -name source,debug-threads=on -m 150M -serial file:/tmp/migration-test-dmqzpM/src_serial -drive file=/tmp/migration-test-dmqzpM/bootsect,format=raw -accel qtest [New LWP 456196] [New LWP 456197] [New LWP 456198] [New LWP 456229] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/s390x-linux-gnu/libthread_db.so.1". 0x000003ff9a071c9c in __ppoll (fds=0x2aa2c46c2f0, nfds=5, timeout=<optimized out>, sigmask=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:44 44 ../sysdeps/unix/sysv/linux/ppoll.c: No such file or directory. Thread 5 (Thread 0x3fee0ff9900 (LWP 456229)): #0 futex_abstimed_wait_cancelable (private=0, abstime=0x0, clockid=0, expected=0, futex_word=0x2aa2c46e7e4) at ../sysdeps/nptl/futex-internal.h:320 #1 do_futex_wait (sem=sem@entry=0x2aa2c46e7e0, abstime=0x0, clockid=0) at sem_waitcommon.c:112 #2 0x000003ff9a191870 in __new_sem_wait_slow (sem=0x2aa2c46e7e0, abstime=0x0, clockid=0) at sem_waitcommon.c:184 #3 0x000003ff9a19190e in __new_sem_wait (sem=<optimized out>) at sem_wait.c:42 #4 0x000002aa2923da1e in qemu_sem_wait (sem=0x2aa2c46e7e0) at ../../util/qemu-thread-posix.c:358 #5 0x000002aa289483cc in multifd_send_sync_main (f=0x2aa2b5f92d0) at ../../migration/multifd.c:610 #6 0x000002aa28dfa30c in ram_save_iterate (f=0x2aa2b5f92d0, opaque=0x2aa29bf75d0 <ram_state>) at ../../migration/ram.c:3049 #7 0x000002aa28958fee in qemu_savevm_state_iterate (f=0x2aa2b5f92d0, postcopy=false) at ../../migration/savevm.c:1296 #8 0x000002aa28942d40 in migration_iteration_run (s=0x2aa2b3f9800) at ../../migration/migration.c:3607 #9 0x000002aa289434da in migration_thread (opaque=0x2aa2b3f9800) at ../../migration/migration.c:3838 #10 0x000002aa2923e020 in qemu_thread_start (args=0x2aa2b8b29e0) at ../../util/qemu-thread-posix.c:556 #11 0x000003ff9a187e66 in start_thread (arg=0x3fee0ff9900) at pthread_create.c:477 #12 0x000003ff9a07cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 4 (Thread 0x3ff89f2f900 (LWP 456198)): #0 env_neg (env=0x2aa2b5f5030) at /home/linux1/qemu/include/exec/cpu-all.h:478 #1 0x000002aa28f5376a in env_tlb (env=0x2aa2b5f5030) at /home/linux1/qemu/include/exec/cpu-all.h:502 #2 0x000002aa28f538a8 in tlb_index (env=0x2aa2b5f5030, mmu_idx=2, addr=73265152) at /home/linux1/qemu/include/exec/cpu_ldst.h:366 #3 0x000002aa28f574bc in tlb_set_page_with_attrs (cpu=0x2aa2b5ec750, vaddr=73265152, paddr=73265152, attrs=..., prot=7, mmu_idx=2, size=4096) at ../../accel/tcg/cputlb.c:1194 #4 0x000002aa28cdfd3e in handle_mmu_fault (cs=0x2aa2b5ec750, addr=73265152, size=1, is_write1=0, mmu_idx=2) at ../../target/i386/tcg/sysemu/excp_helper.c:442 #5 0x000002aa28cdfe90 in x86_cpu_tlb_fill (cs=0x2aa2b5ec750, addr=73265152, size=1, access_type=MMU_DATA_LOAD, mmu_idx=2, probe=false, retaddr=4393820748608) at ../../target/i386/tcg/sysemu/excp_helper.c:468 #6 0x000002aa28f5794e in tlb_fill (cpu=0x2aa2b5ec750, addr=73265152, size=1, access_type=MMU_DATA_LOAD, mmu_idx=2, retaddr=4393820748608) at ../../accel/tcg/cputlb.c:1313 #7 0x000002aa28f59982 in load_helper (env=0x2aa2b5f5030, addr=73265152, oi=3586, retaddr=4393820748608, op=MO_8, code_read=false, full_load=0x2aa28f59db0 <full_ldub_mmu>) at ../../accel/tcg/cputlb.c:1934 #8 0x000002aa28f59e2e in full_ldub_mmu (env=0x2aa2b5f5030, addr=73265152, oi=3586, retaddr=4393820748608) at ../../accel/tcg/cputlb.c:2025 #9 0x000002aa28f59e94 in helper_ret_ldub_mmu (env=0x2aa2b5f5030, addr=73265152, oi=3586, retaddr=4393820748608) at ../../accel/tcg/cputlb.c:2031 #10 0x000003ff041ffbfa in code_gen_buffer () #11 0x000002aa28f3cfba in cpu_tb_exec (cpu=0x2aa2b5ec750, itb=0x3ff441ffa00, tb_exit=0x3ff89f2af44) at ../../accel/tcg/cpu-exec.c:357 #12 0x000002aa28f3e47e in cpu_loop_exec_tb (cpu=0x2aa2b5ec750, tb=0x3ff441ffa00, last_tb=0x3ff89f2af58, tb_exit=0x3ff89f2af44) at ../../accel/tcg/cpu-exec.c:847 #13 0x000002aa28f3e970 in cpu_exec (cpu=0x2aa2b5ec750) at ../../accel/tcg/cpu-exec.c:1006 #14 0x000002aa28f71a1e in tcg_cpus_exec (cpu=0x2aa2b5ec750) at ../../accel/tcg/tcg-accel-ops.c:68 #15 0x000002aa28f71efe in mttcg_cpu_thread_fn (arg=0x2aa2b5ec750) at ../../accel/tcg/tcg-accel-ops-mttcg.c:96 #16 0x000002aa2923e020 in qemu_thread_start (args=0x2aa2b60bb00) at ../../util/qemu-thread-posix.c:556 #17 0x000003ff9a187e66 in start_thread (arg=0x3ff89f2f900) at pthread_create.c:477 #18 0x000003ff9a07cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 3 (Thread 0x3ff8a821900 (LWP 456197)): #0 0x000003ff9a071b42 in __GI___poll (fds=0x3fefc003280, nfds=3, timeout=<optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:29 #1 0x000003ff9c7d4386 in () at /lib/s390x-linux-gnu/libglib-2.0.so.0 #2 0x000003ff9c7d4790 in g_main_loop_run () at /lib/s390x-linux-gnu/libglib-2.0.so.0 #3 0x000002aa28fd9d56 in iothread_run (opaque=0x2aa2b339750) at ../../iothread.c:73 #4 0x000002aa2923e020 in qemu_thread_start (args=0x2aa2b2e7980) at ../../util/qemu-thread-posix.c:556 #5 0x000003ff9a187e66 in start_thread (arg=0x3ff8a821900) at pthread_create.c:477 #6 0x000003ff9a07cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 2 (Thread 0x3ff8b1a4900 (LWP 456196)): #0 syscall () at ../sysdeps/unix/sysv/linux/s390/s390-64/syscall.S:37 #1 0x000002aa2923db52 in qemu_futex_wait (f=0x2aa29c14244 <rcu_call_ready_event>, val=4294967295) at /home/linux1/qemu/include/qemu/futex.h:29 #2 0x000002aa2923ddf6 in qemu_event_wait (ev=0x2aa29c14244 <rcu_call_ready_event>) at ../../util/qemu-thread-posix.c:481 #3 0x000002aa2924cbd2 in call_rcu_thread (opaque=0x0) at ../../util/rcu.c:261 #4 0x000002aa2923e020 in qemu_thread_start (args=0x2aa2b26ac90) at ../../util/qemu-thread-posix.c:556 #5 0x000003ff9a187e66 in start_thread (arg=0x3ff8b1a4900) at pthread_create.c:477 #6 0x000003ff9a07cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 1 (Thread 0x3ff9d5fe440 (LWP 456194)): #0 0x000003ff9a071c9c in __ppoll (fds=0x2aa2c46c2f0, nfds=5, timeout=<optimized out>, sigmask=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:44 #1 0x000002aa2927a3e4 in qemu_poll_ns (fds=0x2aa2c46c2f0, nfds=5, timeout=27206167) at ../../util/qemu-timer.c:348 #2 0x000002aa29272280 in os_host_main_loop_wait (timeout=27206167) at ../../util/main-loop.c:250 #3 0x000002aa29272434 in main_loop_wait (nonblocking=0) at ../../util/main-loop.c:531 #4 0x000002aa28901276 in qemu_main_loop () at ../../softmmu/runstate.c:727 #5 0x000002aa2887d2ce in main (argc=25, argv=0x3fff647eac8, envp=0x3fff647eb98) at ../../softmmu/main.c:50 [Inferior 1 (process 456194) detached] =========================================================== PROCESS: 456200 linux1 456200 455775 0 14:39 pts/0 00:00:00 [qemu-system-i38] <defunct> /proc/456200/exe: No such file or directory. Could not attach to process. If your uid matches the uid of the target process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try again as the root user. For more details, see /etc/sysctl.d/10-ptrace.conf warning: process 456200 is a zombie - the process has already terminated ptrace: Operation not permitted. /home/linux1/456200: No such file or directory. =========================================================== PROCESS: 456266 linux1 456266 455775 0 14:39 pts/0 00:00:00 ./qemu-system-i386 -qtest unix:/tmp/qtest-455775.sock -qtest-log /dev/null -chardev socket,path=/tmp/qtest-455775.qmp,id=char0 -mon chardev=char0,mode=control -display none -accel kvm -accel tcg -name target,debug-threads=on -m 150M -serial file:/tmp/migration-test-dmqzpM/dest_serial -incoming defer -drive file=/tmp/migration-test-dmqzpM/bootsect,format=raw -accel qtest [New LWP 456268] [New LWP 456269] [New LWP 456270] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/s390x-linux-gnu/libthread_db.so.1". 0x000003ff9a271c9c in __ppoll (fds=0x2aa0435eb40, nfds=6, timeout=<optimized out>, sigmask=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:44 44 ../sysdeps/unix/sysv/linux/ppoll.c: No such file or directory. Thread 4 (Thread 0x3ff8a12f900 (LWP 456270)): #0 futex_wait_cancelable (private=0, expected=0, futex_word=0x2aa0459cbac) at ../sysdeps/nptl/futex-internal.h:183 #1 __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x2aa02ddec88 <qemu_global_mutex>, cond=0x2aa0459cb80) at pthread_cond_wait.c:508 #2 __pthread_cond_wait (cond=0x2aa0459cb80, mutex=0x2aa02ddec88 <qemu_global_mutex>) at pthread_cond_wait.c:638 #3 0x000002aa0243d498 in qemu_cond_wait_impl (cond=0x2aa0459cb80, mutex=0x2aa02ddec88 <qemu_global_mutex>, file=0x2aa024e81e8 "../../softmmu/cpus.c", line=424) at ../../util/qemu-thread-posix.c:195 #4 0x000002aa01af4cc0 in qemu_wait_io_event (cpu=0x2aa0457d750) at ../../softmmu/cpus.c:424 #5 0x000002aa02172028 in mttcg_cpu_thread_fn (arg=0x2aa0457d750) at ../../accel/tcg/tcg-accel-ops-mttcg.c:124 #6 0x000002aa0243e020 in qemu_thread_start (args=0x2aa0459cbc0) at ../../util/qemu-thread-posix.c:556 #7 0x000003ff9a387e66 in start_thread (arg=0x3ff8a12f900) at pthread_create.c:477 #8 0x000003ff9a27cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 3 (Thread 0x3ff8aa21900 (LWP 456269)): #0 0x000003ff9a271b42 in __GI___poll (fds=0x3fefc003280, nfds=3, timeout=<optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:29 #1 0x000003ff9c9d4386 in () at /lib/s390x-linux-gnu/libglib-2.0.so.0 #2 0x000003ff9c9d4790 in g_main_loop_run () at /lib/s390x-linux-gnu/libglib-2.0.so.0 #3 0x000002aa021d9d56 in iothread_run (opaque=0x2aa042ca750) at ../../iothread.c:73 #4 0x000002aa0243e020 in qemu_thread_start (args=0x2aa04278980) at ../../util/qemu-thread-posix.c:556 #5 0x000003ff9a387e66 in start_thread (arg=0x3ff8aa21900) at pthread_create.c:477 #6 0x000003ff9a27cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 2 (Thread 0x3ff8b3a4900 (LWP 456268)): #0 syscall () at ../sysdeps/unix/sysv/linux/s390/s390-64/syscall.S:37 #1 0x000002aa0243db52 in qemu_futex_wait (f=0x2aa02e14244 <rcu_call_ready_event>, val=4294967295) at /home/linux1/qemu/include/qemu/futex.h:29 #2 0x000002aa0243ddf6 in qemu_event_wait (ev=0x2aa02e14244 <rcu_call_ready_event>) at ../../util/qemu-thread-posix.c:481 #3 0x000002aa0244cbd2 in call_rcu_thread (opaque=0x0) at ../../util/rcu.c:261 #4 0x000002aa0243e020 in qemu_thread_start (args=0x2aa041fbc90) at ../../util/qemu-thread-posix.c:556 #5 0x000003ff9a387e66 in start_thread (arg=0x3ff8b3a4900) at pthread_create.c:477 #6 0x000003ff9a27cbf6 in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65 Thread 1 (Thread 0x3ff9d7fe440 (LWP 456266)): #0 0x000003ff9a271c9c in __ppoll (fds=0x2aa0435eb40, nfds=6, timeout=<optimized out>, sigmask=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:44 #1 0x000002aa0247a3e4 in qemu_poll_ns (fds=0x2aa0435eb40, nfds=6, timeout=1000000000) at ../../util/qemu-timer.c:348 #2 0x000002aa02472280 in os_host_main_loop_wait (timeout=1000000000) at ../../util/main-loop.c:250 #3 0x000002aa02472434 in main_loop_wait (nonblocking=0) at ../../util/main-loop.c:531 #4 0x000002aa01b01276 in qemu_main_loop () at ../../softmmu/runstate.c:727 #5 0x000002aa01a7d2ce in main (argc=27, argv=0x3ffe38fe7e8, envp=0x3ffe38fe8c8) at ../../softmmu/main.c:50 [Inferior 1 (process 456266) detached] thanks -- PMM