Problem in mutex?

[Shachar Shemesh]

Hi all,

Attached is a sample program, originally written to find out about the 
impact of using epoll on performance.

However, the program doesn't run properly. When running it, I get 
deadlocked.

Does anyone have any explanation? Is it a bug in my Win32 code?
> err:ntdll:RtlpWaitForCriticalSection section 0x4017fec0 "?" wait timed 
> out in thread 0009, blocked by 0000, retrying (60 sec)

Shachar

[Mike Hearn]

> However, the program doesn't run properly. When running it, I get 
> deadlocked.
>
> Does anyone have any explanation? Is it a bug in my Win32 code?

Doubt it, it *looks* OK. But the acid test is to run it on Windows.

I've not used the mutex APIs much though, so could well be wrong.
> > err:ntdll:RtlpWaitForCriticalSection section 0x4017fec0 "?" wait timed 
> > out in thread 0009, blocked by 0000, retrying (60 sec)

Well, this must be a Wine internal critical section and 0 is an invalid 
thread ID. So it looks like something is going badly wrong inside Wine.

What does the backtrace of thread 9 look like?

thanks -mike

[Michael Drüing]

Hi,

running the program in WinXP results in an output like this:
Failed to create thread 8
Failed to create thread 8
.... (repeated quite often)
Failed to create thread 8
Failed to create thread 8
Program exit 33060

Watching the program with the taskmanager shows that it seems to only create
about 2000 threads, after which it seems to get these "out of memory"
errors.
Sometimes I get the following line one or two times after the "Program exit"
line (this seems to happen when the system is under load, for example when
starting the task manager with Ctrl-Alt-Esc while the program is running):
Didn't get mutex 80

The count after "Program exit" is always about 30000, but sometimes it's
even <10000

Hope that helps
--Michael

-----Original Message-----
From: [e-mail] [mailto:[e-mail]] On
Behalf Of Mike Hearn
Sent: Friday, August 27, 2004 3:56 PM
To: Shachar Shemesh
Cc: Wine Development
Subject: Re: Problem in mutex?
> However, the program doesn't run properly. When running it, I get 
> deadlocked.
>
> Does anyone have any explanation? Is it a bug in my Win32 code?

Doubt it, it *looks* OK. But the acid test is to run it on Windows.

I've not used the mutex APIs much though, so could well be wrong.
> > err:ntdll:RtlpWaitForCriticalSection section 0x4017fec0 "?" wait timed 
> > out in thread 0009, blocked by 0000, retrying (60 sec)

Well, this must be a Wine internal critical section and 0 is an invalid 
thread ID. So it looks like something is going badly wrong inside Wine.

What does the backtrace of thread 9 look like?

thanks -mike

[Francois Gouget]

On Fri, 27 Aug 2004, Michael Drüing wrote:
> Hi,
>
> running the program in WinXP results in an output like this:
> Failed to create thread 8
> Failed to create thread 8
> .... (repeated quite often)
> Failed to create thread 8
> Failed to create thread 8
> Program exit 33060
>
> Watching the program with the taskmanager shows that it seems to only create
> about 2000 threads, after which it seems to get these "out of memory"
> errors.

Unless you've done something special, each thread gets a 1MB stack. So
2000 threads works out to about 2GB which exhausts the virtual memory
space. I have not read the code but I assume you don't try to
create 2000 concurrent threads. Could it be that somehow the resources
used by each thread are not getting released?

[Shachar Shemesh]

Mike Hearn wrote:
> > However, the program doesn't run properly. When running it, I get 
> > deadlocked.
> >
> > Does anyone have any explanation? Is it a bug in my Win32 code?
>
> Doubt it, it *looks* OK. But the acid test is to run it on Windows.
>
> I've not used the mutex APIs much though, so could well be wrong.
> > > err:ntdll:RtlpWaitForCriticalSection section 0x4017fec0 "?" wait 
> > > timed out in thread 0009, blocked by 0000, retrying (60 sec)
>
> Well, this must be a Wine internal critical section and 0 is an 
> invalid thread ID. So it looks like something is going badly wrong 
> inside Wine.
>
> What does the backtrace of thread 9 look like?
>
> thanks -mike
> Wine-dbg>info thread
> process  tid      prio (all id:s are in hex)
> 00000008 (D) Z:\home\sun\sources\wine\threadtest\threadtest.exe
>         00000009    0 <==
> Wine-dbg>bt
> Backtrace:
> =>1 0x400484d1 (0x402fac54)
>   2 0x401e5462 NTDLL_wait_for_multiple_objects+0x122(count=0x0, 
> handles=0x0, flags=0x8, timeout=0x402fad10) 
> [/home/sun/sources/wine/wine/dlls/ntdll/sync.c:587] in ntdll (0x402facf8)
>   3 0x401e39cc usr1_handler+0x4c(__signal=0xa, __context=0x33) 
> [/home/sun/sources/wine/wine/dlls/ntdll/signal_i386.c:1160] in ntdll 
> (0x402fad1c)
>   4 0xffffe420 (0x406bcd98)
>   5 0x401e5462 NTDLL_wait_for_multiple_objects+0x122(count=0x1, 
> handles=0x406bce8c, flags=0xc, timeout=0x406bcebc) 
> [/home/sun/sources/wine/wine/dlls/ntdll/sync.c:587] in ntdll (0x406bce3c)
>   6 0x401e54d6 NtWaitForMultipleObjects+0x66(count=0x1, 
> handles=0x406bce8c, wait_all=0x0, alertable=0x0, timeout=0x406bcebc) 
> [/home/sun/sources/wine/wine/dlls/ntdll/sync.c:605] in ntdll (0x406bce64)
>   7 0x401e552c NtWaitForSingleObject+0x3c(handle=0x2c98, 
> alertable=0x0, timeout=0x406bcebc) 
> [/home/sun/sources/wine/wine/dlls/ntdll/sync.c:614] in ntdll (0x406bce84)
>   8 0x401bfd15 RtlpWaitForCriticalSection+0x115(crit=0x4017fec0) 
> [/home/sun/sources/wine/wine/dlls/ntdll/critsection.c:220] in ntdll 
> (0x406bcf24)
>   9 0x401bffa9 RtlEnterCriticalSection+0x49(crit=0x4017fec0) 
> [/home/sun/sources/wine/wine/dlls/ntdll/critsection.c:298] in ntdll 
> (0x406bcf3c)
>   10 0x406cf980 (0x406bfe90)
>   11 0x405b318afixme:dbghelp:elf_load_debug_info Unsupported Dwarf2 
> information
>  (0x406bff20)
>   12 0x404ffe52 start_process+0xf2(arg=0x0) 
> [/home/sun/sources/wine/wine/dlls/kernel/process.c:1014] in kernel32 
> (0x406bfff4)
>   13 0x4001d151 wine_switch_to_stack+0x11 in libwine.so.1 (0x00000000)

I find that there are several disturbing things here:
1. There is only one process. How did that happen?
2. The debugger cannot load the debug info for my winelib application. 
What the....?
3. When compiling this in Visual Studio 6 and running on wine:
> sun@sun:~/sources/wine/threadtest$ time ../wine/wine Debug/main.exe  > 
> /dev/null
> Program exit 299732
>
> real    0m17.826s
> user    0m3.244s
> sys     0m5.671s

Just for comparison, when running on Windows, I get as far as 298015, 
but in less time.

In order to achieve this, I lowered the stack (second CreateThread 
parameter) to 8*1024, to avoid running out of memory. This does not 
solve the problem when compiled as winelib, though. Could this be a 
winelib problem??

In short - things are getting weirder.....

Shachar

[Eric Pouech]

> I find that there are several disturbing things here:
> - There is only one process. How did that happen?

you mean thread don't you ?
> - The debugger cannot load the debug info for my winelib application.
>
> What the....?

did you compile your winelib app with -g or -gstabs as it's supposed to be ?
A+

[Shachar Shemesh]

Shachar Shemesh wrote:
> > sun@sun:~/sources/wine/threadtest$ time ../wine/wine Debug/main.exe
> > > /dev/null
> >
> > Program exit 299732
>
> Just for comparison, when running on Windows, I get as far as 298015, 
> but in less time.

Just for the record, if all the threads run to completion, and the mutex 
do their job, the number should have been 300000. Any other number seems 
to indicate that there was a problem with the mutex. If a mutex failed 
to be granted we should have seen messages, which didn't happen either.

This problem is for both Windows AND wine. I can only deduct that I'm 
doing something wrong. Maybe named mutexes are not shared like I thought 
they are? When I try to create the mutex only once and share the handle 
I get a lot of failed locking responses, also on Windows. Then again, 
when I use the original code, even on windows, the number is not a 
multiple of 1000, which suggests that not all increments happened.

The only explanation is that there is a bug in the win32 code. But what?

Shachar

[Alexandre Julliard]

Shachar Shemesh  writes:
> #define NUMTHREADS 3000
>
> [...]
>     WaitForMultipleObjects(NUMTHREADS, threads, TRUE, INFINITE);

That's probably not the cause of the deadlock, but you can't wait for
more than 64 objects with WaitForMultipleObjects, so your code won't
wait for the threads to terminate.