On 10/10/20 12:50 PM, Claudio Fontana wrote:
> On 10/9/20 6:01 PM, Paolo Bonzini wrote:
>> On 09/10/20 17:21, Claudio Fontana wrote:
>>> it seems that ide-test depends on TCG currently.
>>>
>>> Signed-off-by: Claudio Fontana <cfont...@suse.de>
>>> ---
>>> tests/qtest/meson.build | 2 +-
>>> 1 file changed, 1 insertion(+), 1 deletion(-)
>>>
>>> diff --git a/tests/qtest/meson.build b/tests/qtest/meson.build
>>> index ad33ac311d..3418f65e2a 100644
>>> --- a/tests/qtest/meson.build
>>> +++ b/tests/qtest/meson.build
>>> @@ -46,9 +46,9 @@ qtests_i386 = \
>>> (config_all_devices.has_key('CONFIG_TPM_TIS_ISA') ? ['tpm-tis-test'] :
>>> []) + \
>>> (config_all_devices.has_key('CONFIG_TPM_TIS_ISA') ?
>>> ['tpm-tis-swtpm-test'] : []) + \
>>> (config_all_devices.has_key('CONFIG_RTL8139_PCI') ? ['rtl8139-test'] :
>>> []) + \
>>> + (config_all.has_key('CONFIG_TCG') ? ['ide-test'] : []) +
>>> \
>>> qtests_pci +
>>> \
>>> ['fdc-test',
>>> - 'ide-test',
>>> 'hd-geo-test',
>>> 'boot-order-test',
>>> 'bios-tables-test',
>>>
>>
>> Interesting, why?...
>>
>> Paolo
>>
>>
>
> I am slowly trying to find out. I found out that the qos-test that buzzes is
> ide-test,
> and I found out which specific ide test it was by manually bisecting
> functions inside the qtest_add_func in ide-test.c.
>
> The issue seems limited to qtest_add_func("/ide/bmdma/trim", test_bmdma_trim);
> No idea yet why that test buzzes forever.
>
> Side note, maybe more verbose output on which specific test is attempted
> could be helpful? maybe only enabled on make V=2 ?
>
> So the buzz.
> top says:
>
> 22621 claudio 20 0 89700 3292 3004 R 53.82 0.010 1:22.43 ide-test
>
> 22844 claudio 20 0 1026700 61168 38632 R 99.67 0.188 2:39.53
> qemu-system-i38
> 25325 claudio 20 0 89700 3208 2940 R 52.16 0.010 0:56.05 ide-test
>
> 25403 claudio 20 0 1026720 63028 38416 R 99.67 0.194 1:48.63
> qemu-system-x86
>
>
> i386 and x86_64 seem to show the exact same behaviour.
>
>
> gdb says:
>
> qemu-system-x86 (25403):
>
> (gdb) info threads
> Id Target Id Frame
> * 1 Thread 0x7fe35a406140 (LWP 25403) "qemu-system-x86" 0x00007fe35157f7d6
> in ppoll () from /lib64/libc.so.6
> 2 Thread 0x7fe33946e700 (LWP 25415) "qemu-system-x86" 0x00007fe351584839
> in syscall () from /lib64/libc.so.6
> 3 Thread 0x7fe338c6d700 (LWP 25439) "qemu-system-x86" 0x00007fe35157f6db
> in poll () from /lib64/libc.so.6
> 4 Thread 0x7fe333fff700 (LWP 25440) "qemu-system-x86" 0x00007fe35185bdcf
> in do_sigwait () from /lib64/libpthread.so.0
>
> (gdb) thread 1
> [Switching to thread 1 (Thread 0x7fe35a406140 (LWP 25403))]
> #0 0x00007fe35157f7d6 in ppoll () from /lib64/libc.so.6
> (gdb) bt
> #0 0x00007fe35157f7d6 in ppoll () at /lib64/libc.so.6
> #1 0x000055a1f3138309 in ppoll (__ss=0x0, __timeout=0x7fff64d10b70,
> __nfds=<optimized out>, __fds=<optimized out>)
> at /usr/include/bits/poll2.h:77
> #2 0x000055a1f3138309 in qemu_poll_ns (fds=<optimized out>, nfds=<optimized
> out>, timeout=timeout@entry=27462700)
> at ../util/qemu-timer.c:349
> #3 0x000055a1f31512a5 in os_host_main_loop_wait (timeout=27462700) at
> ../util/main-loop.c:239
> #4 0x000055a1f31512a5 in main_loop_wait (nonblocking=nonblocking@entry=0) at
> ../util/main-loop.c:520
> #5 0x000055a1f2fc4bbd in qemu_main_loop () at ../softmmu/vl.c:1677
> #6 0x000055a1f2d001fe in main (argc=<optimized out>, argv=<optimized out>,
> envp=<optimized out>) at ../softmmu/main.c:50
>
> (gdb) thread 2
> [Switching to thread 2 (Thread 0x7fe33946e700 (LWP 25415))]
> #0 0x00007fe351584839 in syscall () from /lib64/libc.so.6
> (gdb) bt
> #0 0x00007fe351584839 in syscall () at /lib64/libc.so.6
> #1 0x000055a1f312605b in qemu_futex_wait (val=<optimized out>, f=<optimized
> out>)
> at /home/claudio/git/qemu-pristine/qemu/include/qemu/futex.h:29
> #2 0x000055a1f312605b in qemu_event_wait (ev=ev@entry=0x55a1f3a44208
> <rcu_call_ready_event>) at ../util/qemu-thread-posix.c:460
> #3 0x000055a1f314f868 in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../util/rcu.c:258
> #4 0x000055a1f3125276 in qemu_thread_start (args=<optimized out>) at
> ../util/qemu-thread-posix.c:521
> #5 0x00007fe3518514f9 in start_thread () at /lib64/libpthread.so.0
> #6 0x00007fe351589fbf in clone () at /lib64/libc.so.6
> (gdb) frame 3
> #3 0x000055a1f314f868 in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../util/rcu.c:258
> 258 qemu_event_wait(&rcu_call_ready_event);
> (gdb) list 258
> 253 n = qatomic_read(&rcu_call_count);
> 254 if (n == 0) {
> 255 #if defined(CONFIG_MALLOC_TRIM)
> 256 malloc_trim(4 * 1024 * 1024);
> 257 #endif
> 258 qemu_event_wait(&rcu_call_ready_event);
> 259 }
> 260 }
> 261 n = qatomic_read(&rcu_call_count);
> 262 }
>
>
> (gdb) thread 3
> [Switching to thread 3 (Thread 0x7fe338c6d700 (LWP 25439))]
> #0 0x00007fe35157f6db in poll () from /lib64/libc.so.6
> (gdb) bt
> #0 0x00007fe35157f6db in poll () at /lib64/libc.so.6
> #1 0x00007fe357087779 in () at /usr/lib64/libglib-2.0.so.0
> #2 0x00007fe357087ac2 in g_main_loop_run () at /usr/lib64/libglib-2.0.so.0
> #3 0x000055a1f2dc1c51 in iothread_run (opaque=opaque@entry=0x55a1f4b20250)
> at ../iothread.c:80
> #4 0x000055a1f3125276 in qemu_thread_start (args=<optimized out>) at
> ../util/qemu-thread-posix.c:521
> #5 0x00007fe3518514f9 in start_thread () at /lib64/libpthread.so.0
> #6 0x00007fe351589fbf in clone () at /lib64/libc.so.6
> (gdb) frame 3
> #3 0x000055a1f2dc1c51 in iothread_run (opaque=opaque@entry=0x55a1f4b20250)
> at ../iothread.c:80
> 80 g_main_loop_run(iothread->main_loop);
> (gdb) list 80
> 75 /*
> 76 * We must check the running state again in case it was
> 77 * changed in previous aio_poll()
> 78 */
> 79 if (iothread->running &&
> qatomic_read(&iothread->run_gcontext)) {
> 80 g_main_loop_run(iothread->main_loop);
> 81 }
> 82 }
> 83
>
>
> (gdb) thread 4
> [Switching to thread 4 (Thread 0x7fe333fff700 (LWP 25440))]
> #0 0x00007fe35185bdcf in do_sigwait () from /lib64/libpthread.so.0
> (gdb) bt
> #0 0x00007fe35185bdcf in do_sigwait () at /lib64/libpthread.so.0
> #1 0x00007fe35185be5d in sigwait () at /lib64/libpthread.so.0
> #2 0x000055a1f2fd0543 in qtest_cpu_thread_fn (arg=arg@entry=0x55a1f4e84be0)
> at ../accel/qtest/qtest-cpus.c:59
> #3 0x000055a1f3125276 in qemu_thread_start (args=<optimized out>) at
> ../util/qemu-thread-posix.c:521
> #4 0x00007fe3518514f9 in start_thread () at /lib64/libpthread.so.0
> #5 0x00007fe351589fbf in clone () at /lib64/libc.so.6
>
> (gdb) list qtest_cpu_thread_fn
> 26 #include "hw/core/cpu.h"
> 27
> 28 #include "qtest-cpus.h"
> 29
> 30 static void *qtest_cpu_thread_fn(void *arg)
> 31 {
> 32 #ifdef _WIN32
> 33 error_report("qtest is not supported under Windows");
> 34 exit(1);
> 35 #else
> 36 CPUState *cpu = arg;
> 37 sigset_t waitset;
> 38 int r;
> 39
> 40 rcu_register_thread();
> 41
> 42 qemu_mutex_lock_iothread();
> 43 qemu_thread_get_self(cpu->thread);
> 44 cpu->thread_id = qemu_get_thread_id();
> 45 cpu->can_do_io = 1;
> 46 current_cpu = cpu;
> 47
> 48 sigemptyset(&waitset);
> 49 sigaddset(&waitset, SIG_IPI);
> 50
> 51 /* signal CPU creation */
> 52 cpu_thread_signal_created(cpu);
> 53 qemu_guest_random_seed_thread_part2(cpu->random_seed);
> 54
> 55 do {
> 56 qemu_mutex_unlock_iothread();
> 57 do {
> 58 int sig;
> 59 r = sigwait(&waitset, &sig);
> 60 } while (r == -1 && (errno == EAGAIN || errno == EINTR));
> 61 if (r == -1) {
> 62 perror("sigwait");
> 63 exit(1);
> 64 }
> 65 qemu_mutex_lock_iothread();
> 66 qemu_wait_io_event(cpu);
> 67 } while (!cpu->unplug);
> 68
> 69 qemu_mutex_unlock_iothread();
> 70 rcu_unregister_thread();
> 71 return NULL;
> 72 #endif
> 73 }
> 74
>
> ----
>
> ide-test (25325):
>
> (gdb) thread 1
> [Switching to thread 1 (Thread 0x7fdce50b81c0 (LWP 25325))]
> #0 0x00007fdce4651deb in write () from /lib64/libpthread.so.0
> (gdb) bt
> #0 0x00007fdce4651deb in write () from /lib64/libpthread.so.0
> #1 0x000055dc0150a3a7 in socket_send (fd=5, buf=0x55dc036b4bd0 "inb
> 0xc012\n", size=11) at ../tests/qtest/libqtest.c:400
> #2 0x000055dc0150a73b in qtest_sendf (s=s@entry=0x55dc036b4ca0,
> fmt=fmt@entry=0x55dc015377e3 "%s 0x%x\n") at ../tests/qtest/libqtest.c:424
> #3 0x000055dc0150aeea in qtest_in (s=0x55dc036b4ca0, cmd=<optimized out>,
> addr=<optimized out>) at ../tests/qtest/libqtest.c:929
> #4 0x000055dc0150c613 in qtest_inb (s=<optimized out>, addr=<optimized out>)
> at ../tests/qtest/libqtest.c:940
> #5 0x000055dc0150ef08 in qpci_io_readb (dev=<optimized out>, token=...,
> off=<optimized out>) at ../tests/qtest/libqos/pci.c:283
> #6 0x000055dc015079c2 in send_dma_request (qts=0x55dc036b4ca0,
> cmd=<optimized out>, sector=0, nb_sectors=1, prdt=<optimized out>,
> prdt_entries=<optimized out>, post_exec=0x0) at
> ../tests/qtest/ide-test.c:283
> #7 0x000055dc0150839c in test_bmdma_trim () at ../tests/qtest/ide-test.c:426
> #8 0x00007fdce4c11826 in ?? () from /usr/lib64/libglib-2.0.so.0
> #9 0x00007fdce4c1173b in ?? () from /usr/lib64/libglib-2.0.so.0
> #10 0x00007fdce4c1173b in ?? () from /usr/lib64/libglib-2.0.so.0
> #11 0x00007fdce4c1173b in ?? () from /usr/lib64/libglib-2.0.so.0
> #12 0x00007fdce4c11ce2 in g_test_run_suite () from /usr/lib64/libglib-2.0.so.0
> #13 0x00007fdce4c11d01 in g_test_run () from /usr/lib64/libglib-2.0.so.0
> #14 0x000055dc01506da6 in main (argc=<optimized out>, argv=<optimized out>)
> at ../tests/qtest/ide-test.c:1059
>
> (gdb) thread 2
> [Switching to thread 2 (Thread 0x7fdce3ff9700 (LWP 25327))]
> #0 0x00007fdce437b839 in syscall () from /lib64/libc.so.6
> (gdb) bt
> #0 0x00007fdce437b839 in syscall () from /lib64/libc.so.6
> #1 0x000055dc01528b1b in qemu_futex_wait (val=<optimized out>, f=<optimized
> out>)
> at /home/claudio/git/qemu-pristine/qemu/include/qemu/futex.h:29
> #2 qemu_event_wait (ev=ev@entry=0x55dc017566e8 <rcu_call_ready_event>) at
> ../util/qemu-thread-posix.c:460
> #3 0x000055dc01525c88 in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../util/rcu.c:258
> #4 0x000055dc01527d36 in qemu_thread_start (args=<optimized out>) at
> ../util/qemu-thread-posix.c:521
> #5 0x00007fdce46484f9 in start_thread () from /lib64/libpthread.so.0
> #6 0x00007fdce4380fbf in clone () from /lib64/libc.so.6
>
> ----
>
> ide-test (22621):
>
> (gdb) bt
> #0 0x00007f4f9b723e88 in read () from /lib64/libpthread.so.0
> #1 0x00005573ffafb512 in read (__nbytes=1024, __buf=0x7ffdd0be3bf0,
> __fd=<optimized out>) at /usr/include/bits/unistd.h:44
> #2 qtest_client_socket_recv_line (s=0x55740104fca0) at
> ../tests/qtest/libqtest.c:472
> #3 0x00005573ffafb7b1 in qtest_rsp (s=s@entry=0x55740104fca0,
> expected_args=expected_args@entry=2) at ../tests/qtest/libqtest.c:499
> #4 0x00005573ffafbef7 in qtest_in (s=0x55740104fca0, cmd=<optimized out>,
> addr=<optimized out>) at ../tests/qtest/libqtest.c:930
> #5 0x00005573ffafd613 in qtest_inb (s=<optimized out>, addr=<optimized out>)
> at ../tests/qtest/libqtest.c:940
> #6 0x00005573ffafff08 in qpci_io_readb (dev=<optimized out>, token=...,
> off=<optimized out>) at ../tests/qtest/libqos/pci.c:283
> #7 0x00005573ffaf89c2 in send_dma_request (qts=0x55740104fca0,
> cmd=<optimized out>, sector=0, nb_sectors=1, prdt=<optimized out>,
> prdt_entries=<optimized out>, post_exec=0x0) at
> ../tests/qtest/ide-test.c:283
> #8 0x00005573ffaf939c in test_bmdma_trim () at ../tests/qtest/ide-test.c:426
> #9 0x00007f4f9bce3826 in ?? () from /usr/lib64/libglib-2.0.so.0
> #10 0x00007f4f9bce373b in ?? () from /usr/lib64/libglib-2.0.so.0
> #11 0x00007f4f9bce373b in ?? () from /usr/lib64/libglib-2.0.so.0
> #12 0x00007f4f9bce373b in ?? () from /usr/lib64/libglib-2.0.so.0
> #13 0x00007f4f9bce3ce2 in g_test_run_suite () from /usr/lib64/libglib-2.0.so.0
> #14 0x00007f4f9bce3d01 in g_test_run () from /usr/lib64/libglib-2.0.so.0
> #15 0x00005573ffaf7da6 in main (argc=<optimized out>, argv=<optimized out>)
> at ../tests/qtest/ide-test.c:1059
>
> (gdb) thread 2
> [Switching to thread 2 (Thread 0x7f4f9b0cb700 (LWP 22625))]
> #0 0x00007f4f9b44d839 in syscall () from /lib64/libc.so.6
> (gdb) bt
> #0 0x00007f4f9b44d839 in syscall () from /lib64/libc.so.6
> #1 0x00005573ffb19b1b in qemu_futex_wait (val=<optimized out>, f=<optimized
> out>)
> at /home/claudio/git/qemu-pristine/qemu/include/qemu/futex.h:29
> #2 qemu_event_wait (ev=ev@entry=0x5573ffd476e8 <rcu_call_ready_event>) at
> ../util/qemu-thread-posix.c:460
> #3 0x00005573ffb16c88 in call_rcu_thread (opaque=opaque@entry=0x0) at
> ../util/rcu.c:258
> #4 0x00005573ffb18d36 in qemu_thread_start (args=<optimized out>) at
> ../util/qemu-thread-posix.c:521
> #5 0x00007f4f9b71a4f9 in start_thread () from /lib64/libpthread.so.0
> #6 0x00007f4f9b452fbf in clone () from /lib64/libc.so.6
>
> This send_dma_request seems to never end but why..?
>
> Ciao,
>
> Claudio
>
The problem stems from replay changes, in this case it is
replay_bh_schedule_event.
The function tests for events_enabled presence inside the implementation, and
only if replay events is not enabled it forwards stuff to qemu_bh_schedule().
This is done for other events, including
replay_bh_schedule_event
replay_bh_schedule_oneshot_event
replay_block_event
files like block/blkreplay.c and others should also be made conditional on TCG.
I'll try to sort out this and propose a patch.
Ciao,
Claudio
