Deadlock on thread exit using TRACE() on W2K 
Author Message
 Deadlock on thread exit using TRACE() on W2K

Hi,

 I have come across this really annoying deadlock problem in
W2K and VC++ SP4. At first I thought it was the use of a
critical section in my original code. I have reduced the
offending code sequence to its bare minimum. For now,
I will remove all TRACE() statements from my code ...

I suspect some really bad voodoo on reception of the
DLL_THREAD_DETACH notification.

This failure only seems to occur in the de{*filter*} while
it is tracing to the "Output Window". This problem does
not appear to occur in NT4.

I tried this on a {*filter*} VC++ installation (without SP4)
and it failed there too under W2K.

Setups:

Single 650MHz PIII W2K Professionl SP1 and VC++6 SP4
Dual   800MHz PIII W2K Advanced Server SP1 and VC++6 SP4
Dual   800MHz PIII W2K Advanced Server SP1 and VC++6
Dual   266MHz PII  NT Workstation and VC++6 SP4

Only the NT system successfully runs this code in the
de{*filter*}. Can anyone shed some light on this?

If TRACE() is replace with OutputDebugString() the
same failure occurs.

Can someone else confirm the failure.

Cheers,
Vince

-- somewhere in NY USA

// Slap this code into a basic multi-threaded MFC .exe
// classwizard project.
// call the TestTracer() routine from Initinstance()
// for the application.
// Choose MFC as a shared DLL.

// as each of the threads exit, there will come a
// time when the app will deadlock. What is going on?
// I am running VC++ SP4 on W2K SP1.
// I seek enlightenment. I hope that I am not smoking crack ;-)
//

#define NUMBER_OF_THREADS 400

UINT TracerThread(LPVOID);
VOID TestTracer(VOID);

HANDLE hWaiter;

VOID TestTracer(VOID)
{

 hWaiter = CreateEvent(NULL,TRUE,FALSE,NULL);

 for (int index = 0; index < NUMBER_OF_THREADS ; index ++)
 {
  AfxBeginThread(TracerThread,NULL,THREAD_PRIORITY_BELOW_NORMAL);
 }

 // start all the threads running.

 SetEvent(hWaiter);

Quote:
}

UINT TracerThread(LPVOID)
{
 // random number of loops before we exit ...

 unsigned short loops = rand();

 WaitForSingleObject(hWaiter,INFINITE);

 while (TRUE)

  // sleep for some random amount of time

  Sleep(rand() & 0xFF);

  TRACE("11111111111111111111111111111111111111111111\n");
  TRACE("22222222222222222222222222222222222222222222\n");
  TRACE("33333333333333333333333333333333333333333333\n");
  TRACE("44444444444444444444444444444444444444444444\n");
  TRACE("55555555555555555555555555555555555555555555\n");
  TRACE("66666666666666666666666666666666666666666666\n");

  loops --;

  if (!loops) break;
 }

 return 0;

Quote:
}



Mon, 07 Jul 2003 17:48:24 GMT  
 Deadlock on thread exit using TRACE() on W2K
Your code looks OK at first glance, although that while loop could be
written more succintly ;-)

There's a problem with OutputDebugString / TRACE statements running under
the de{*filter*} near synchronization conditions. See the 'Deadlocks caused by
OutputDebugString / TRACE near thread exit' thread in this newsgroup
starting from 23 November 2000.

The problem is documented roughly in the article 'PRB: Synchronization
Failure When Debugging' on MSDN. As I understand it, it's more of a
limitation of the Win32 debug environment rather than any specific de{*filter*}.

The solution unfortunately is to remove the TRACE / OutputDebugString calls
from around the code making SetEvent / WaitForSingleObject (or other
synchronization routines). You could replace with file logging etc.

Hope this helps,

David



Quote:
> Hi,

>  I have come across this really annoying deadlock problem in
> W2K and VC++ SP4. At first I thought it was the use of a
> critical section in my original code. I have reduced the
> offending code sequence to its bare minimum. For now,
> I will remove all TRACE() statements from my code ...

> I suspect some really bad voodoo on reception of the
> DLL_THREAD_DETACH notification.

> This failure only seems to occur in the de{*filter*} while
> it is tracing to the "Output Window". This problem does
> not appear to occur in NT4.

> I tried this on a {*filter*} VC++ installation (without SP4)
> and it failed there too under W2K.

> Setups:

> Single 650MHz PIII W2K Professionl SP1 and VC++6 SP4
> Dual   800MHz PIII W2K Advanced Server SP1 and VC++6 SP4
> Dual   800MHz PIII W2K Advanced Server SP1 and VC++6
> Dual   266MHz PII  NT Workstation and VC++6 SP4

> Only the NT system successfully runs this code in the
> de{*filter*}. Can anyone shed some light on this?

> If TRACE() is replace with OutputDebugString() the
> same failure occurs.

> Can someone else confirm the failure.

> Cheers,
> Vince

> -- somewhere in NY USA

> // Slap this code into a basic multi-threaded MFC .exe
> // classwizard project.
> // call the TestTracer() routine from Initinstance()
> // for the application.
> // Choose MFC as a shared DLL.

> // as each of the threads exit, there will come a
> // time when the app will deadlock. What is going on?
> // I am running VC++ SP4 on W2K SP1.
> // I seek enlightenment. I hope that I am not smoking crack ;-)
> //

> #define NUMBER_OF_THREADS 400

> UINT TracerThread(LPVOID);
> VOID TestTracer(VOID);

> HANDLE hWaiter;

> VOID TestTracer(VOID)
> {

>  hWaiter = CreateEvent(NULL,TRUE,FALSE,NULL);

>  for (int index = 0; index < NUMBER_OF_THREADS ; index ++)
>  {
>   AfxBeginThread(TracerThread,NULL,THREAD_PRIORITY_BELOW_NORMAL);
>  }

>  // start all the threads running.

>  SetEvent(hWaiter);

> }

> UINT TracerThread(LPVOID)
> {
>  // random number of loops before we exit ...

>  unsigned short loops = rand();

>  WaitForSingleObject(hWaiter,INFINITE);

>  while (TRUE)

>   // sleep for some random amount of time

>   Sleep(rand() & 0xFF);

>   TRACE("11111111111111111111111111111111111111111111\n");
>   TRACE("22222222222222222222222222222222222222222222\n");
>   TRACE("33333333333333333333333333333333333333333333\n");
>   TRACE("44444444444444444444444444444444444444444444\n");
>   TRACE("55555555555555555555555555555555555555555555\n");
>   TRACE("66666666666666666666666666666666666666666666\n");

>   loops --;

>   if (!loops) break;
>  }

>  return 0;

> }



Mon, 07 Jul 2003 20:33:52 GMT  
 Deadlock on thread exit using TRACE() on W2K


Quote:
> Your code looks OK at first glance, although that while loop could be
> written more succintly ;-)

Hehe, now that you mention it ;-) my only sorry excuse is doing everything
possible to reproduce the bug - that code was a hell of a lot more
complex when I started out ;-)))

Quote:
> There's a problem with OutputDebugString / TRACE statements running under
> the de{*filter*} near synchronization conditions. See the 'Deadlocks caused by
> OutputDebugString / TRACE near thread exit' thread in this newsgroup
> starting from 23 November 2000.

> The problem is documented roughly in the article 'PRB: Synchronization
> Failure When Debugging' on MSDN. As I understand it, it's more of a
> limitation of the Win32 debug environment rather than any specific

de{*filter*}.

Yes, after posting the message, I noticed all of the other threads. I read
through them and understand the nature of the problem now - I am
not too happy about the wishy/washy solution suggested though.

Quote:

> The solution unfortunately is to remove the TRACE / OutputDebugString
calls
> from around the code making SetEvent / WaitForSingleObject (or other
> synchronization routines). You could replace with file logging etc.

Certainly will do. I spent close on 20 hours messing with my code thinking
that
it was my problem. To make matters worse, the other programmers think that
I am on crack ... I will smack em all when I get into the lab tomorrow.

Quote:

> Hope this helps,

> David

Dave, thanks for all the pointers.

Cheers,
Vince

Quote:


> > Hi,

> >  I have come across this really annoying deadlock problem in
> > W2K and VC++ SP4. At first I thought it was the use of a
> > critical section in my original code. I have reduced the
> > offending code sequence to its bare minimum. For now,
> > I will remove all TRACE() statements from my code ...

> > I suspect some really bad voodoo on reception of the
> > DLL_THREAD_DETACH notification.

> > This failure only seems to occur in the de{*filter*} while
> > it is tracing to the "Output Window". This problem does
> > not appear to occur in NT4.

> > I tried this on a {*filter*} VC++ installation (without SP4)
> > and it failed there too under W2K.

> > Setups:

> > Single 650MHz PIII W2K Professionl SP1 and VC++6 SP4
> > Dual   800MHz PIII W2K Advanced Server SP1 and VC++6 SP4
> > Dual   800MHz PIII W2K Advanced Server SP1 and VC++6
> > Dual   266MHz PII  NT Workstation and VC++6 SP4

> > Only the NT system successfully runs this code in the
> > de{*filter*}. Can anyone shed some light on this?

> > If TRACE() is replace with OutputDebugString() the
> > same failure occurs.

> > Can someone else confirm the failure.

> > Cheers,
> > Vince

> > -- somewhere in NY USA

> > // Slap this code into a basic multi-threaded MFC .exe
> > // classwizard project.
> > // call the TestTracer() routine from Initinstance()
> > // for the application.
> > // Choose MFC as a shared DLL.

> > // as each of the threads exit, there will come a
> > // time when the app will deadlock. What is going on?
> > // I am running VC++ SP4 on W2K SP1.
> > // I seek enlightenment. I hope that I am not smoking crack ;-)
> > //

> > #define NUMBER_OF_THREADS 400

> > UINT TracerThread(LPVOID);
> > VOID TestTracer(VOID);

> > HANDLE hWaiter;

> > VOID TestTracer(VOID)
> > {

> >  hWaiter = CreateEvent(NULL,TRUE,FALSE,NULL);

> >  for (int index = 0; index < NUMBER_OF_THREADS ; index ++)
> >  {
> >   AfxBeginThread(TracerThread,NULL,THREAD_PRIORITY_BELOW_NORMAL);
> >  }

> >  // start all the threads running.

> >  SetEvent(hWaiter);

> > }

> > UINT TracerThread(LPVOID)
> > {
> >  // random number of loops before we exit ...

> >  unsigned short loops = rand();

> >  WaitForSingleObject(hWaiter,INFINITE);

> >  while (TRUE)

> >   // sleep for some random amount of time

> >   Sleep(rand() & 0xFF);

> >   TRACE("11111111111111111111111111111111111111111111\n");
> >   TRACE("22222222222222222222222222222222222222222222\n");
> >   TRACE("33333333333333333333333333333333333333333333\n");
> >   TRACE("44444444444444444444444444444444444444444444\n");
> >   TRACE("55555555555555555555555555555555555555555555\n");
> >   TRACE("66666666666666666666666666666666666666666666\n");

> >   loops --;

> >   if (!loops) break;
> >  }

> >  return 0;

> > }



Mon, 07 Jul 2003 21:51:36 GMT  
 Deadlock on thread exit using TRACE() on W2K
You're not alone. I've had a couple of people mention this problem privately
in e-mail after seeing the thread and they had spent considerably more than
20 hours on it. And their colleagues didn't believe them either when they
saw the hang was in OutputDebugString.



Quote:
> Certainly will do. I spent close on 20 hours messing with my code thinking
> that
> it was my problem. To make matters worse, the other programmers think that
> I am on crack ... I will smack em all when I get into the lab tomorrow.



Mon, 07 Jul 2003 22:15:34 GMT  
 Deadlock on thread exit using TRACE() on W2K
Someone said recently that the de{*filter*} in Visual Studio.NET did not suffer
from this problem.
I may not be remembering correctly though.

Nick

--


Quote:
> You're not alone. I've had a couple of people mention this problem
privately
> in e-mail after seeing the thread and they had spent considerably more
than
> 20 hours on it. And their colleagues didn't believe them either when they
> saw the hang was in OutputDebugString.



> > Certainly will do. I spent close on 20 hours messing with my code
thinking
> > that
> > it was my problem. To make matters worse, the other programmers think
that
> > I am on crack ... I will smack em all when I get into the lab tomorrow.



Sat, 12 Jul 2003 07:30:48 GMT  
 Deadlock on thread exit using TRACE() on W2K
I'll have to have a play with it ;-) although I rather suspect it won't be
using the Win32 debug environment but a .NET debug environment, but I don't
know for sure. One thing that concerns me about the .NET is the quality of
the debug environment - although they may have eliminated pointer errors and
we should see fewer access violation crashes, printer and video drivers
won't have magically got better overnight. And the .NET synchronization
stuff is going to boil down to the Win32 mechanisms at some point - I'd hate
to have to debug deadlocks in .NET code without WinDbg's locks extension.

David


Quote:
> Someone said recently that the de{*filter*} in Visual Studio.NET did not
suffer
> from this problem.
> I may not be remembering correctly though.

> Nick

> --



> > You're not alone. I've had a couple of people mention this problem
> privately
> > in e-mail after seeing the thread and they had spent considerably more
> than
> > 20 hours on it. And their colleagues didn't believe them either when
they
> > saw the hang was in OutputDebugString.



> > > Certainly will do. I spent close on 20 hours messing with my code
> thinking
> > > that
> > > it was my problem. To make matters worse, the other programmers think
> that
> > > I am on crack ... I will smack em all when I get into the lab
tomorrow.



Sat, 12 Jul 2003 18:04:13 GMT  
 
 [ 6 post ] 

 Relevant Pages 

1. Deadlock on thread exit using TRACE() on W2K

2. Deadlocks caused by OutputDebugString / TRACE near thread exit

3. system wide deadlock from user mode on W2K

4. Deadlocked TRACE statements - any cure?

5. What is the difference between Application.Exit(), Environment.Exit(-1) and Thread.CurrentThread.Abo

6. Thread Pool Deadlock -- need help!

7. Timeouts and suspected thread deadlocks

8. Tracing function entry and exit

9. Nest-indented subroutine entry/exit trace?

10. Exit One Thread From Another Thread

11. Control in Thread, can not exit thread

12. Exit One Thread From Another Thread

 

 
Powered by phpBB® Forum Software