Re: [Qemu-devel] [Bug 1706296] [NEW] Booting NT 4 disk causes /home/rjones/d/qemu/cpus.c:1580:qemu_mutex_lock_iothread: assertion failed: (!qemu_mutex_iothread_locked())

[Alex Bennée]

Thomas Huth <address@hidden> writes:

> On 25.07.2017 11:30, Richard Jones wrote:
>> ERROR:/home/rjones/d/qemu/cpus.c:1580:qemu_mutex_lock_iothread: assertion 
>> failed: (!qemu_mutex_iothread_locked())
>> Aborted (core dumped)
>>
>> The stack trace in the failing thread is:
>>
>> Thread 4 (Thread 0x7fffb0418700 (LWP 21979)):
>> #0  0x00007fffdd89b64b in raise () at /lib64/libc.so.6
>> #1  0x00007fffdd89d450 in abort () at /lib64/libc.so.6
>> #2  0x00007fffdff8c75d in g_assertion_message () at /lib64/libglib-2.0.so.0
>> #3  0x00007fffdff8c7ea in g_assertion_message_expr ()
>>     at /lib64/libglib-2.0.so.0
>> #4  0x00005555557a7d00 in qemu_mutex_lock_iothread ()
>>     at /home/rjones/d/qemu/cpus.c:1580
>> #5  0x00005555557cb429 in io_writex (address@hidden, 
>> iotlbentry=0x55555675b678,
>>     address@hidden, address@hidden, address@hidden, retaddr=0, 
>> address@hidden, address@hidden)
>>     at /home/rjones/d/qemu/accel/tcg/cputlb.c:795
>> #6  0x00005555557ce0f7 in io_writel (retaddr=93825011136120, 
>> addr=2148532220, val=8, index=255, mmu_idx=21845, env=0x555556751400)
>>     at /home/rjones/d/qemu/softmmu_template.h:265
>> #7  0x00005555557ce0f7 in helper_le_stl_mmu (address@hidden, address@hidden, 
>> address@hidden, oi=<optimized out>, retaddr=93825011136120, address@hidden) 
>> at /home/rjones/d/qemu/softmmu_template.h:300
>> #8  0x000055555587c0a4 in cpu_stl_kernel_ra (env=0x555556751400, 
>> ptr=2148532220, v=8, retaddr=0) at 
>> /home/rjones/d/qemu/include/exec/cpu_ldst_template.h:182
>> #9  0x0000555555882610 in do_interrupt_protected (is_hw=<optimized
>> out>, next_eip=<optimized out>, error_code=2, is_int=<optimized out>,
>> intno=<optimized out>, env=0x555556751400) at
>> /home/rjones/d/qemu/target/i386/seg_helper.c:758

Erm, what is happening here? I think the seg_helper is writing a stack
frame but for some reason to io memory, triggering the BQL. This just
seems weird.

>> #10 0x0000555555882610 in do_interrupt_all (address@hidden, intno=<optimized 
>> out>, is_int=<optimized out>, error_code=2, next_eip=<optimized out>, 
>> address@hidden) at /home/rjones/d/qemu/target/i386/seg_helper.c:1252
>> #11 0x00005555558839d3 in x86_cpu_do_interrupt (cs=0x555556749170)
>>     at /home/rjones/d/qemu/target/i386/seg_helper.c:1298
>> #12 0x00005555557d2ccb in cpu_handle_exception (ret=<synthetic pointer>, 
>> cpu=0x5555566a4590) at /home/rjones/d/qemu/accel/tcg/cpu-exec.c:465
>> #13 0x00005555557d2ccb in cpu_exec (address@hidden)
>>     at /home/rjones/d/qemu/accel/tcg/cpu-exec.c:670
>> #14 0x00005555557a855a in tcg_cpu_exec (cpu=0x555556749170)
>>     at /home/rjones/d/qemu/cpus.c:1270
>> #15 0x00005555557a855a in qemu_tcg_rr_cpu_thread_fn (arg=<optimized out>)
>>     at /home/rjones/d/qemu/cpus.c:1365
>> #16 0x00007fffddc3d36d in start_thread () at /lib64/libpthread.so.0
>> #17 0x00007fffdd975b9f in clone () at /lib64/libc.so.6
>
> Looks like the iothread lock is taken twice here, one time in
> accel/tcg/cpu-exec.c around line 465 and one time in
> accel/tcg/cputlb.c:795 again.
>
> If I've get that right, the locks have been added by this commit here:
>
>  8d04fb55dec381bc5105cb47f29d918e579e8cbd
>  tcg: drop global lock during TCG code execution
>
> so this looks related to the MTTCG reworks that happened recently. I
> hope one of the MTTCG gurus has some spare time to look at this...

I think I really need an x86 guru to explain what just happened.

--
Alex Bennée