Console Writes from nunit tests
Arun Lakshminarayanan
through the stack trace - we spotted a deadlock arising from
attempting to write to the console from within the test.
We use NUnit version 2.4.3, and we kick off the tests using nunit-
console.exe multiple times : once for each test DLL.
I came across an earlier post (http://osdir.com/ml/nunit-discuss/
2009-12/msg00011.html) that talks about this issue a bit. Looks like
the nunit test execution engine locks the event buffer queue at
various stages and if we attempt to write to the console during that
time, it would result in a deadlock.
We would like to get some clarity on when it is ok to write to the
console and when it is not?. For example something along the lines of
Console.WriteLine from a class that is tagged as a [TestFixture] and a
method that is tagged as a [Test]/[TestFixtureSetup]/
[TestFixtureTearDown] is fine
What is the recommended work around to capture those print statements?
Write to a file log?
thanks,
-Arun.
RJV
--
You received this message because you are subscribed to the Google Groups "NUnit-Discuss" group.
To post to this group, send email to nunit-...@googlegroups.com.
To unsubscribe from this group, send email to nunit-discus...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/nunit-discuss?hl=en.
Arun Lakshminarayanan
log and error files, which is where all the console writes will be
captured. This is useful but don't think this will solve my problem.
I am more interested in understanding about the event buffer queue,
the lock down and possible deadlock scenarios. In one of our tests,
writing to the console from one of the background threads in test
suite caused a deadlock. This background thread is not a part of any
TextFixture class, but a singleton class that is statically
instantiated and periodically triggers certain actions that are needed
for the test. It appears that writing to console may not be "safe"
under all circumstances. We want to understand the NUnit internals a
bit better here, and find out when it is ok and when it is not.
thanks,
-Arun.
On Feb 8, 2:24 am, RJV <jv.ravichand...@gmail.com> wrote:
> Hi Arun,
>
> Will using /out:TestResult.txt switch solve your problem? Or if you want to
> catch the error outputs use the /err: option
>
> Other options you can use with the console runner is here:http://www.nunit.org/index.php?p=consoleCommandLine&r=2.2.5
>
> Yes, logging is also an useful way to do it but it may take a lot of space
> at times...depends on your preference.
>
> HTH
>
> Jv
>
> > nunit-discus...@googlegroups.com<nunit-discuss%2Bunsubscribe@googlegroups.com>
> > .
> > For more options, visit this group at
> >http://groups.google.com/group/nunit-discuss?hl=en.- Hide quoted text -
>
> - Show quoted text -
Charlie Poole
There is one case where writing to console could cause a deadlock,
any other cases would be a bug - which we should try to nail down
and fix.
That one case is as follows...
1. You have an EventListener addin.
2. Within a TestOutput handler, you try to write to the console,
thereby triggering another TestOutput event.
(Alternatively, you could create a similar situation by some
chain of direct calls to your own handlers. Don't do that.)
If you have an EventListener addin, that's where we should look.
If not we should try to narrow down the exact situation where
a console write is causing deadlock.
If someone wants to cast an eye on the code for enqueing events
to see whether we have a race condition, take a look at
EventQueue.cs and EventPump.cs.
Charlie
> > > nunit-discuss+be@googlegroups.com>
> > > .
> > > For more options, visit this group at
> > >http://groups.google.com/group/nunit-discuss?hl=en.- Hide
> quoted text
> > >-
> >
> > - Show quoted text -
>
> --
> You received this message because you are subscribed to the
> Google Groups "NUnit-Discuss" group.
> To post to this group, send email to nunit-...@googlegroups.com.
> To unsubscribe from this group, send email to
> nunit-discus...@googlegroups.com.
Rags
similar symptoms. The instance constructor of a class marked as
TestFixture creates a thread which Console.WriteLine and this causing
a deadlock inconsistently
We do NOT have any EventListener addin.
I have included the stack trace of all threads from the process by
omitting our app specific frames for confidentiality. This is not a
consistent repro and I may not be able to fetch more data. Is the
relevant code in nunit publicly accessible - I'd like to take a look
if possible...
0:010> ~*kb
0 Id: 1270.10dc Suspend: 1 Teb: 000007ff`fffdd000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744b362 : 00000000`00d1d708 00000000`0000babe
00000000`00000000 00000000`7736d39e : ntdll!ZwWaitForMultipleObjects
+0xa
00000000`7736d9b5 : 00000000`00000001 00000000`0021e418
00000001`00000000 00000000`00000000 : KERNEL32!FileTimeToSystemTime
+0xc2
00000000`7736da2e : 00000000`0021dfc0 00000000`0021e418
00000000`00000001 00000000`0021dfb0 : USER32!CopyRect+0x131
000007fe`fdb7c676 : 00000000`0021dfc0 00000000`00000001
00000000`00000000 00000000`0021dfb0 : USER32!
MsgWaitForMultipleObjectsEx+0x2e
000007fe`fdbbc344 : 00000000`80010116 00000000`0021e0d0
00000000`80010115 00000000`0021e418 : ole32!CreatePointerMoniker+0x4d6
000007fe`f865624f : 00000000`00350298 00000000`77597b1a
00000000`1b07b350 00000000`00000020 : ole32!CoWaitForMultipleHandles
+0x120
000007fe`f864bf15 : 00000000`00000001 000007ff`0018c550
00000000`1b05e4b0 00000000`00000000 : mscorwks!ClrCreateManagedInstance
+0x9f3
000007fe`f84d74bb : ffffffff`00000001 00000000`0021e418
00000000`00000000 000007fe`ffffffff : mscorwks!CopyPDBs+0x1884d
000007fe`f8506501 : 00000000`00000000 00000000`0021e418
00000000`00000000 00000000`ffffffff : mscorwks!GetCLRFunction+0xd8cf
000007fe`f8603080 : 00000000`00000000 00000000`1b07b350
00000000`0021e418 00000000`00000000 : mscorwks!CreateApplicationContext
+0x222e9
000007fe`f84af3d1 : 00000000`00000001 000007ff`00000001
00000000`00000000 000007ff`0018c550 : mscorwks!CreateAssemblyNameObject
+0x39edc
000007fe`f8a97b1a : 000007ff`001eb9c0 00000000`00000000
00000000`0039bfa0 00000000`00000274 : mscorwks+0xef3d1
000007fe`f8ac306a : 00000000`00000001 000007ff`001e57c0
00000000`1b06e120 00000000`0039bfa0 : mscorwks!DeleteShadowCache
+0x171a
000007ff`0018c581 : 00000000`02899730 00000000`028ed138
00000000`028ed7c8 00000000`00000001 : mscorwks!ReOpenMetaDataWithMemory
+0x1e99a
000007ff`0018c3a7 : 00000000`028ee340 00000000`1b068328
00000000`0021e3f0 00000000`00000000 : nunit_core!
NUnit.Core.TestRunnerThread.Wait()+0x31
000007ff`0018bc66 : 00000000`028b37b8 00000000`1b068328
00000000`0021e3f0 00000000`00000000 : nunit_core!
NUnit.Core.ThreadedTestRunner.EndRun()+0x17
000007ff`0018bc08 : 00000000`028b37b8 00000000`028ed7c8
00000000`02899730 00000000`00000000 : nunit_core!
NUnit.Core.ThreadedTestRunner.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x26
000007ff`0018b439 : 00000000`028b2d10 00000000`028ed7c8
00000000`02899730 00000000`00000000 : nunit_core!
NUnit.Core.DelegatingTestRunner.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x38
000007ff`00182af7 : 00000000`028b2d10 00000000`028ed138
00000000`02899730 00000000`00000000 : nunit_core!
NUnit.Core.RemoteTestRunner.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x99
000007ff`00180400 : 00000000`028996c0 00000000`02842bb8
00000000`0021e4b8 00000000`0021e540 : nunit_console_runner!
NUnit.ConsoleRunner.ConsoleUi.Execute(NUnit.ConsoleRunner.ConsoleOptions)
+0x397
000007ff`00180129 : 00000000`02843e60 000007fe`f856532a
000007fe`f8435880 00000000`00000000 : nunit_console_runner!
NUnit.ConsoleRunner.Runner.Main(System.String[])+0x230
000007fe`f8692012 : 00000000`02843e60 000007fe`f856532a
000007fe`f8435880 00000000`00000000 : nunit_console!
NUnit.ConsoleRunner.Class1.Main(System.String[])+0x9
000007fe`f8550243 : 00000000`00000000 000007fe`f6a365a0
00000000`00000000 00000000`00000000 : mscorwks!IEE+0xb0ea
000007fe`f855e49f : 00000000`0021eaf8 00000000`00000008
00000000`0021ed10 00000000`0021eaf8 : mscorwks!CompareAssemblyIdentity
+0x2d36b
000007fe`f84d9422 : 00000000`00000004 00000000`00000000
00000000`00000000 00000000`0021ef70 : mscorwks!CompareAssemblyIdentity
+0x3b5c7
000007fe`f84bcb44 : 00000000`00350298 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks!GetCLRFunction+0xf836
000007fe`f86022a5 : 00000000`0021f560 00000000`003b64c0
00000000`003adbc8 00000000`00000200 : mscorwks!StrongNameErrorInfo
+0x55c8
000007fe`f84b39e3 : 00000000`00000000 00000000`00000000
00000000`00000000 000007fe`f862bebe : mscorwks!CreateAssemblyNameObject
+0x39101
000007fe`f84c3c90 : 00000000`00000000 00000000`00000000
000007fe`f9793d18 00000000`00000000 : mscorwks+0xf39e3
000007fe`f97a253e : ffffffff`ffffffff 00000000`0039bfa0
00000000`00000000 00000000`00000000 : mscorwks!CorExeMain+0xac
00000000`7744466d : 000007fe`f83c0000 00000000`00000000
00000000`00000000 00000000`00000000 : mscoree!CorExeMain+0x3e
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
1 Id: 1270.1094 Suspend: 1 Teb: 000007ff`fffdb000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744b362 : 00000000`008d263e 00000000`00000000
00000000`00100000 00000000`00001000 : ntdll!ZwWaitForMultipleObjects
+0xa
00000000`77434661 : 00000000`0038d2a0 00000000`ffffffff
00000002`00000000 000007fe`f8575c5b : KERNEL32!FileTimeToSystemTime
+0xc2
000007fe`f861fbe1 : 00000002`00000000 00000000`0038d2a0
00000000`00000000 00000000`0038d2a0 : KERNEL32!WaitForMultipleObjects
+0x11
000007fe`f84be065 : 00000000`00000001 00000000`00000000
00000000`0038d2a0 00000000`00000000 : mscorwks!CorExitProcess+0x4751
000007fe`f84b44de : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks!StrongNameErrorInfo
+0x6ae9
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks+0xf44de
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
2 Id: 1270.bf8 Suspend: 1 Teb: 000007ff`fffd9000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744b362 : 00000000`00000000 00000000`7744bedf
00000000`00000128 00000000`00000000 : ntdll!ZwWaitForMultipleObjects
+0xa
00000000`77434661 : 00000000`003a4330 00000000`00000000
00000000`00000000 00000000`00385dc0 : KERNEL32!FileTimeToSystemTime
+0xc2
000007fe`f8613573 : 00000000`00000000 00000000`00000001
00000000`00000000 00000000`00000001 : KERNEL32!WaitForMultipleObjects
+0x11
000007fe`f84c339a : 00000000`003a4300 000007fe`f8573d1e
ffffffff`fffffffe 00000000`003a4330 : mscorwks!CreateAssemblyNameObject
+0x4a3cf
000007fe`f84d8058 : 00000000`00000001 00000000`003862e0
00000002`00000000 000007fe`f8550936 : mscorwks!
StrongNameSignatureVerification+0x237e
000007fe`f85e91cd : 00000000`00000000 00000000`00000000
00000000`003a4330 00000000`1b03fd20 : mscorwks!GetCLRFunction+0xe46c
000007fe`f84cb22d : 00000000`003a4330 00000000`003a4330
00000000`1b03fc60 00000000`003a4330 : mscorwks!CreateAssemblyNameObject
+0x20029
000007fe`f84a460a : 00000000`1b03fd20 ffffffff`ffffffff
00000000`003a4330 00000000`00000001 : mscorwks!GetCLRFunction+0x1641
000007fe`f84bc424 : 00000000`003a4330 00000000`00000000
00000000`00000000 000007fe`00000008 : mscorwks+0xe460a
000007fe`f84aff88 : 00000002`00000000 00000000`00000000
00000000`00000000 000007fe`f84bc3b0 : mscorwks!StrongNameErrorInfo
+0x4ea8
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks+0xeff88
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
3 Id: 1270.6a8 Suspend: 1 Teb: 000007ff`fffd7000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744a9dc : 00000000`1ba9f688 00000000`00000000
00000000`00000001 000007fe`fe00e6b7 : ntdll!ZwRemoveIoCompletion+0xa
000007fe`fe0297b0 : 00000000`ffffffff 00000000`00000000
00000000`1b091820 00000000`00000000 : KERNEL32!
GetQueuedCompletionStatus+0x4c
000007fe`fe0296a8 : 00000000`00000000 00000000`000001a4
00000000`00380800 00000000`003ca1e0 : RPCRT4!I_RpcGetBufferWithObject
+0x2010
000007fe`fe011469 : 00000000`00000000 00000000`00009993
00000000`00000000 00000000`00860060 : RPCRT4!I_RpcGetBufferWithObject
+0x1f08
000007fe`fe01151b : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : RPCRT4!NdrComplexArrayMarshall
+0x519
000007fe`fe011584 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : RPCRT4!NdrComplexArrayMarshall
+0x5cb
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : RPCRT4!NdrComplexArrayMarshall
+0x634
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
4 Id: 1270.708 Suspend: 1 Teb: 000007ff`fffd3000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744b362 : 00000000`00010001 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!ZwWaitForMultipleObjects
+0xa
000007fe`f84d1da9 : 00000000`1b0736c0 00000000`00000000
00000000`00000000 000007fe`f84d5edf : KERNEL32!FileTimeToSystemTime
+0xc2
000007fe`f84d7495 : ffffffff`00000001 00000000`1b068388
00000000`1b0736c0 000007fe`f84ea274 : mscorwks!GetCLRFunction+0x81bd
000007fe`f8506501 : 00000000`00000000 00000000`1b068388
00000000`00000000 00000000`ffffffff : mscorwks!GetCLRFunction+0xd8a9
000007fe`f8603080 : 00000000`00000000 000007fe`f8542d1d
00000000`1b068388 000007fe`00000000 : mscorwks!CreateApplicationContext
+0x222e9
000007fe`f85bf9ca : ffffffff`fffffffe 00000000`00000001
00000000`1b13ad50 00000000`00000000 : mscorwks!CreateAssemblyNameObject
+0x39edc
000007fe`f84b50e9 : 00000000`1b068370 00000000`1bddf190
00000000`1b0736c0 00000000`1b0736c0 : mscorwks!CompareAssemblyIdentity
+0x9caf2
000007fe`f8619fe2 : 00000000`1b068370 00000000`1b068370
00000000`ffffffff 00000000`00000000 : mscorwks+0xf50e9
000007fe`f8a2fab5 : ffffffff`00000001 000007fe`f8567ebf
00000000`02874ff0 00000000`1b0736c0 : mscorwks!
GetMetaDataInternalInterfaceFromPublic+0x571e
000007fe`f6964a7a : 00000000`00000000 00000000`1bddf198
00000000`00000001 000007fe`f6990504 : mscorwks!PreBindAssembly+0x36c35
000007ff`0019268e : 00000000`02875420 000007ff`001e11c8
00000000`00000000 00000000`00000001 : mscorlib_ni!System.IO.TextWriter
+SyncTextWriter.Write(System.String)+0x2a
000007ff`00192511 : 00000000`02874ff0 00000000`028734d8
000007ff`00206c20 00000000`00000001 : nunit_console_runner!
NUnit.ConsoleRunner.EventCollector.TestStarted(NUnit.Core.TestName)
+0x8e
000007ff`0018bdc1 : 00000000`02a8c5f8 00000000`02874ff0
00000000`0287516c 00000000`00000001 : nunit_core!
NUnit.Core.TestStartedEvent.Send(NUnit.Core.EventListener)+0x21
000007fe`f68f174b : 00000000`02875570 000007fe`f6a41e40
00000000`1bddf160 00000000`00000000 : nunit_core!
NUnit.Core.EventPump.PumpThreadProc()+0x51
000007fe`f698956d : 000007ff`00042020 00000000`00000168
00000000`00000000 00000000`1bddf350 : mscorlib_ni!
System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext,
System.Threading.ContextCallback, System.Object)+0x9b
000007fe`f8692012 : 00000000`028ee270 00000000`ec0001ed
00000000`1b06eae0 00000023`77550000 : mscorlib_ni!
System.Threading.ThreadHelper.ThreadStart()+0x4d
000007fe`f8550243 : 00000000`77420000 00000000`00000000
00000000`77508cbc 00000000`00000000 : mscorwks!IEE+0xb0ea
000007fe`f855e49f : 00000000`1bddf4a8 00000000`00000001
00000000`00000000 00000000`1bddf6c8 : mscorwks!CompareAssemblyIdentity
+0x2d36b
000007fe`f8496765 : 00000000`1bddfb00 00000000`1bddfd40
00000000`1bddfba0 000007fe`f6a41e40 : mscorwks!CompareAssemblyIdentity
+0x3b5c7
000007fe`f84d8058 : 00000000`00000001 00000000`003862e0
00000002`00000000 000007fe`f8550936 : mscorwks+0xd6765
000007fe`f85e91cd : 00000000`00000000 00000000`00000000
00000000`1b0736c0 00000000`1bddfb00 : mscorwks!GetCLRFunction+0xe46c
000007fe`f84cb22d : 00000000`00000000 00000000`1b0736c0
00000000`1bddfa40 00000000`1bddfaa0 : mscorwks!CreateAssemblyNameObject
+0x20029
000007fe`f8611025 : 00000000`1bddfb00 ffffffff`ffffffff
00000000`1b0736c0 00000000`00000000 : mscorwks!GetCLRFunction+0x1641
000007fe`f86110ff : 00000000`1b0736c0 00000000`00000000
00000000`00000000 00000000`00000008 : mscorwks!CreateAssemblyNameObject
+0x47e81
000007fe`f84aff88 : 00000002`00000000 00000000`00000000
00000000`1b0736c0 00000000`1bddfbb8 : mscorwks!CreateAssemblyNameObject
+0x47f5b
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks+0xeff88
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
5 Id: 1270.4f0 Suspend: 1 Teb: 000007ff`fff0e000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744b362 : 000007ff`00232c78 000007ff`00048390
00000000`74cc3cd2 00000008`00000011 : ntdll!ZwWaitForMultipleObjects
+0xa
000007fe`f84d1da9 : 00000000`1b06e120 00000000`00000000
000007ff`00000000 000007fe`f84d5edf : KERNEL32!FileTimeToSystemTime
+0xc2
000007fe`f84d7495 : ffffffff`00000001 00000000`1b0682f8
00000000`1b06e120 000007fe`f84ea274 : mscorwks!GetCLRFunction+0x81bd
000007fe`f8506501 : 00000000`00000000 00000000`1b0682f8
00000000`00000000 00000000`ffffffff : mscorwks!GetCLRFunction+0xd8a9
000007fe`f8603080 : 00000000`1b0ad3d0 00000000`00000000
00000000`1b0682f8 00000000`00000000 : mscorwks!CreateApplicationContext
+0x222e9
000007fe`f85bf9ca : 00000000`00000000 00000000`00000001
00000000`00000000 00000000`00000000 : mscorwks!CreateAssemblyNameObject
+0x39edc
000007fe`f84b50e9 : 00000000`1b0682e0 00000000`ffffffff
00000000`1b06e120 00000000`1b0682e0 : mscorwks!CompareAssemblyIdentity
+0x9caf2
000007fe`f8619fe2 : 00000000`1b0682e0 00000000`1b0682e0
00000000`ffffffff 00000000`00000000 : mscorwks+0xf50e9
000007fe`f84fdf1b : 00000000`00000003 00000000`ffffffff
00000000`00387000 00000000`1b0682e0 : mscorwks!
GetMetaDataInternalInterfaceFromPublic+0x571e
000007fe`f8a9958f : 00000000`1b06e120 00000000`1bfde660
00000000`1bfde508 00000000`1b06e120 : mscorwks!CreateApplicationContext
+0x19d03
000007ff`0018cb32 : 00000000`1b0682e0 00000000`00000000
00000000`02ad2f78 00000000`02a8c5a8 : mscorwks!DeleteShadowCache
+0x318f
000007ff`00190e88 : 00000000`02875158 00000000`02a8c5a8
00000000`00000002 00000000`00000000 : nunit_core!
NUnit.Core.EventQueue.Enqueue(NUnit.Core.Event)+0x22
000007ff`0019077d : 00000000`02873438 00000000`02875158
00000000`02869b90 00000000`02869b90 : nunit_core!
NUnit.Core.TestCase.Run(NUnit.Core.EventListener)+0x168
000007ff`0018d9a8 : 00000000`02873438 00000000`02875158
00000000`02869b90 00000000`02869b90 : nunit_core!
NUnit.Core.TestCase.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0xd
000007ff`0018ce91 : 00000000`028b7828 00000000`029015d8
00000000`00000002 00000000`00000000 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018db89 : 00000000`00000000 00000000`00000000
0000a895`3077e062 000007fe`f841c220 : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018d9a8 : 00000000`028b7828 00000000`028ed7c8
00000000`02899730 00000000`02899730 : nunit_core!
NUnit.Core.TestFixture.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x79
000007ff`0018ce91 : 00000000`028e9f80 00000000`028ff1e8
00000000`00000000 00000000`028e9e48 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018d9a8 : 00000000`028f4200 000007fe`f69085f1
00000000`1bfdea90 48cc725e`aac9558b : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018ce91 : 00000000`028e9dd8 00000000`028fe918
00000000`00000000 00000000`028e9ca8 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018d9a8 : 00000000`028f4200 000007fe`f69085f1
00000000`1bfdebf0 48cc725e`aac9558b : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018ce91 : 00000000`028e9c38 00000000`028fe018
00000000`00000000 00000000`028e9b28 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018d9a8 : 00000000`028f4200 000007fe`f69085f1
00000000`1bfded50 48cc725e`aac9558b : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018ce91 : 00000000`028e9ab8 00000000`028f56b0
00000000`028f4e00 00000000`028e99e0 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018d9a8 : 00000000`028f4e00 000007ff`00203f20
00000000`00000000 00000000`02899730 : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018ce91 : 00000000`028e9970 00000000`028f4d50
00000000`028ed7c8 00000000`02899730 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018d9a8 : 00000000`02899730 00000000`028e9970
00000000`028f448c 00000000`02899730 : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018ce91 : 00000000`028e9568 00000000`028f4150
00000000`028ed7c8 00000000`02899730 : nunit_core!
NUnit.Core.TestSuite.RunAllTests(NUnit.Core.TestSuiteResult,
NUnit.Core.EventListener, NUnit.Core.ITestFilter)+0x128
000007ff`0018c661 : 00000000`028e9568 00000000`028ed7c8
00000000`02899730 00000000`00000000 : nunit_core!
NUnit.Core.TestSuite.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0x191
000007ff`0018c441 : 00000000`0286f1a0 00000000`02875158
00000000`02899730 00000000`00000001 : nunit_core!
NUnit.Core.SimpleTestRunner.Run(NUnit.Core.EventListener,
NUnit.Core.ITestFilter)+0xb1
000007fe`f68f174b : 00000000`028ee340 000007fe`f6a41e40
00000000`1bfdf130 00000000`00000000 : nunit_core!
NUnit.Core.TestRunnerThread.TestRunnerThreadProc()+0x51
000007fe`f698956d : 00000000`7763369a 00000000`00000008
00000000`00020000 00000000`00000000 : mscorlib_ni!
System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext,
System.Threading.ContextCallback, System.Object)+0x9b
000007fe`f8692012 : 00000000`028ee540 00000000`1bfdf558
00000000`1b06e6f0 0000001e`775500e8 : mscorlib_ni!
System.Threading.ThreadHelper.ThreadStart()+0x4d
000007fe`f8550243 : 00000000`00007265 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks!IEE+0xb0ea
000007fe`f855e49f : 00000000`1bfdf478 00000000`00000001
00000000`00000000 00000000`1bfdf698 : mscorwks!CompareAssemblyIdentity
+0x2d36b
000007fe`f8496765 : 00000000`1bfdfad0 00000000`1bfdfd90
00000000`1bfdfb70 000007fe`f6a41e40 : mscorwks!CompareAssemblyIdentity
+0x3b5c7
000007fe`f84d8058 : 00000000`00000001 00000000`003862e0
00000002`00000000 000007fe`f8550936 : mscorwks+0xd6765
000007fe`f85e91cd : 00000000`00000000 00000000`00000000
00000000`1b06e120 00000000`1bfdfad0 : mscorwks!GetCLRFunction+0xe46c
000007fe`f84cb22d : 00000000`00000000 00000000`1b06e120
00000000`1bfdfa10 00000000`1bfdfa70 : mscorwks!CreateAssemblyNameObject
+0x20029
000007fe`f8611025 : 00000000`1bfdfad0 ffffffff`ffffffff
00000000`1b06e120 00000000`00000000 : mscorwks!GetCLRFunction+0x1641
000007fe`f86110ff : 00000000`1b06e120 00000000`00000000
00000000`00000000 00000000`00000008 : mscorwks!CreateAssemblyNameObject
+0x47e81
000007fe`f84aff88 : 00000002`00000000 00000000`00000000
00000000`1b06e120 00000000`1bfdfb88 : mscorwks!CreateAssemblyNameObject
+0x47f5b
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks+0xeff88
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
6 Id: 1270.9e8 Suspend: 1 Teb: 000007ff`fff0a000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744c730 : 00000000`00000000 00000000`00000010
00000000`1c6bf820 00000000`00000000 : ntdll!NtWaitForSingleObject+0xa
00000642`ff3f19b6 : 00000000`00000520 00000000`00000000
00000000`00000000 00000000`00000520 : KERNEL32!WaitForSingleObjectEx
+0xa0
00000642`ff3f2120 : 00000000`0000052c 00000000`00000000
00000000`00000000 00000000`00000000 : aspnet_perf+0x19b6
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : aspnet_perf!ClosePerfCommonData
+0x20
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
7 Id: 1270.1260 Suspend: 1 Teb: 000007ff`fff08000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744c730 : 00000000`00000000 00000000`1bab2820
00000000`1bab27e0 00000000`00000000 : ntdll!NtWaitForSingleObject+0xa
00000642`ff3f3584 : 00000000`00000518 00000000`00000000
00000000`00000000 00000000`00000518 : KERNEL32!WaitForSingleObjectEx
+0xa0
00000642`ff3f3790 : 00000642`ff3f8170 00000000`00000000
00000000`00000000 00000000`00000000 : aspnet_perf!
CollectStateServicePerfData+0xc94
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : aspnet_perf!
CollectVersionedPerfData+0x40
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
8 Id: 1270.d68 Suspend: 1 Teb: 000007ff`ffefc000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`775910be : 00000000`1b07f850 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!
NtWaitForWorkViaWorkerFactory+0xa
00000000`7744466d : 00000000`1b07f850 00000000`00000000
00000000`1b07f850 00000000`00000000 : ntdll!RtlSizeHeap+0x11fe
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
9 Id: 1270.13d8 Suspend: 1 Teb: 000007ff`fff0c000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`7744b362 : 00000000`1cb3e610 00000000`00000000
ffffffff`fffffffe 00000000`00000000 : ntdll!ZwWaitForMultipleObjects
+0xa
000007fe`f84d1da9 : 00000000`003a3ce0 00000000`00000000
00000000`00000000 000007fe`f84d5edf : KERNEL32!FileTimeToSystemTime
+0xc2
000007fe`f84d7495 : ffffffff`00000001 00000000`1b0682f8
00000000`003a3ce0 000007fe`f84ea274 : mscorwks!GetCLRFunction+0x81bd
000007fe`f8506501 : 00000000`00000000 00000000`1b0682f8
00000000`00000000 00000000`ffffffff : mscorwks!GetCLRFunction+0xd8a9
000007fe`f8603080 : 00000000`003870f0 000007fe`f8a97183
00000000`1b0682f8 000007fe`00000000 : mscorwks!CreateApplicationContext
+0x222e9
000007fe`f85bf9ca : ffffffff`fffffffe 00000000`00000001
00000000`003870f0 00000000`00000000 : mscorwks!CreateAssemblyNameObject
+0x39edc
000007fe`f84b50e9 : 00000000`1b0682e0 00000000`ffffffff
00000000`003a3ce0 00000000`1b0682e0 : mscorwks!CompareAssemblyIdentity
+0x9caf2
000007fe`f8619fe2 : 00000000`1b0682e0 00000000`1b0682e0
00000000`ffffffff 00000000`00000000 : mscorwks+0xf50e9
000007fe`f84fdf1b : 00000000`00000001 00000000`ffffffff
00000000`00387000 00000000`1b0682e0 : mscorwks!
GetMetaDataInternalInterfaceFromPublic+0x571e
000007fe`f8a9958f : 00000000`003a3ce0 00000000`1cb3ea00
00000000`1cb3e8a8 00000000`003a3ce0 : mscorwks!CreateApplicationContext
+0x19d03
000007ff`0018cb32 : 00000000`1b0682e0 00000000`00000000
00000000`02ab9ac0 00000000`02ab9aa0 : mscorwks!DeleteShadowCache
+0x318f
000007ff`0018e11c : 00000000`02875158 00000000`02ab9aa0
00000000`00000000 00000000`00000001 : nunit_core!
NUnit.Core.EventQueue.Enqueue(NUnit.Core.Event)+0x22
000007fe`f6990d2d : 00000000`00000000 000007fe`f69924b2
00000000`00000032 000007fe`f6990504 : nunit_core!
NUnit.Core.EventListenerTextWriter.WriteLine(System.String)+0x6c
000007ff`00191f7d : 00000000`02875420 00000000`00000032
00000000`1cb3e7a8 00000000`1b068220 : mscorlib_ni!System.IO.TextWriter
+SyncTextWriter.WriteLine(System.String)+0x3d
000007ff`0019092a : 00000000`0287dd08 00000000`0287dd08
00000000`02a7cf20 00000000`02a7d0a0 : -- ommitted -- from new thread
created from instance constructor of class marked as TestFixture
000007fe`f68f174b : 00000000`0287df18 000007fe`f6a41e40
00000000`1cb3eb10 00000000`00000000 : -- ommitted -- from new thread
created from instance constructor of class marked as TestFixture
000007fe`f698956d : 00000000`1b970158 00000000`00000008
00000000`1b97001e 00000000`00000000 : mscorlib_ni!
System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext,
System.Threading.ContextCallback, System.Object)+0x9b
000007fe`f8692012 : 00000000`02a7d230 00000000`7759e8ed
00000000`776356c0 00000000`003562e0 : mscorlib_ni!
System.Threading.ThreadHelper.ThreadStart()+0x4d
000007fe`f8550243 : 00000000`00000000 00000000`1cb3ef88
00000080`1b97a6b0 00000000`00000000 : mscorwks!IEE+0xb0ea
000007fe`f855e49f : 00000000`1cb3ee58 00000000`00000001
00000000`00000000 00000000`1cb3f078 : mscorwks!CompareAssemblyIdentity
+0x2d36b
000007fe`f8496765 : 00000000`1cb3f4b0 00000000`1cb3f7f0
00000000`1cb3f550 000007fe`f6a41e40 : mscorwks!CompareAssemblyIdentity
+0x3b5c7
000007fe`f84d8058 : 00000000`00000001 00000000`003862e0
00000002`00000000 000007fe`f8550936 : mscorwks+0xd6765
000007fe`f85e91cd : 00000000`00000000 00000000`00000000
00000000`003a3ce0 00000000`1cb3f4b0 : mscorwks!GetCLRFunction+0xe46c
000007fe`f84cb22d : 00000000`00000000 00000000`003a3ce0
00000000`1cb3f3f0 00000000`1cb3f450 : mscorwks!CreateAssemblyNameObject
+0x20029
000007fe`f8611025 : 00000000`1cb3f4b0 ffffffff`ffffffff
00000000`003a3ce0 00000000`00000000 : mscorwks!GetCLRFunction+0x1641
000007fe`f86110ff : 00000000`003a3ce0 00000000`00000000
00000000`00000000 00000000`00000008 : mscorwks!CreateAssemblyNameObject
+0x47e81
000007fe`f84aff88 : 00000002`00000000 00000000`00000000
00000000`003a3ce0 00000000`1cb3f568 : mscorwks!CreateAssemblyNameObject
+0x47f5b
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : mscorwks+0xeff88
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
# 10 Id: 1270.650 Suspend: 1 Teb: 000007ff`fffd5000 Unfrozen
RetAddr : Args to
Child : Call
Site
00000000`77618778 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!DbgBreakPoint
00000000`7744466d : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!DbgUiRemoteBreakin+0x38
00000000`77578791 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000
00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
Thanks Rags
> > queue, the lock down and possibledeadlockscenarios. In one
> > of our tests, writing to the console from one of the
> > background threads in test suite caused adeadlock. This
> > background thread is not a part of any TextFixture class, but
> > a singleton class that is statically instantiated and
> > periodically triggers certain actions that are needed for the
> > test. It appears that writing to console may not be "safe"
> > under all circumstances. We want to understand the NUnit
> > internals a bit better here, and find out when it is ok and
> > when it is not.
>
> > thanks,
> > -Arun.
>
> > On Feb 8, 2:24 am, RJV <jv.ravichand...@gmail.com> wrote:
> > > Hi Arun,
>
> > > Will using /out:TestResult.txt switch solve your problem? Or if you
> > > want to catch the error outputs use the /err: option
>
> > > Other options you can use with the console runner is
> > > here:http://www.nunit.org/index.php?p=consoleCommandLine&r=2.2.5
>
> > > Yes, logging is also an useful way to do it but it may take
> > a lot of
> > > space at times...depends on your preference.
>
> > > HTH
>
> > > Jv
>
> > > On Fri, Feb 5, 2010 at 1:23 AM, Arun Lakshminarayanan
> > <buzzs...@gmail.com>wrote:
>
> > > > We noticed that some of our unittest exeuctions hung and looking
> > > > through the stack trace - we spotted adeadlockarising from
Charlie Poole
I'll spend some time looking at the stack traces today.
A few general comments / ideas...
Creating a thread in the test fixture constructor seems to
me like a bad idea. You have no knowledge of when or how
often that constructor is used by NUnit. In fact, in some
circumstances it could be used at the time the test is
loaded or reloaded - even before it is run! If you need
to create a thread that will run for the life of a single
test, do it in a setup method. If you want it to run for
the life of the entire fixture, do it in a testfixture
setup method. This may not be causing your problem, but
I suggest making the change anyway. Of course, you should
make sure the thread has terminated in the corresponding
teardown method as well.
Are you using any non-default timeout setting? if so,
remove it as an experiment. A non-zero timeout causes a
thread to be created for each test.
NUnit is open source software, so you can, of course,
examine the source code all you want. Just download the
source package for the version you are using. If you
like, you can compile it as debug in order to check
out your problem.
Also, I repeat my request to have some other eyes - yours
or anyone on the list - review the code for EventQueue
and EventPump looking for potential deadlocks. It seems
almost certain that this is where the problem lies.
Charlie
> -----Original Message-----
> From: nunit-...@googlegroups.com
> [mailto:nunit-...@googlegroups.com] On Behalf Of Rags
> Sent: Wednesday, February 24, 2010 4:39 PM
> To: NUnit-Discuss
> Subject: [nunit-discuss] Re: Console Writes from nunit tests
>
Rags
No, we do NOT use any non-default timeout settings. We do use '/
domain=none' if that matters.
I agree with your comment about constructor vs setup method - I made
the similar observation but felt that probably is not the real cause
here. We'll plan on changing that nonetheless.
I'll need to check with legal of our company before looking at source
code to make sure we'll be ok. But I'll try...
Thanks Rags
> ...
>
> read more »- Hide quoted text -