[Qemu-devel] Help with deadlock when using sound

[Qemu-devel] Help with deadlock when using sound

[Programmingkid]

When I try to use the pcspk sound hardware, QEMU freezes and uses 100% of the cpu time. This is the command I use:

qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk

This looks like a deadlock situation because some unknown code called qemu_mutex_lock(). Here is the stack trace at the freeze:

(gdb) bt
#0  0x00007fff824e2db6 in semaphore_wait_trap ()
#1  0x00007fff824e8417 in pthread_mutex_lock ()
#2  0x0000000100267199 in qemu_mutex_lock (mutex=<value temporarily unavailable, due to optimizations>) at util/qemu-thread-posix.c:73
#3  0x003c44016e95153b in ?? ()

My host is Mac OS 10.6.8. My guest isn't really anything. I have used Windows XP before but it isn't necessary to reproduce the problem. 

The ?? is what appears to be the problem. I can't even print instructions at that address. Any ideas as to what is calling the qemu_mutex_lock() function could help.

Re: [Qemu-devel] Help with deadlock when using sound

[Peter Maydell]

On 6 May 2015 at 17:40, Programmingkid <programmingkidx@gmail.com> wrote:
> (gdb) bt
> #0  0x00007fff824e2db6 in semaphore_wait_trap ()
> #1  0x00007fff824e8417 in pthread_mutex_lock ()
> #2  0x0000000100267199 in qemu_mutex_lock (mutex=<value temporarily unavailable, due to optimizations>) at util/qemu-thread-posix.c:73
> #3  0x003c44016e95153b in ?? ()
>
> My host is Mac OS 10.6.8. My guest isn't really anything. I have used Windows XP before but it isn't necessary to reproduce the problem.
>
> The ?? is what appears to be the problem. I can't even print instructions at that address. Any ideas as to what is calling the qemu_mutex_lock() function could help.

Recompile with optimization disabled and try again. It would
also be helpful to provide the backtraces for all threads.

thanks
-- PMM

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 6, 2015, at 1:00 PM, Peter Maydell wrote:

> On 6 May 2015 at 17:40, Programmingkid <programmingkidx@gmail.com> wrote:
>> (gdb) bt
>> #0  0x00007fff824e2db6 in semaphore_wait_trap ()
>> #1  0x00007fff824e8417 in pthread_mutex_lock ()
>> #2  0x0000000100267199 in qemu_mutex_lock (mutex=<value temporarily unavailable, due to optimizations>) at util/qemu-thread-posix.c:73
>> #3  0x003c44016e95153b in ?? ()
>> 
>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used Windows XP before but it isn't necessary to reproduce the problem.
>> 
>> The ?? is what appears to be the problem. I can't even print instructions at that address. Any ideas as to what is calling the qemu_mutex_lock() function could help.
> 
> Recompile with optimization disabled and try again. It would
> also be helpful to provide the backtraces for all threads.

Here is my info:

Configured like this:
configure --target-list=ppc-softmmu,i386-softmmu --disable-gtk --audio-drv-list=sdl --enable-debug

Ran like this:
qemu-system-i386 -soundhw pcspk -cdrom <cd image file>

The cd image file does not matter, since QEMU freezes so quickly in the boot process.

This freeze issue also happens when using the coreaudio.

Where all the threads stopped at:

11                                0x00007fff824fca2a in __workq_kernreturn ()
  10                                 0x00007fff8251da6a in __semwait_signal ()
  8                                 tb_jmp_cache_hash_func (pc=1) at exec/exec-all.h:208
  6                                 0x00007fff8254499e in __sigwait ()
  3 "com.apple.libdispatch-manager" 0x00007fff824fbc0a in kevent ()
  2                                 0x00007fff8251da6a in __semwait_signal ()
* 1 "com.apple.main-thread"         0x00007fff824e2dc2 in semaphore_wait_signal_


Full backtrace of all threads:

Thread 11 (process 29237):
#0  0x00007fff824fca2a in __workq_kernreturn ()
#1  0x00007fff824fce3c in _pthread_wqthread ()
#2  0x00007fff824fcaa5 in start_wqthread ()

Thread 10 (process 29237):
#0  0x00007fff8251da6a in __semwait_signal ()
#1  0x00007fff82521881 in _pthread_cond_wait ()
#2  0x00000001010602ce in SDL_CondWaitTimeout ()
#3  0x000000010105ffbf in SDL_SemWaitTimeout ()
#4  0x000000010013b3e4 in sdl_wait (s=0x10062ba80, forfn=0x1003a68e2 "sdl_callback") at audio/sdlaudio.c:101
#5  0x000000010013b7cf in sdl_callback (opaque=0x122a5d410, buf=0x10385d600 "", len=4096) at audio/sdlaudio.c:247
#6  0x000000010106084f in audioCallback ()
#7  0x0000000122c2017a in basic_engine_core_text_type ()
#8  0x0000000122c2023d in basic_engine_core_text_type ()
#9  0x00007fff852ea8b4 in AudioConverterChain::CallInputProc ()
#10 0x00007fff852ea462 in AudioConverterChain::FillBufferFromInputProc ()
#11 0x00007fff852ea3e4 in BufferedAudioConverter::GetInputBytes ()
#12 0x00007fff852ea2a7 in CBRConverter::RenderOutput ()
#13 0x00007fff852ea027 in BufferedAudioConverter::FillBuffer ()
#14 0x00007fff852ea198 in AudioConverterChain::RenderOutput ()
#15 0x00007fff852ea027 in BufferedAudioConverter::FillBuffer ()
#16 0x00007fff852e9da3 in AudioConverterFillComplexBuffer ()
#17 0x0000000122c202f7 in basic_engine_core_text_type ()
#18 0x0000000122c1f95a in basic_engine_core_text_type ()
#19 0x0000000122c1e323 in basic_engine_core_text_type ()
#20 0x0000000122c1d45c in basic_engine_core_text_type ()
#21 0x0000000122c22fd0 in AUGenericOutputEntry ()
#22 0x00007fff8423733d in HP_IOProc::Call ()
#23 0x00007fff8423710f in IOA_Device::CallIOProcs ()
#24 0x00007fff84236f45 in HP_IOThread::PerformIO ()
#25 0x00007fff84234f54 in HP_IOThread::WorkLoop ()
#26 0x00007fff84234827 in HP_IOThread::ThreadEntry ()
#27 0x00007fff84234755 in CAPThread::Entry ()
#28 0x00007fff8251bfd6 in _pthread_start ()
#29 0x00007fff8251be89 in thread_start ()

Thread 8 (process 29237):
#0  tb_jmp_cache_hash_func (pc=1) at exec/exec-all.h:208
#1  0x000000010000c9d7 in tb_find_slow (env=0x103846620, pc=133133655, cs_base=133118944, flags=244) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:309
#2  0x000000010000cae3 in tb_find_fast (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:327
#3  0x000000010000cf66 in cpu_x86_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:485
#4  0x000000010003978b in tcg_cpu_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1354
#5  0x0000000100039878 in tcg_exec_all () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1387
#6  0x0000000100038dec in qemu_tcg_cpu_thread_fn (arg=0x10383e400) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1032
#7  0x00007fff8251bfd6 in _pthread_start ()
#8  0x00007fff8251be89 in thread_start ()

Thread 6 (process 29237):
#0  0x00007fff8254499e in __sigwait ()
#1  0x00007fff82544977 in sigwait ()
#2  0x0000000100373ea0 in sigwait_compat (opaque=0x10297ca70) at util/compatfd.c:36
#3  0x00007fff8251bfd6 in _pthread_start ()
#4  0x00007fff8251be89 in thread_start ()

Thread 3 (process 29237):
#0  0x00007fff824fbc0a in kevent ()
#1  0x00007fff824fdadd in _dispatch_mgr_invoke ()
#2  0x00007fff824fd7b4 in _dispatch_queue_invoke ()
#3  0x00007fff824fd2de in _dispatch_worker_thread2 ()
#4  0x00007fff824fcc08 in _pthread_wqthread ()
#5  0x00007fff824fcaa5 in start_wqthread ()

Thread 2 (process 29237):
#0  0x00007fff8251da6a in __semwait_signal ()
#1  0x00007fff82521881 in _pthread_cond_wait ()
#2  0x000000010036ff9c in futex_wait (ev=0x100a4f880, val=4294967295) at util/qemu-thread-posix.c:319
#3  0x0000000100370116 in qemu_event_wait (ev=0x100a4f880) at util/qemu-thread-posix.c:399
#4  0x0000000100384982 in call_rcu_thread (opaque=0x0) at util/rcu.c:233
#5  0x00007fff8251bfd6 in _pthread_start ()
#6  0x00007fff8251be89 in thread_start ()

Thread 1 (process 29237):
#0  0x00007fff824e2dc2 in semaphore_wait_signal_trap ()
#1  0x00007fff824e840d in pthread_mutex_lock ()
#2  0x000000010036f9fa in qemu_mutex_lock (mutex=0x100630240) at util/qemu-thread-posix.c:73
#3  0x000000010003903a in qemu_mutex_lock_iothread () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1128
#4  0x00000001002d7252 in os_host_main_loop_wait (timeout=911000) at main-loop.c:242
#5  0x00000001002d7317 in main_loop_wait (nonblocking=0) at main-loop.c:494
#6  0x0000000100114038 in main_loop () at vl.c:1799
#7  0x000000010011be99 in qemu_main (argc=5, argv=0x10292ffb0, envp=0x0) at vl.c:4385
#8  0x0000000100111799 in SDL_main (argc=5, argv=0x10292ffb0) at vl.c:47
#9  0x0000000100385400 in -[SDLMain applicationDidFinishLaunching:] (self=0x5fbfe75000000005, _cmd=0x10292ffb0, note=0x0) at SDLMain.m:300
#10 0x00007fff8a50dbc5 in _nsnote_callback ()
#11 0x00007fff83a7b000 in __CFXNotificationPost ()
#12 0x00007fff83a67578 in _CFXNotificationPostNotification ()
#13 0x00007fff8a504b26 in -[NSNotificationCenter postNotificationName:object:userInfo:] ()
#14 0x00007fff80a1c44a in -[NSApplication _postDidFinishNotification] ()
#15 0x00007fff80a1c37f in -[NSApplication _sendFinishLaunchingNotification] ()
#16 0x00007fff80ae735d in -[NSApplication(NSAppleEventHandling) _handleAEOpen:] ()
#17 0x00007fff80ae6fd9 in -[NSApplication(NSAppleEventHandling) _handleCoreEvent:withReplyEvent:] ()
#18 0x00007fff8a53c1c6 in -[NSAppleEventManager dispatchRawAppleEvent:withRawReply:handlerRefCon:] ()
#19 0x00007fff8a53bff6 in _NSAppleEventManagerGenericHandler ()
#20 0x00007fff84a6f32b in aeDispatchAppleEvent ()
#21 0x00007fff84a6f224 in dispatchEventAndSendReply ()
#22 0x00007fff84a6f12b in aeProcessAppleEvent ()
#23 0x00007fff87300619 in AEProcessAppleEvent ()
#24 0x00007fff809ec095 in _DPSNextEvent ()
#25 0x00007fff809eb801 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#26 0x00007fff809b168f in -[NSApplication run] ()
#27 0x0000000100385214 in CustomApplicationMain [inlined] () at :227
#28 0x0000000100385214 in main (argc=43217056, argv=0x102938010) at SDLMain.m:377

Re: [Qemu-devel] Help with deadlock when using sound

[Peter Maydell]

On 6 May 2015 at 20:41, Programmingkid <programmingkidx@gmail.com> wrote:
>
> On May 6, 2015, at 1:00 PM, Peter Maydell wrote:
>
>> On 6 May 2015 at 17:40, Programmingkid <programmingkidx@gmail.com> wrote:
>>> (gdb) bt
>>> #0  0x00007fff824e2db6 in semaphore_wait_trap ()
>>> #1  0x00007fff824e8417 in pthread_mutex_lock ()
>>> #2  0x0000000100267199 in qemu_mutex_lock (mutex=<value temporarily unavailable, due to optimizations>) at util/qemu-thread-posix.c:73
>>> #3  0x003c44016e95153b in ?? ()
>>>
>>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used Windows XP before but it isn't necessary to reproduce the problem.
>>>
>>> The ?? is what appears to be the problem. I can't even print instructions at that address. Any ideas as to what is calling the qemu_mutex_lock() function could help.
>>
>> Recompile with optimization disabled and try again. It would
>> also be helpful to provide the backtraces for all threads.
>
> Here is my info:
>
> Configured like this:
> configure --target-list=ppc-softmmu,i386-softmmu --disable-gtk --audio-drv-list=sdl --enable-debug

Does that work? I would not expect anything other than the
coreaudio backend to necessarily work on OSX... At any rate,
better to start with debugging the issue under coreaudio for
simplicity, since you say it happens there too. Checking
whether it works OK on x86/Linux host would also help
narrow down the possibilities.

> Thread 8 (process 29237):
> #0  tb_jmp_cache_hash_func (pc=1) at exec/exec-all.h:208
> #1  0x000000010000c9d7 in tb_find_slow (env=0x103846620, pc=133133655, cs_base=133118944, flags=244) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:309
> #2  0x000000010000cae3 in tb_find_fast (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:327
> #3  0x000000010000cf66 in cpu_x86_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:485
> #4  0x000000010003978b in tcg_cpu_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1354
> #5  0x0000000100039878 in tcg_exec_all () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1387
> #6  0x0000000100038dec in qemu_tcg_cpu_thread_fn (arg=0x10383e400) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1032
> #7  0x00007fff8251bfd6 in _pthread_start ()
> #8  0x00007fff8251be89 in thread_start ()

This backtrace says QEMU hasn't hung -- it is still executing
guest code (though possibly the guest has crashed or gone off
into the weeds, of course).

-- PMM

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 6, 2015, at 5:10 PM, Peter Maydell wrote:

> On 6 May 2015 at 20:41, Programmingkid <programmingkidx@gmail.com> wrote:
>> 
>> On May 6, 2015, at 1:00 PM, Peter Maydell wrote:
>> 
>>> On 6 May 2015 at 17:40, Programmingkid <programmingkidx@gmail.com> wrote:
>>>> (gdb) bt
>>>> #0  0x00007fff824e2db6 in semaphore_wait_trap ()
>>>> #1  0x00007fff824e8417 in pthread_mutex_lock ()
>>>> #2  0x0000000100267199 in qemu_mutex_lock (mutex=<value temporarily unavailable, due to optimizations>) at util/qemu-thread-posix.c:73
>>>> #3  0x003c44016e95153b in ?? ()
>>>> 
>>>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used Windows XP before but it isn't necessary to reproduce the problem.
>>>> 
>>>> The ?? is what appears to be the problem. I can't even print instructions at that address. Any ideas as to what is calling the qemu_mutex_lock() function could help.
>>> 
>>> Recompile with optimization disabled and try again. It would
>>> also be helpful to provide the backtraces for all threads.
>> 
>> Here is my info:
>> 
>> Configured like this:
>> configure --target-list=ppc-softmmu,i386-softmmu --disable-gtk --audio-drv-list=sdl --enable-debug
> 
> Does that work? I would not expect anything other than the
> coreaudio backend to necessarily work on OSX... At any rate,
> better to start with debugging the issue under coreaudio for
> simplicity, since you say it happens there too. Checking
> whether it works OK on x86/Linux host would also help
> narrow down the possibilities.
Already tried that. Something is wrong with my Linux distro because every time I try to run QEMU, I see a floating point exception. Maybe somebody on the list who does use Linux could let us know if using -soundhw pcspk works. 

> 
>> Thread 8 (process 29237):
>> #0  tb_jmp_cache_hash_func (pc=1) at exec/exec-all.h:208
>> #1  0x000000010000c9d7 in tb_find_slow (env=0x103846620, pc=133133655, cs_base=133118944, flags=244) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:309
>> #2  0x000000010000cae3 in tb_find_fast (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:327
>> #3  0x000000010000cf66 in cpu_x86_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:485
>> #4  0x000000010003978b in tcg_cpu_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1354
>> #5  0x0000000100039878 in tcg_exec_all () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1387
>> #6  0x0000000100038dec in qemu_tcg_cpu_thread_fn (arg=0x10383e400) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1032
>> #7  0x00007fff8251bfd6 in _pthread_start ()
>> #8  0x00007fff8251be89 in thread_start ()
> 
> This backtrace says QEMU hasn't hung -- it is still executing
> guest code (though possibly the guest has crashed or gone off
> into the weeds, of course).

If it were still executing guest code, then accessing the monitor would still work. 

Re: [Qemu-devel] Help with deadlock when using sound

[Peter Maydell]

On 6 May 2015 at 22:19, Programmingkid <programmingkidx@gmail.com> wrote:
>
> On May 6, 2015, at 5:10 PM, Peter Maydell wrote:
>>> Thread 8 (process 29237):
>>> #0  tb_jmp_cache_hash_func (pc=1) at exec/exec-all.h:208
>>> #1  0x000000010000c9d7 in tb_find_slow (env=0x103846620, pc=133133655, cs_base=133118944, flags=244) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:309
>>> #2  0x000000010000cae3 in tb_find_fast (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:327
>>> #3  0x000000010000cf66 in cpu_x86_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:485
>>> #4  0x000000010003978b in tcg_cpu_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1354
>>> #5  0x0000000100039878 in tcg_exec_all () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1387
>>> #6  0x0000000100038dec in qemu_tcg_cpu_thread_fn (arg=0x10383e400) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1032
>>> #7  0x00007fff8251bfd6 in _pthread_start ()
>>> #8  0x00007fff8251be89 in thread_start ()
>>
>> This backtrace says QEMU hasn't hung -- it is still executing
>> guest code (though possibly the guest has crashed or gone off
>> into the weeds, of course).
>
> If it were still executing guest code, then accessing the monitor
> would still work.

Well, that backtrace says we're executing code. We're not stuck
waiting for a lock, we're in the middle of the execution loop
(looking for a TB for PC=0x7ef7557). Your command line hasn't
redirected the monitor to the terminal or to a TCP port, so
possibly it's just that the GUI has got wedged? Try with
'-monitor stdio' and see if that's responsive.

I just tried on OSX and for me there's no hang -- the BIOS
boots normally, fails to find a valid image on the cdrom
and drops into attempting to network-boot, same behaviour
with or without -soundhw pcspk. (I build with coreaudio.)

-- PMM

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 6, 2015, at 5:31 PM, Peter Maydell wrote:

> On 6 May 2015 at 22:19, Programmingkid <programmingkidx@gmail.com> wrote:
>> 
>> On May 6, 2015, at 5:10 PM, Peter Maydell wrote:
>>>> Thread 8 (process 29237):
>>>> #0  tb_jmp_cache_hash_func (pc=1) at exec/exec-all.h:208
>>>> #1  0x000000010000c9d7 in tb_find_slow (env=0x103846620, pc=133133655, cs_base=133118944, flags=244) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:309
>>>> #2  0x000000010000cae3 in tb_find_fast (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:327
>>>> #3  0x000000010000cf66 in cpu_x86_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:485
>>>> #4  0x000000010003978b in tcg_cpu_exec (env=0x103846620) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1354
>>>> #5  0x0000000100039878 in tcg_exec_all () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1387
>>>> #6  0x0000000100038dec in qemu_tcg_cpu_thread_fn (arg=0x10383e400) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1032
>>>> #7  0x00007fff8251bfd6 in _pthread_start ()
>>>> #8  0x00007fff8251be89 in thread_start ()
>>> 
>>> This backtrace says QEMU hasn't hung -- it is still executing
>>> guest code (though possibly the guest has crashed or gone off
>>> into the weeds, of course).
>> 
>> If it were still executing guest code, then accessing the monitor
>> would still work.
> 
> Well, that backtrace says we're executing code. We're not stuck
> waiting for a lock, we're in the middle of the execution loop
> (looking for a TB for PC=0x7ef7557). Your command line hasn't
> redirected the monitor to the terminal or to a TCP port, so
> possibly it's just that the GUI has got wedged? Try with
> '-monitor stdio' and see if that's responsive.
Tried this, still froze.

> I just tried on OSX and for me there's no hang -- the BIOS
> boots normally, fails to find a valid image on the cdrom
> and drops into attempting to network-boot, same behaviour
> with or without -soundhw pcspk. (I build with coreaudio.)
> 
> -- PMM


I did what you did "qemu-system-i386 -soundhw pcspk" and QEMU froze on me with this as the last thing printed on the screen: "Press Ctrl-B for the iPXE command line...". What version of Mac OS X are you trying QEMU on?

Re: [Qemu-devel] Help with deadlock when using sound

[Peter Maydell]

On 6 May 2015 at 22:41, Programmingkid <programmingkidx@gmail.com> wrote:
> I did what you did "qemu-system-i386 -soundhw pcspk" and QEMU froze
> on me with this as the last thing printed on the screen: "Press Ctrl-B
> for the iPXE command line...".

Hmm. Mine definitely gets further than that -- it goes up to
"No bootable devices." with the guest cursor blinking still.

> What version of Mac OS X are you trying QEMU on?

10.10.3 (Yosemite).

-- PMM

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

[-- Attachment #1: Type: text/plain, Size: 5798 bytes --]

Here is the back trace of qemu-system-i386 after it has frozen. This time I used cocoa and coreaudio.

Configuration commands:  	--target-list=ppc-softmmu,i386-softmmu --disable-sdl --disable-gtk --enable-debug

Run commands:   			qemu-system-i386 -cdrom <cd image file>  -soundhw pcspk

My only theory right now has to do with pthread_mutex_init(). When pthread_mutex_init() is called, it is given NULL as an attribute. This means to use the default attributes. The default attribute on Linux and on Mac OS X are probably different. That might be why we see this problem on Mac OS X. The code is found in qemu-thread-posix.c. Here it is:

void qemu_mutex_init(QemuMutex *mutex)
{
    int err;

    err = pthread_mutex_init(&mutex->lock, NULL);
    if (err)
        error_exit(err, __func__);
}


The full back trace:

Thread 10 (process 34926):
#0  0x00007fff824e2dda in semaphore_timedwait_signal_trap ()
#1  0x00007fff82521772 in _pthread_cond_wait ()
#2  0x00007fff8423468c in CAGuard::WaitFor ()
#3  0x00007fff84236c1b in CAGuard::WaitUntil ()
#4  0x00007fff84234d85 in HP_IOThread::WorkLoop ()
#5  0x00007fff84234827 in HP_IOThread::ThreadEntry ()
#6  0x00007fff84234755 in CAPThread::Entry ()
#7  0x00007fff8251bfd6 in _pthread_start ()
#8  0x00007fff8251be89 in thread_start ()

Thread 8 (process 34926):
#0  0x000000010000cae1 in tb_find_fast (env=0x102099820) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:325
#1  0x000000010000cfd6 in cpu_x86_exec (env=0x102099820) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpu-exec.c:485
#2  0x00000001000397fb in tcg_cpu_exec (env=0x102099820) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1354
#3  0x00000001000398e8 in tcg_exec_all () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1387
#4  0x0000000100038e5c in qemu_tcg_cpu_thread_fn (arg=0x102091600) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1032
#5  0x00007fff8251bfd6 in _pthread_start ()
#6  0x00007fff8251be89 in thread_start ()

Thread 7 (process 34926):
#0  0x00007fff8251da6a in __semwait_signal ()
#1  0x00007fff82521881 in _pthread_cond_wait ()
#2  0x000000010036bfb7 in qemu_sem_timedwait (sem=0x101e34cc0, ms=10000) at util/qemu-thread-posix.c:229
#3  0x00000001002c5e3a in worker_thread (opaque=0x101e34c40) at thread-pool.c:92
#4  0x00007fff8251bfd6 in _pthread_start ()
#5  0x00007fff8251be89 in thread_start ()

Thread 6 (process 34926):
#0  0x00007fff8254499e in __sigwait ()
#1  0x00007fff82544977 in sigwait ()
#2  0x0000000100370038 in sigwait_compat (opaque=0x101993ad0) at util/compatfd.c:36
#3  0x00007fff8251bfd6 in _pthread_start ()
#4  0x00007fff8251be89 in thread_start ()

Thread 3 (process 34926):
#0  0x00007fff824fbc0a in kevent ()
#1  0x00007fff824fdadd in _dispatch_mgr_invoke ()
#2  0x00007fff824fd7b4 in _dispatch_queue_invoke ()
#3  0x00007fff824fd2de in _dispatch_worker_thread2 ()
#4  0x00007fff824fcc08 in _pthread_wqthread ()
#5  0x00007fff824fcaa5 in start_wqthread ()

Thread 2 (process 34926):
#0  0x00007fff8251da6a in __semwait_signal ()
#1  0x00007fff82521881 in _pthread_cond_wait ()
#2  0x000000010036c134 in futex_wait (ev=0x100aa14c0, val=4294967295) at util/qemu-thread-posix.c:319
#3  0x000000010036c2ae in qemu_event_wait (ev=0x100aa14c0) at util/qemu-thread-posix.c:399
#4  0x0000000100380b22 in call_rcu_thread (opaque=0x0) at util/rcu.c:233
#5  0x00007fff8251bfd6 in _pthread_start ()
#6  0x00007fff8251be89 in thread_start ()

Thread 1 (process 34926):
#0  0x00007fff824e2dc2 in semaphore_wait_signal_trap ()
#1  0x00007fff824e840d in pthread_mutex_lock ()
#2  0x000000010036bb92 in qemu_mutex_lock (mutex=0x100681f80) at util/qemu-thread-posix.c:73
#3  0x00000001000390aa in qemu_mutex_lock_iothread () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1128
#4  0x00000001002d33ea in os_host_main_loop_wait (timeout=9942000) at main-loop.c:242
#5  0x00000001002d34af in main_loop_wait (nonblocking=0) at main-loop.c:494
#6  0x0000000100114081 in main_loop () at vl.c:1799
#7  0x000000010011bb7e in qemu_main (argc=5, argv=0x7fff5fbff440, envp=0x7fff5fbff470) at vl.c:4385
#8  0x00000001002a46d9 in -[QemuCocoaAppController startEmulationWithArgc:argv:] (self=0x101e007b0, _cmd=0x1003f2e1e, argc=5, argv=0x7fff5fbff440) at cocoa.m:897
#9  0x00000001002a4532 in -[QemuCocoaAppController applicationDidFinishLaunching:] (self=0x101e007b0, _cmd=0x7fff8064d906, note=0x101e32bf0) at cocoa.m:875
#10 0x00007fff8a50dbc5 in _nsnote_callback ()
#11 0x00007fff83a7b000 in __CFXNotificationPost ()
#12 0x00007fff83a67578 in _CFXNotificationPostNotification ()
#13 0x00007fff8a504b26 in -[NSNotificationCenter postNotificationName:object:userInfo:] ()
#14 0x00007fff80a1c44a in -[NSApplication _postDidFinishNotification] ()
#15 0x00007fff80a1c37f in -[NSApplication _sendFinishLaunchingNotification] ()
#16 0x00007fff80ae735d in -[NSApplication(NSAppleEventHandling) _handleAEOpen:] ()
#17 0x00007fff80ae6fd9 in -[NSApplication(NSAppleEventHandling) _handleCoreEvent:withReplyEvent:] ()
#18 0x00007fff8a53c1c6 in -[NSAppleEventManager dispatchRawAppleEvent:withRawReply:handlerRefCon:] ()
#19 0x00007fff8a53bff6 in _NSAppleEventManagerGenericHandler ()
#20 0x00007fff84a6f32b in aeDispatchAppleEvent ()
#21 0x00007fff84a6f224 in dispatchEventAndSendReply ()
#22 0x00007fff84a6f12b in aeProcessAppleEvent ()
#23 0x00007fff87300619 in AEProcessAppleEvent ()
#24 0x00007fff809ec095 in _DPSNextEvent ()
#25 0x00007fff809eb801 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#26 0x00007fff809b168f in -[NSApplication run] ()
#27 0x00000001002a548a in main (argc=5, argv=0x7fff5fbff440) at cocoa.m:1034


[-- Attachment #2: Type: text/html, Size: 8552 bytes --]

Re: [Qemu-devel] Help with deadlock when using sound

[Paolo Bonzini]

On 06/05/2015 18:40, Programmingkid wrote:
> When I try to use the pcspk sound hardware, QEMU freezes and uses
> 100% of the cpu time. This is the command I use:
> 
> qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk
> 
> This looks like a deadlock situation because some unknown code called
> qemu_mutex_lock(). Here is the stack trace at the freeze:
> 
> (gdb) bt #0  0x00007fff824e2db6 in semaphore_wait_trap () #1
> 0x00007fff824e8417 in pthread_mutex_lock () #2  0x0000000100267199 in
> qemu_mutex_lock (mutex=<value temporarily unavailable, due to
> optimizations>) at util/qemu-thread-posix.c:73 #3  0x003c44016e95153b
> in ?? ()
> 
> My host is Mac OS 10.6.8. My guest isn't really anything. I have used
> Windows XP before but it isn't necessary to reproduce the problem.
> 
> The ?? is what appears to be the problem. I can't even print
> instructions at that address. Any ideas as to what is calling the
> qemu_mutex_lock() function could help.

Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
as soon as you type "beep".

It works with the PulseAudio and ALSA backends, but it doesn't with the
SDL backend, even on Linux.

Also, it deadlocks even with KVM enabled.

Paolo

Re: [Qemu-devel] Help with deadlock when using sound

[Paolo Bonzini]

On 10/05/2015 16:54, Paolo Bonzini wrote:
> Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
> as soon as you type "beep".
> 
> It works with the PulseAudio and ALSA backends, but it doesn't with the
> SDL backend, even on Linux.
> 
> Also, it deadlocks even with KVM enabled.

Hmm, looks like SDL audio is broken; it's not pcspk's fault.
I get an instant deadlock from

QEMU_AUDIO_DRV=sdl qemu-system-x86_64 -soundhw gus /mnt/vm/freedos.raw

even if I add "-display sdl", "-monitor stdio", etc.

Paolo

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 10, 2015, at 10:54 AM, Paolo Bonzini wrote:

> 
> 
> On 06/05/2015 18:40, Programmingkid wrote:
>> When I try to use the pcspk sound hardware, QEMU freezes and uses
>> 100% of the cpu time. This is the command I use:
>> 
>> qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk
>> 
>> This looks like a deadlock situation because some unknown code called
>> qemu_mutex_lock(). Here is the stack trace at the freeze:
>> 
>> (gdb) bt #0  0x00007fff824e2db6 in semaphore_wait_trap () #1
>> 0x00007fff824e8417 in pthread_mutex_lock () #2  0x0000000100267199 in
>> qemu_mutex_lock (mutex=<value temporarily unavailable, due to
>> optimizations>) at util/qemu-thread-posix.c:73 #3  0x003c44016e95153b
>> in ?? ()
>> 
>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used
>> Windows XP before but it isn't necessary to reproduce the problem.
>> 
>> The ?? is what appears to be the problem. I can't even print
>> instructions at that address. Any ideas as to what is calling the
>> qemu_mutex_lock() function could help.
> 
> Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
> as soon as you type "beep".
> 
> It works with the PulseAudio and ALSA backends, but it doesn't with the
> SDL backend, even on Linux.
> 
> Also, it deadlocks even with KVM enabled.
> 
> Paolo

Thank you very much for finding this out. Any theories as to what is wrong?

This is my list of theories:
- Compiler bug
- Bug with a dependency 
- Host operating system bug/untrue assumption
- Emulated sound cards not implementing some required functionality
- Missing/broken deadlock prevention code

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 10, 2015, at 10:54 AM, Paolo Bonzini wrote:

> 
> 
> On 06/05/2015 18:40, Programmingkid wrote:
>> When I try to use the pcspk sound hardware, QEMU freezes and uses
>> 100% of the cpu time. This is the command I use:
>> 
>> qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk
>> 
>> This looks like a deadlock situation because some unknown code called
>> qemu_mutex_lock(). Here is the stack trace at the freeze:
>> 
>> (gdb) bt #0  0x00007fff824e2db6 in semaphore_wait_trap () #1
>> 0x00007fff824e8417 in pthread_mutex_lock () #2  0x0000000100267199 in
>> qemu_mutex_lock (mutex=<value temporarily unavailable, due to
>> optimizations>) at util/qemu-thread-posix.c:73 #3  0x003c44016e95153b
>> in ?? ()
>> 
>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used
>> Windows XP before but it isn't necessary to reproduce the problem.
>> 
>> The ?? is what appears to be the problem. I can't even print
>> instructions at that address. Any ideas as to what is calling the
>> qemu_mutex_lock() function could help.
> 
> Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
> as soon as you type "beep".
> 
> It works with the PulseAudio and ALSA backends, but it doesn't with the
> SDL backend, even on Linux.
> 
> Also, it deadlocks even with KVM enabled.
> 
> Paolo

OK, I see a pattern. SDL and CoreAudio both don't support audio input. Both of them have this code:
 .voice_size_in  = 0

Alsa and PulseAudio do support audio input and work. Coincidence?

Re: [Qemu-devel] Help with deadlock when using sound

[Paolo Bonzini]

On 12/05/2015 00:43, Programmingkid wrote:
> 
> On May 10, 2015, at 10:54 AM, Paolo Bonzini wrote:
> 
>>
>>
>> On 06/05/2015 18:40, Programmingkid wrote:
>>> When I try to use the pcspk sound hardware, QEMU freezes and uses
>>> 100% of the cpu time. This is the command I use:
>>>
>>> qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk
>>>
>>> This looks like a deadlock situation because some unknown code called
>>> qemu_mutex_lock(). Here is the stack trace at the freeze:
>>>
>>> (gdb) bt #0  0x00007fff824e2db6 in semaphore_wait_trap () #1
>>> 0x00007fff824e8417 in pthread_mutex_lock () #2  0x0000000100267199 in
>>> qemu_mutex_lock (mutex=<value temporarily unavailable, due to
>>> optimizations>) at util/qemu-thread-posix.c:73 #3  0x003c44016e95153b
>>> in ?? ()
>>>
>>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used
>>> Windows XP before but it isn't necessary to reproduce the problem.
>>>
>>> The ?? is what appears to be the problem. I can't even print
>>> instructions at that address. Any ideas as to what is calling the
>>> qemu_mutex_lock() function could help.

The unknown code here is probably some place where gdb cannot find the
frame pointer.  Not a surprise if you are using a 5 year old debugger
with (presumably) a newer compiler.

>> Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
>> as soon as you type "beep".
>>
>> It works with the PulseAudio and ALSA backends, but it doesn't with the
>> SDL backend, even on Linux.
>>
>> Also, it deadlocks even with KVM enabled.
>>
>> Paolo
> 
> OK, I see a pattern. SDL and CoreAudio both don't support audio input. Both of them have this code:
>  .voice_size_in  = 0
> 
> Alsa and PulseAudio do support audio input and work. Coincidence?

Yes.  Locking in SDL is completely broken.  sdl_callback runs with the
SDL audio lock taken, but then it waits on a semaphore so you cannot
call any other SDL audio function from the main thread.  As soon as you
do that, you get a deadlock.  I'm strongly tempted to just remove the
driver.

On the other hand, CoreAudio seems to be okay.  Can you try "thread
apply all bt full" from gdb?

Paolo

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 12, 2015, at 3:45 AM, Paolo Bonzini wrote:

> On 12/05/2015 00:43, Programmingkid wrote:
>> 
>> On May 10, 2015, at 10:54 AM, Paolo Bonzini wrote:
>> 
>>> 
>>> 
>>> On 06/05/2015 18:40, Programmingkid wrote:
>>>> When I try to use the pcspk sound hardware, QEMU freezes and uses
>>>> 100% of the cpu time. This is the command I use:
>>>> 
>>>> qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk
>>>> 
>>>> This looks like a deadlock situation because some unknown code called
>>>> qemu_mutex_lock(). Here is the stack trace at the freeze:
>>>> 
>>>> (gdb) bt #0  0x00007fff824e2db6 in semaphore_wait_trap () #1
>>>> 0x00007fff824e8417 in pthread_mutex_lock () #2  0x0000000100267199 in
>>>> qemu_mutex_lock (mutex=<value temporarily unavailable, due to
>>>> optimizations>) at util/qemu-thread-posix.c:73 #3  0x003c44016e95153b
>>>> in ?? ()
>>>> 
>>>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used
>>>> Windows XP before but it isn't necessary to reproduce the problem.
>>>> 
>>>> The ?? is what appears to be the problem. I can't even print
>>>> instructions at that address. Any ideas as to what is calling the
>>>> qemu_mutex_lock() function could help.
> 
> The unknown code here is probably some place where gdb cannot find the
> frame pointer.  Not a surprise if you are using a 5 year old debugger
> with (presumably) a newer compiler.
> 
>>> Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
>>> as soon as you type "beep".
>>> 
>>> It works with the PulseAudio and ALSA backends, but it doesn't with the
>>> SDL backend, even on Linux.
>>> 
>>> Also, it deadlocks even with KVM enabled.
>>> 
>>> Paolo
>> 
>> OK, I see a pattern. SDL and CoreAudio both don't support audio input. Both of them have this code:
>> .voice_size_in  = 0
>> 
>> Alsa and PulseAudio do support audio input and work. Coincidence?
> 
> Yes.  Locking in SDL is completely broken.  sdl_callback runs with the
> SDL audio lock taken, but then it waits on a semaphore so you cannot
> call any other SDL audio function from the main thread.  As soon as you
> do that, you get a deadlock.  I'm strongly tempted to just remove the
> driver.

This sounds very similar to what happens to CoreAudio.

> On the other hand, CoreAudio seems to be okay.  Can you try "thread
> apply all bt full" from gdb?
> 
> Paolo

Here is the output you wanted. 
Note: used run -soundhw ac97 -cdrom ~/debian.iso

Thread 9 (process 44956):
#0  0x00007fff824e2dda in semaphore_timedwait_signal_trap ()
No symbol table info available.
#1  0x00007fff82521772 in _pthread_cond_wait ()
No symbol table info available.
#2  0x00007fff8423468c in CAGuard::WaitFor ()
No symbol table info available.
#3  0x00007fff84236c1b in CAGuard::WaitUntil ()
No symbol table info available.
#4  0x00007fff84234d85 in HP_IOThread::WorkLoop ()
No symbol table info available.
#5  0x00007fff84234827 in HP_IOThread::ThreadEntry ()
No symbol table info available.
#6  0x00007fff84234755 in CAPThread::Entry ()
No symbol table info available.
#7  0x00007fff8251bfd6 in _pthread_start ()
No symbol table info available.
#8  0x00007fff8251be89 in thread_start ()
No symbol table info available.

Thread 8 (process 44956):
#0  addr_add (env=0x121ff2e78, addr=1, arg=247) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/target-ppc/mem_helper.c:42
No locals.
#1  0x0000000100158f4b in helper_lmw (env=0x101db1220, addr=132087416, reg=30) at /Users/user/Documents/Development/Projects/Qemu/qemu-git/target-ppc/mem_helper.c:61
No locals.
#2  0x0000000116426c97 in ?? ()
No symbol table info available.
Current language:  auto; currently c

Thread 6 (process 44956):
#0  0x00007fff8254499e in __sigwait ()
No symbol table info available.
#1  0x00007fff82544977 in sigwait ()
No symbol table info available.
#2  0x00000001003add68 in sigwait_compat (opaque=0x101eb7350) at util/compatfd.c:36
	sig = 0
	err = 0
	info = (struct sigfd_compat_info *) 0x101eb7350
#3  0x00007fff8251bfd6 in _pthread_start ()
No symbol table info available.
#4  0x00007fff8251be89 in thread_start ()
No symbol table info available.

Thread 3 (process 44956):
#0  0x00007fff824fbc0a in kevent ()
No symbol table info available.
#1  0x00007fff824fdadd in _dispatch_mgr_invoke ()
No symbol table info available.
#2  0x00007fff824fd7b4 in _dispatch_queue_invoke ()
No symbol table info available.
#3  0x00007fff824fd2de in _dispatch_worker_thread2 ()
No symbol table info available.
#4  0x00007fff824fcc08 in _pthread_wqthread ()
No symbol table info available.
#5  0x00007fff824fcaa5 in start_wqthread ()
No symbol table info available.

Thread 2 (process 44956):
#0  0x00007fff824e2dc2 in semaphore_wait_signal_trap ()
No symbol table info available.
#1  0x00007fff824e840d in pthread_mutex_lock ()
No symbol table info available.
#2  0x00000001003a98c2 in qemu_mutex_lock (mutex=0x10070e080) at util/qemu-thread-posix.c:73
	err = 0
#3  0x000000010004da9d in qemu_mutex_lock_iothread () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1128
No locals.
#4  0x00000001003be885 in call_rcu_thread (opaque=0x0) at util/rcu.c:241
	tries = 1
	n = 41
	node = (struct rcu_head *) 0x101a98cf0
#5  0x00007fff8251bfd6 in _pthread_start ()
No symbol table info available.
#6  0x00007fff8251be89 in thread_start ()
No symbol table info available.

Thread 1 (process 44956):
#0  0x00007fff824e2dc2 in semaphore_wait_signal_trap ()
No symbol table info available.
#1  0x00007fff824e840d in pthread_mutex_lock ()
No symbol table info available.
#2  0x00000001003a98c2 in qemu_mutex_lock (mutex=0x10070e080) at util/qemu-thread-posix.c:73
	err = 0
#3  0x000000010004da9d in qemu_mutex_lock_iothread () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1128
No locals.
#4  0x000000010031035a in os_host_main_loop_wait (timeout=29193000) at main-loop.c:242
	ret = 0
	spin_counter = 0
#5  0x000000010031041f in main_loop_wait (nonblocking=0) at main-loop.c:494
	ret = 1
	timeout = 1000
	timeout_ns = 29193000
#6  0x00000001001713c1 in main_loop () at vl.c:1799
	nonblocking = false
	last_io = 0
#7  0x0000000100178ebe in qemu_main (argc=5, argv=0x7fff5fbff458, envp=0x7fff5fbff488) at vl.c:4385
	i = 32767
	snapshot = 0
	linux_boot = 0
	initrd_filename = 0x0
	kernel_filename = 0x0
	kernel_cmdline = 0x1003ccfc8 ""
	boot_order = 0x1003d30c4 "cd"
	boot_once = 0x0
	ds = (DisplayState *) 0x101a64f90
	cyls = 0
	heads = 0
	secs = 0
	translation = 0
	hda_opts = (QemuOpts *) 0x0
	opts = (QemuOpts *) 0x0
	machine_opts = (QemuOpts *) 0x101eb6ea0
	icount_opts = (QemuOpts *) 0x0
	olist = (QemuOptsList *) 0x100b31218
	optind = 5
	optarg = 0x0
	loadvm = 0x0
	machine_class = (MachineClass *) 0x101e8de10
	cpu_model = 0x0
	vga_model = 0x1003ec714 "std"
	qtest_chrdev = 0x0
	qtest_log = 0x0
	pid_file = 0x0
	incoming = 0x0
	show_vnc_port = 0
	defconfig = true
	userconfig = true
	log_mask = 0x0
	log_file = 0x0
	mem_trace = {
  malloc = 0x1001745b9 <malloc_and_trace>, 
  realloc = 0x1001745ee <realloc_and_trace>, 
  free = 0x100174632 <free_and_trace>, 
  calloc = 0, 
  try_malloc = 0, 
  try_realloc = 0
}
	trace_events = 0x0
	trace_file = 0x0
	maxram_size = 134217728
	ram_slots = 0
	vmstate_dump_file = (FILE *) 0x0
	main_loop_err = (Error *) 0x0
	__func__ = "qemu_main"
#8  0x00000001002e0569 in -[QemuCocoaAppController startEmulationWithArgc:argv:] (self=0x101e117a0, _cmd=0x100446830, argc=5, argv=0x7fff5fbff458) at cocoa.m:937
	status = 1
#9  0x00000001002e03c2 in -[QemuCocoaAppController applicationDidFinishLaunching:] (self=0x101e117a0, _cmd=0x7fff8064d906, note=0x101e347f0) at cocoa.m:915
No locals.
#10 0x00007fff8a50dbc5 in _nsnote_callback ()
No symbol table info available.
#11 0x00007fff83a7b000 in __CFXNotificationPost ()
No symbol table info available.
#12 0x00007fff83a67578 in _CFXNotificationPostNotification ()
No symbol table info available.
#13 0x00007fff8a504b26 in -[NSNotificationCenter postNotificationName:object:userInfo:] ()
No symbol table info available.
#14 0x00007fff80a1c44a in -[NSApplication _postDidFinishNotification] ()
No symbol table info available.
#15 0x00007fff80a1c37f in -[NSApplication _sendFinishLaunchingNotification] ()
No symbol table info available.
#16 0x00007fff80ae735d in -[NSApplication(NSAppleEventHandling) _handleAEOpen:] ()
No symbol table info available.
#17 0x00007fff80ae6fd9 in -[NSApplication(NSAppleEventHandling) _handleCoreEvent:withReplyEvent:] ()
No symbol table info available.
#18 0x00007fff8a53c1c6 in -[NSAppleEventManager dispatchRawAppleEvent:withRawReply:handlerRefCon:] ()
No symbol table info available.
#19 0x00007fff8a53bff6 in _NSAppleEventManagerGenericHandler ()
No symbol table info available.
#20 0x00007fff84a6f32b in aeDispatchAppleEvent ()
No symbol table info available.
#21 0x00007fff84a6f224 in dispatchEventAndSendReply ()
No symbol table info available.
#22 0x00007fff84a6f12b in aeProcessAppleEvent ()
No symbol table info available.
#23 0x00007fff87300619 in AEProcessAppleEvent ()
No symbol table info available.
#24 0x00007fff809ec095 in _DPSNextEvent ()
No symbol table info available.
#25 0x00007fff809eb801 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
No symbol table info available.
#26 0x00007fff809b168f in -[NSApplication run] ()
No symbol table info available.
#27 0x00000001002e1d4a in main (argc=5, argv=0x7fff5fbff458) at cocoa.m:1169
	i = 5
	pool = (NSAutoreleasePool *) 0x101a2eb10
	psn = {
  highLongOfPSN = 0, 
  lowLongOfPSN = 2
}
	menuItem = (NSMenuItem *) 0x101e15410
	appController = (QemuCocoaAppController *) 0x101e117a0
	menu = (NSMenu *) 0x101e15070

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

[-- Attachment #1: Type: text/plain, Size: 4614 bytes --]


On May 12, 2015, at 3:45 AM, Paolo Bonzini wrote:

> On 12/05/2015 00:43, Programmingkid wrote:
>> 
>> On May 10, 2015, at 10:54 AM, Paolo Bonzini wrote:
>> 
>>> 
>>> 
>>> On 06/05/2015 18:40, Programmingkid wrote:
>>>> When I try to use the pcspk sound hardware, QEMU freezes and uses
>>>> 100% of the cpu time. This is the command I use:
>>>> 
>>>> qemu-system-i386 -cdrom <anything you wan here> -soundhw pcspk
>>>> 
>>>> This looks like a deadlock situation because some unknown code called
>>>> qemu_mutex_lock(). Here is the stack trace at the freeze:
>>>> 
>>>> (gdb) bt #0  0x00007fff824e2db6 in semaphore_wait_trap () #1
>>>> 0x00007fff824e8417 in pthread_mutex_lock () #2  0x0000000100267199 in
>>>> qemu_mutex_lock (mutex=<value temporarily unavailable, due to
>>>> optimizations>) at util/qemu-thread-posix.c:73 #3  0x003c44016e95153b
>>>> in ?? ()
>>>> 
>>>> My host is Mac OS 10.6.8. My guest isn't really anything. I have used
>>>> Windows XP before but it isn't necessary to reproduce the problem.
>>>> 
>>>> The ?? is what appears to be the problem. I can't even print
>>>> instructions at that address. Any ideas as to what is calling the
>>>> qemu_mutex_lock() function could help.
> 
> The unknown code here is probably some place where gdb cannot find the
> frame pointer.  Not a surprise if you are using a 5 year old debugger
> with (presumably) a newer compiler.
> 
>>> Reproduced with a FreeDOS image from QEMU Advent Calendar.  It locks up
>>> as soon as you type "beep".
>>> 
>>> It works with the PulseAudio and ALSA backends, but it doesn't with the
>>> SDL backend, even on Linux.
>>> 
>>> Also, it deadlocks even with KVM enabled.
>>> 
>>> Paolo
>> 
>> OK, I see a pattern. SDL and CoreAudio both don't support audio input. Both of them have this code:
>> .voice_size_in  = 0
>> 
>> Alsa and PulseAudio do support audio input and work. Coincidence?
> 
> Yes.  Locking in SDL is completely broken.  sdl_callback runs with the
> SDL audio lock taken, but then it waits on a semaphore so you cannot
> call any other SDL audio function from the main thread.  As soon as you
> do that, you get a deadlock.  I'm strongly tempted to just remove the
> driver.
> 
> On the other hand, CoreAudio seems to be okay.  Can you try "thread
> apply all bt full" from gdb?
> 
> Paolo


Found out why QEMU is deadlocking. It is because a mutex that has been unlocked over 20 times in a row is being locked. 

http://pubs.opengroup.org/onlinepubs/009695399/functions/pthread_mutex_lock.html

According to the above link, if pthread_mutex_unlock() is called on a mutex that isn't locked, undefined behavior results. This means the mutex that has been unlocked so many times in a row cannot be trusted. There isn't a way to find out who owns a mutex on Mac OS X, so I made my own logging code to help find out what was going on. If you have access to Mac OS 10.6, you could try out this code by just pasting it in qemu-thread-posix.c:

// Debugging code

#define MAX_SIZE 100
int thread_dict[MAX_SIZE] = {0};
int mutex_dict[MAX_SIZE] = {0};

int addToDict(int id, int * a_dict)
{
    static int index = 0;
    if(index > 99) {
        printf("ERROR: too many threads to keep track of!\n");
        return -1;
    }
    a_dict[index] = id;
    index++;
    return index;
}

int getID(int origID, int* a_dict)
{
    int index;
    for (index = 0; index < MAX_SIZE; index++) {
        if(a_dict[index] == origID) {
            return index;
        }
    }
    return addToDict(origID, a_dict);
}

#include <sys/syscall.h>
void qemu_mutex_lock(QemuMutex *mutex)
{
    int err;
    static int count = 0;
    printf("Lock\tThread = %d\tMutex = %d\n", getID(syscall(SYS_thread_selfid), thread_dict), getID(&mutex, mutex_dict));
    
    err = pthread_mutex_lock(&mutex->lock);
    if (err)
        error_exit(err, __func__);
}

int qemu_mutex_trylock(QemuMutex *mutex)
{
    printf("Trying lock\tThread = %d\tMutex = %d\n", getID(syscall(SYS_thread_selfid), thread_dict), getID(&mutex, mutex_dict));
    return pthread_mutex_trylock(&mutex->lock);
}

void qemu_mutex_unlock(QemuMutex *mutex)
{
    int err;

    static int count = 0;
    printf("Unlock\tThread = %d\tMutex = %d\n", getID(syscall(SYS_thread_selfid), thread_dict), getID(&mutex, mutex_dict));

    err = pthread_mutex_unlock(&mutex->lock);
    if (err)
        error_exit(err, __func__);
}

Locking mutex 38 is where qemu-system-i386 seems to fail the most. 

To test the code, I just ran qemu with -soundhw pcspk. 

[-- Attachment #2: Type: text/html, Size: 18793 bytes --]

Re: [Qemu-devel] Help with deadlock when using sound

[Peter Maydell]

On 13 May 2015 at 04:23, Programmingkid <programmingkidx@gmail.com> wrote:
> Found out why QEMU is deadlocking. It is because a mutex that has been
> unlocked over 20 times in a row is being locked.

OSX supports 'error checking' mutexes which will fail in these
undefined-behaviour cases like double-unlock. (The error checking
slows things down which is why it's not the default). If you make
qemu_mutex_init() something like:

void qemu_mutex_init(QemuMutex *mutex)
{
    int err;
    pthread_mutexattr_t mta;

    err = pthread_mutexattr_init(&mta);
    if (err) {
        error_exit(err, __func__);
    }
    err = pthread_mutexattr_settype(&mta, PTHREAD_MUTEX_ERRORCHECK);
    if (err) {
        error_exit(err, __func__);
    }
    err = pthread_mutex_init(&mutex->lock, &mta);
    if (err) {
        error_exit(err, __func__);
    }
    pthread_mutexattr_destroy(&mta);
    if (err) {
        error_exit(err, __func__);
    }
}

then we'll turn on the error checking, and a double-unlock
will result in a call to abort(). If you run QEMU under
a debugger you'll get a backtrace which will tell you which
code did the second unlock (and thus which mutex it is).

(Linux has a similar attribute, though it is named
PTHREAD_MUTEX_ERRORCHECK_NP; we might want to consider
turning on mutex debugging for --enable-debug builds.)

-- PMM

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 13, 2015, at 5:38 AM, Peter Maydell wrote:

> On 13 May 2015 at 04:23, Programmingkid <programmingkidx@gmail.com> wrote:
>> Found out why QEMU is deadlocking. It is because a mutex that has been
>> unlocked over 20 times in a row is being locked.
> 
> OSX supports 'error checking' mutexes which will fail in these
> undefined-behaviour cases like double-unlock. (The error checking
> slows things down which is why it's not the default). If you make
> qemu_mutex_init() something like:
> 
> void qemu_mutex_init(QemuMutex *mutex)
> {
>    int err;
>    pthread_mutexattr_t mta;
> 
>    err = pthread_mutexattr_init(&mta);
>    if (err) {
>        error_exit(err, __func__);
>    }
>    err = pthread_mutexattr_settype(&mta, PTHREAD_MUTEX_ERRORCHECK);
>    if (err) {
>        error_exit(err, __func__);
>    }
>    err = pthread_mutex_init(&mutex->lock, &mta);
>    if (err) {
>        error_exit(err, __func__);
>    }
>    pthread_mutexattr_destroy(&mta);
>    if (err) {
>        error_exit(err, __func__);
>    }
> }
> 
> then we'll turn on the error checking, and a double-unlock
> will result in a call to abort(). If you run QEMU under
> a debugger you'll get a backtrace which will tell you which
> code did the second unlock (and thus which mutex it is).
> 
> (Linux has a similar attribute, though it is named
> PTHREAD_MUTEX_ERRORCHECK_NP; we might want to consider
> turning on mutex debugging for --enable-debug builds.)
> 
> -- PMM

Thanks for the code, but it didn't work as it was expected to. The abort or stack trace never happened. I did recompile using enable-debug. 

Re: [Qemu-devel] Help with deadlock when using sound

[Peter Maydell]

On 13 May 2015 at 14:54, Programmingkid <programmingkidx@gmail.com> wrote:
> Thanks for the code, but it didn't work as it was expected to. The
> abort or stack trace never happened. I did recompile using enable-debug.

I tested that it did detect double-unlock by adding a second
call to unlock in qemu_mutex_unlock; does that fire for you?
If so then maybe the bug isn't actually a double-unlock.

If you could send the trace from your debug printing that
might be helpful.

thanks
-- PMM

Re: [Qemu-devel] Help with deadlock when using sound

[Paolo Bonzini]

On 13/05/2015 11:38, Peter Maydell wrote:
> 
> then we'll turn on the error checking, and a double-unlock
> will result in a call to abort(). If you run QEMU under
> a debugger you'll get a backtrace which will tell you which
> code did the second unlock (and thus which mutex it is).
> 
> (Linux has a similar attribute, though it is named
> PTHREAD_MUTEX_ERRORCHECK_NP; we might want to consider
> turning on mutex debugging for --enable-debug builds.)

We had it, but I had to disable it because it doesn't work (at all) when
you fork.  The PID changes under the code's feet and subsequent unlocks
do not like it.

Paolo

Re: [Qemu-devel] Help with deadlock when using sound

[Programmingkid]

On May 9, 2015, at 6:00 PM, Peter Maydell wrote:

> On 9 May 2015 at 22:42, Programmingkid <programmingkidx@gmail.com> wrote:
>> Where you able to see the new stack trace I sent? If so, any idea what could be wrong?
> 
> Did you see the mail I sent where I asked you to try sending
> the monitor somewhere other than the GUI?
> 
> thanks
> -- PMM

Ok, I sent the monitor to the stdio using this command:  -soundhw pcspk -monitor stdio

Here is the stack trace of QEMU after it has froze:

Program received signal SIGINT, Interrupt.
[Switching to process 4291 thread 0xa0f]
0x00007fff824e2dc2 in semaphore_wait_signal_trap ()
(gdb) thread apply all backtrace

Thread 8 (process 4291):
#0  0x00007fff824e2dda in semaphore_timedwait_signal_trap ()
#1  0x00007fff82521772 in _pthread_cond_wait ()
#2  0x00007fff8423468c in CAGuard::WaitFor ()
#3  0x00007fff84236c1b in CAGuard::WaitUntil ()
#4  0x00007fff84234d85 in HP_IOThread::WorkLoop ()
#5  0x00007fff84234827 in HP_IOThread::ThreadEntry ()
#6  0x00007fff84234755 in CAPThread::Entry ()
#7  0x00007fff8251bfd6 in _pthread_start ()
#8  0x00007fff8251be89 in thread_start ()

Thread 7 (process 4291):
#0  0x00000001160df83f in ?? ()

Thread 6 (process 4291):
#0  0x00007fff8254499e in __sigwait ()
#1  0x00007fff82544977 in sigwait ()
#2  0x000000010036e3d0 in sigwait_compat (opaque=0x101d735d0) at util/compatfd.c:36
#3  0x00007fff8251bfd6 in _pthread_start ()
#4  0x00007fff8251be89 in thread_start ()

Thread 3 (process 4291):
#0  0x00007fff824fbc0a in kevent ()
#1  0x00007fff824fdadd in _dispatch_mgr_invoke ()
#2  0x00007fff824fd7b4 in _dispatch_queue_invoke ()
#3  0x00007fff824fd2de in _dispatch_worker_thread2 ()
#4  0x00007fff824fcc08 in _pthread_wqthread ()
#5  0x00007fff824fcaa5 in start_wqthread ()

Thread 2 (process 4291):
#0  0x00007fff8251da6a in __semwait_signal ()
#1  0x00007fff82521881 in _pthread_cond_wait ()
#2  0x000000010036a8ea in futex_wait (ev=0x100a9e280, val=4294967295) at util/qemu-thread-posix.c:328
#3  0x000000010036aa64 in qemu_event_wait (ev=0x100a9e280) at util/qemu-thread-posix.c:408
#4  0x000000010037ee92 in call_rcu_thread (opaque=0x0) at util/rcu.c:233
#5  0x00007fff8251bfd6 in _pthread_start ()
#6  0x00007fff8251be89 in thread_start ()

Thread 1 (process 4291):
#0  0x00007fff824e2dc2 in semaphore_wait_signal_trap ()
#1  0x00007fff824e840d in pthread_mutex_lock ()
#2  0x000000010036a348 in qemu_mutex_lock (mutex=0x10067ed40) at util/qemu-thread-posix.c:82
#3  0x0000000100039c2e in qemu_mutex_lock_iothread () at /Users/user/Documents/Development/Projects/Qemu/qemu-git/cpus.c:1128
#4  0x00000001002d7e05 in os_host_main_loop_wait (timeout=6221000) at main-loop.c:242
#5  0x00000001002d7eca in main_loop_wait (nonblocking=0) at main-loop.c:494
#6  0x0000000100114909 in main_loop () at vl.c:1798
#7  0x000000010011c3c4 in qemu_main (argc=5, argv=0x7fff5fbff468, envp=0x7fff5fbff498) at vl.c:4362
#8  0x00000001002a4339 in -[QemuCocoaAppController startEmulationWithArgc:argv:] (self=0x101937740, _cmd=0x1003f095e, argc=5, argv=0x7fff5fbff468) at cocoa.m:897
#9  0x00000001002a4192 in -[QemuCocoaAppController applicationDidFinishLaunching:] (self=0x101937740, _cmd=0x7fff8064d906, note=0x101d3b250) at cocoa.m:875
#10 0x00007fff8a50dbc5 in _nsnote_callback ()
#11 0x00007fff83a7b000 in __CFXNotificationPost ()
#12 0x00007fff83a67578 in _CFXNotificationPostNotification ()
#13 0x00007fff8a504b26 in -[NSNotificationCenter postNotificationName:object:userInfo:] ()
#14 0x00007fff80a1c44a in -[NSApplication _postDidFinishNotification] ()
#15 0x00007fff80a1c37f in -[NSApplication _sendFinishLaunchingNotification] ()
#16 0x00007fff80ae735d in -[NSApplication(NSAppleEventHandling) _handleAEOpen:] ()
#17 0x00007fff80ae6fd9 in -[NSApplication(NSAppleEventHandling) _handleCoreEvent:withReplyEvent:] ()
#18 0x00007fff8a53c1c6 in -[NSAppleEventManager dispatchRawAppleEvent:withRawReply:handlerRefCon:] ()
#19 0x00007fff8a53bff6 in _NSAppleEventManagerGenericHandler ()
#20 0x00007fff84a6f32b in aeDispatchAppleEvent ()
#21 0x00007fff84a6f224 in dispatchEventAndSendReply ()
#22 0x00007fff84a6f12b in aeProcessAppleEvent ()
#23 0x00007fff87300619 in AEProcessAppleEvent ()
#24 0x00007fff809ec095 in _DPSNextEvent ()
#25 0x00007fff809eb801 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#26 0x00007fff809b168f in -[NSApplication run] ()
#27 0x00000001002a50ea in main (argc=5, argv=0x7fff5fbff468) at cocoa.m:1034