Unit Test Adapter threw exception: System.NullReferenceException

Hello,

maybe anyone can provide a solution to the following scenario.

I have a device project that compiles fine and I have a unit test project for this device project that was working well too. After signing the assemblies the tests do not run anymore. But it's not the tests that are failing. If I debug the tests I see that all my test code is executed without any failure. After the test the TestCleanup method is also executed. The code within this method is executed fine too but when the method is finished the test immediately displays the Error result with the following error message: "Unit Test Adapter threw exception: System.NullReferenceException: Object reference not set to an instance of an object.."

Code coverage (that was working before signing the assemblies) has been disabled.

Can anyone explain what's going on behind the scenes? Maybe there is any hint how to find out the exact reason for this error?

Kind regards,

Lars Roith

[1006 byte] By [LarsRoith] at [2007-12-31]
# 1

Hi Lars,

To clarify, are you using VS2005?

Thanks,

David Williamson

DavidR.WilliamsonMSFT at 2007-9-6 > top of Msdn Tech,Visual Studio Team System,Visual Studio Team System - Web and Load Testing...
# 2
Hi David,

yes I do use VS2005 or to be exactly VSTS.
I was able to solve the problem. One of the components used in the test had destructors that caused failures. It's really tricky to find such mistakes so although the problem is solved is there any hint on how to debug tests in a scenario like mine?

Kind regards,

Lars

LarsRoith at 2007-9-6 > top of Msdn Tech,Visual Studio Team System,Visual Studio Team System - Web and Load Testing...
# 3

Lars, you can enable tracing for Testing components, we usually ask for the trace log file when there is not enough information for the problem, like in this case. This give us diagnostics info and often helps to find the issue.

To enable tracing for test execution issues, do the following:
- open vstesthost.exe.config in notepad (the file is located next to ..\Program Files\Microsoft Visual Studio 8\Common7\IDE\vstesthost.exe, the process the tests are running in)
- add the <system.diagnostics> following section in front of </configuration> at the end of the file, like this:

<?xml version ="1.0"?>
<configuration>
<runtime>
<assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
<probing privatePath="PrivateAssemblies;PublicAssemblies"/>
</assemblyBinding>
</runtime>
<system.diagnostics>
<trace autoflush="true" indentsize="4">
<listeners>
<add name="EqtListener"
type="Microsoft.VisualStudio.TestTools.Common.EqtTextWriterTraceListener, Microsoft.VisualStudio.QualityTools.Common"
initializeData="C:\VstesthostTrace.log" />
</listeners>
</trace>
<switches>
<!-- use integral values for "value". 0 = off, 1 = error, 2 = warn, 3 = info, 4 = verbose. -->
<add name="EqtTraceLevel" value="4" />
</switches>
</system.diagnostics>

</configuration>

The trace will be saved into C:\VstesthostTrace.log.

To enable tracing for VS or mstest.exe, do the same but for devenv.exe.config and mstest.exe.config respetively. We recommend to use different trace files for different processes.

Thank you,
Michael Koltachev, VSTS

MichaelKoltachev-MS at 2007-9-6 > top of Msdn Tech,Visual Studio Team System,Visual Studio Team System - Web and Load Testing...
# 4

Hi Michael,

I am getting the same error. I debugged through the end of the test case including the Dispose and Finalizer, etc. and did not see any problem still.

Unit Test Adapter threw exception: System.NullReferenceException: Object reference not set to an instance of an object.

I have enabled the tracing as you suggested above and attached it below. Any hellp is greatly appreciated.

Thanks
Qin

[V, 5612, 1, 2007/03/05 15:37:49.213 57000110181752] vstesthost.exe: Opening events...
[V, 5612, 1, 2007/03/05 15:37:49.228 57000123950912] vstesthost.exe: Opened events successfully.
[V, 5612, 1, 2007/03/05 15:37:49.228 57000136476648] vstesthost.exe: Successfully registered channels, pipe name: eqt-0c8f7327-e2b1-693b-4dd9-754acffe4f4f-3901025638768.
[I, 5612, 1, 2007/03/05 15:37:49.228 57000142493720] vstesthost.exe: Creating ControllerObject local case
[V, 5612, 1, 2007/03/05 15:37:49.244 57000183152760] vstesthost.exe: Host process: Successfully published Controller.
[V, 5612, 1, 2007/03/05 15:37:49.244 57000183596000] vstesthost.exe: Host process: Waiting for IDE to finish the run...
[V, 5612, 5, 2007/03/05 15:37:49.244 57000188187600] vstesthost.exe: Hello
[V, 5612, 5, 2007/03/05 15:37:49.432 57000806560984] vstesthost.exe: ** Created FileCopyService w security: null
[V, 5612, 5, 2007/03/05 15:37:49.432 57000806869264] vstesthost.exe: ** Created FileCopyService w2
[I, 5612, 5, 2007/03/05 15:37:49.447 57000819818104] vstesthost.exe: Calling QueueTestRun on specialized object
[I, 5612, 5, 2007/03/05 15:37:49.447 57000839097080] vstesthost.exe: Seach Path added to assembly resolver: D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\Out
[I, 5612, 5, 2007/03/05 15:37:49.447 57000854696112] vstesthost.exe: Advise - Current User: REDMOND\qinzhang
[I, 5612, 5, 2007/03/05 15:37:49.463 57000884809864] vstesthost.exe: Regsitering: 0af0faa5-8998-47ec-9e1c-568b9d066d98
[I, 5612, 8, 2007/03/05 15:37:49.463 57000888033424] vstesthost.exe: calling AgentObject to start test run
[I, 5612, 8, 2007/03/05 15:37:49.463 57000894195000] vstesthost.exe: Calling back into HA for deployment settings and values
[I, 5612, 8, 2007/03/05 15:37:49.478 57000920874656] vstesthost.exe: Setting __testDeploymentDir == D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\Out
[I, 5612, 8, 2007/03/05 15:37:49.478 57000921158224] vstesthost.exe: Setting __testLogsDir == D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\In\HEDGEHOG
[I, 5612, 8, 2007/03/05 15:37:49.478 57000921338552] vstesthost.exe: Setting __testDir == D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48
[I, 5612, 8, 2007/03/05 15:37:49.478 57000921473960] vstesthost.exe: Setting __AgentId == 1
[I, 5612, 8, 2007/03/05 15:37:49.478 57000921631304] vstesthost.exe: Setting __AgentWeighting == 100
[I, 5612, 8, 2007/03/05 15:37:49.478 57000921763168] vstesthost.exe: Setting __TotalAgents == 1
[V, 5612, 8, 2007/03/05 15:37:49.478 57000933982608] vstesthost.exe: Enqueing deployment job
[V, 5612, 8, 2007/03/05 15:37:49.478 57000964573936] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test '' with id {00000000-0000-0000-0000-000000000000}: MessageKind: RunStateChanged
[V, 5612, 8, 2007/03/05 15:37:49.494 57000968569560] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 8, 2007/03/05 15:37:49.494 57000981805128] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 9, 2007/03/05 15:37:49.525 57001083454208] vstesthost.exe: ExecutionTimeouts are disabled.
[V, 5612, 9, 2007/03/05 15:37:49.525 57001093449600] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test '' with id {00000000-0000-0000-0000-000000000000}: MessageKind: RunStateChanged
[V, 5612, 10, 2007/03/05 15:37:49.525 57001095471616] vstesthost.exe: ResultQueueThread waiting...
[V, 5612, 9, 2007/03/05 15:37:49.525 57001095983000] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 9, 2007/03/05 15:37:49.525 57001098051600] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 9, 2007/03/05 15:37:49.525 57001098270584] vstesthost.exe: Deployment thread exiting.
[I, 5612, 11, 2007/03/05 15:37:49.541 57001138278056] vstesthost.exe: Agent Object: runlocation:Local
[V, 5612, 11, 2007/03/05 15:37:49.541 57001149872248] vstesthost.exe: ControllerTask loading plugins for 1 elements.
[V, 5612, 11, 2007/03/05 15:37:49.557 57001168480912] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test '' with id {00000000-0000-0000-0000-000000000000}: MessageKind: RunStart
[V, 5612, 11, 2007/03/05 15:37:49.557 57001171010736] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 11, 2007/03/05 15:37:49.635 57001447295144] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 11, 2007/03/05 15:37:49.635 57001452601408] vstesthost.exe: Registering for timeout callbacks
[I, 5612, 11, 2007/03/05 15:37:49.650 57001480588264] vstesthost.exe: Using 1 agent(s) for test run
[V, 5612, 11, 2007/03/05 15:37:49.650 57001486087520] vstesthost.exe: making Async call to start test locally: HEDGEHOG
[I, 5612, 11, 2007/03/05 15:37:49.650 57001486543944] vstesthost.exe: Setting __testDeploymentDir == D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\Out
[I, 5612, 11, 2007/03/05 15:37:49.650 57001486729656] vstesthost.exe: Setting __testLogsDir == D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\In\HEDGEHOG
[I, 5612, 11, 2007/03/05 15:37:49.650 57001486865944] vstesthost.exe: Setting __testDir == D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48
[I, 5612, 11, 2007/03/05 15:37:49.650 57001487031568] vstesthost.exe: Setting __AgentId == 1
[I, 5612, 11, 2007/03/05 15:37:49.650 57001487163808] vstesthost.exe: Setting __AgentWeighting == 100
[I, 5612, 11, 2007/03/05 15:37:49.650 57001487293208] vstesthost.exe: Setting __TotalAgents == 1
[V, 5612, 11, 2007/03/05 15:37:49.650 57001502532592] vstesthost.exe: Calling endinvoke for inproc agent start call:HEDGEHOG
[V, 5612, 12, 2007/03/05 15:37:49.650 57001508123168] vstesthost.exe: Agent Object starting a test case
[V, 5612, 12, 2007/03/05 15:37:49.666 57001532177616] vstesthost.exe: Attempting to load adapters
[I, 5612, 12, 2007/03/05 15:37:49.666 57001546124696] vstesthost.exe: Attempting to load adapter: Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestAdapter, Microsoft.VisualStudio.QualityTools.Tips.UnitTest.Adapter, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a
[I, 5612, 12, 2007/03/05 15:37:49.682 57001567041472] vstesthost.exe: calling initialize on adapter: Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestAdapter, Microsoft.VisualStudio.QualityTools.Tips.UnitTest.Adapter, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a
[I, 5612, 12, 2007/03/05 15:37:49.682 57001570914024] vstesthost.exe: UnitTestAdapter.Initialize called
[I, 5612, 12, 2007/03/05 15:37:49.682 57001582058944] vstesthost.exe: Attempting to load adapter: Microsoft.VisualStudio.TestTools.HostAdapters.AspNetPlugin, Microsoft.VisualStudio.QualityTools.HostAdapters.ASPNETAgent, Version=8.0.0.0, PublicKeyToken=b03f5f7f11d50a3a
[I, 5612, 12, 2007/03/05 15:37:49.682 57001588993232] vstesthost.exe: calling BeforeExecutionStarted on adapter: Microsoft.VisualStudio.TestTools.HostAdapters.AspNetPlugin, Microsoft.VisualStudio.QualityTools.HostAdapters.ASPNETAgent, Version=8.0.0.0, PublicKeyToken=b03f5f7f11d50a3a
[V, 5612, 17, 2007/03/05 15:37:49.713 57001682314592] vstesthost.exe: Enqueing message kind: TestStart
[V, 5612, 15, 2007/03/05 15:37:49.713 57001682822440] vstesthost.exe: Dequeing message kind: TestStart
[V, 5612, 15, 2007/03/05 15:37:49.713 57001683158776] vstesthost.exe: Broadcasting message kind: TestStart
[V, 5612, 15, 2007/03/05 15:37:49.713 57001705072152] vstesthost.exe: Enqueing message kind: TestStart
[V, 5612, 15, 2007/03/05 15:37:49.713 57001705427624] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 10, 2007/03/05 15:37:49.713 57001705483272] vstesthost.exe: ResultQueueThread processing...
[V, 5612, 15, 2007/03/05 15:37:49.713 57001705900232] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:49.713 57001706386552] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 10, 2007/03/05 15:37:49.728 57001718127960] vstesthost.exe: Dequeing message kind: TestStart
[V, 5612, 10, 2007/03/05 15:37:49.728 57001718817160] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TestStart
[V, 5612, 10, 2007/03/05 15:37:49.728 57001721031016] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 10, 2007/03/05 15:37:49.728 57001726946088] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:49.728 57001727299872] vstesthost.exe: Time to send TRM to HA: 0
[V, 5612, 10, 2007/03/05 15:37:49.728 57001727440696] vstesthost.exe: ResultQueueThread waiting...
[I, 5612, 18, 2007/03/05 15:37:49.744 57001791393856] vstesthost.exe: UnitTestAdapter executing test TTraceInfo ID={404bd687-9b58-7965-5351-785a16a4e41f}
[V, 5612, 18, 2007/03/05 15:37:49.744 57001803654824] vstesthost.exe: UnitTestAdapter: test: TTraceInfo, using code base: D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\Out\TracingTest.dll
[V, 5612, 18, 2007/03/05 15:37:49.744 57001813055960] vstesthost.exe: UnitTestAdapter.CreateAppDomain: start
[I, 5612, 18, 2007/03/05 15:37:49.947 57002443027744] vstesthost.exe: UnitTestAdapter.CreateAppDomain: finished, AppBase = D:\ACDMDev\private\ACDM\Registration\dev\sln\TestResults\qinzhang_HEDGEHOG 2007-03-05 15_37_48\Out\TracingTest.dll
[V, 5612, 18, 2007/03/05 15:37:50.541 57004309581960] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.541 57004310066400] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.541 57004330161952] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.541 57004330481392] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.541 57004330637288] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.541 57004330787216] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.541 57004330926472] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 10, 2007/03/05 15:37:50.541 57004331110416] vstesthost.exe: ResultQueueThread processing...
[V, 5612, 10, 2007/03/05 15:37:50.541 57004331281544] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.541 57004334928728] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.541 57004337218136] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 10, 2007/03/05 15:37:50.557 57004371400648] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.557 57004371715008] vstesthost.exe: Time to send TRM to HA: 15
[V, 5612, 10, 2007/03/05 15:37:50.557 57004371882816] vstesthost.exe: ResultQueueThread waiting...
[V, 5612, 18, 2007/03/05 15:37:50.619 57004588329768] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.619 57004588862752] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.619 57004589251080] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.619 57004589481720] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.619 57004589638296] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 10, 2007/03/05 15:37:50.619 57004589671744] vstesthost.exe: ResultQueueThread processing...
[V, 5612, 15, 2007/03/05 15:37:50.619 57004589806696] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 10, 2007/03/05 15:37:50.619 57004590021760] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.619 57004590066512] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 10, 2007/03/05 15:37:50.619 57004590245152] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.619 57004592389176] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 18, 2007/03/05 15:37:50.635 57004613021296] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004613392928] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004613566816] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004613775872] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004613918320] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004614051688] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004614184288] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 18, 2007/03/05 15:37:50.635 57004620023424] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004620374208] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004620541888] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004620736408] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004620889312] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004621024864] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004621157048] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 18, 2007/03/05 15:37:50.635 57004628412472] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004628821896] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.635 57004628842072] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.635 57004629204656] vstesthost.exe: Time to send TRM to HA: 15
[V, 5612, 15, 2007/03/05 15:37:50.635 57004629012896] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.635 57004629426216] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004629539704] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.635 57004629642120] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004629688136] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004629951728] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004630085112] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 10, 2007/03/05 15:37:50.635 57004631810120] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 18, 2007/03/05 15:37:50.635 57004634198416] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004634935264] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004635124704] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004635340616] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004635483144] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004635617624] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004635760848] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 18, 2007/03/05 15:37:50.635 57004640017872] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004640329384] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004640499400] vstesthost.exe: Broadcasting message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004640688424] vstesthost.exe: Enqueing message kind: TextMessage
[V, 5612, 15, 2007/03/05 15:37:50.635 57004640842088] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004640975144] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.635 57004641107776] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 10, 2007/03/05 15:37:50.650 57004664315560] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.650 57004664637728] vstesthost.exe: Time to send TRM to HA: 16
[V, 5612, 10, 2007/03/05 15:37:50.650 57004664861176] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.650 57004665060248] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.650 57004667263512] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 10, 2007/03/05 15:37:50.650 57004699206840] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.650 57004699533008] vstesthost.exe: Time to send TRM to HA: 0
[V, 5612, 10, 2007/03/05 15:37:50.650 57004699756376] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.650 57004699953920] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.650 57004702114224] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[E, 5612, 18, 2007/03/05 15:37:50.666 57004712744064] vstesthost.exe: UnitTestRunner threw exception or failed to load dependencies!!System.NullReferenceException: Object reference not set to an instance of an object.
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestRunner.Run(UnitTestElement test, ITestContext testContext, Boolean isLoadTest)
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestRunner.Run(UnitTestElement test, ITestContext testContext, Boolean isLoadTest)
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestAdapter.Run(ITestElement testElement, ITestContext testContext, Boolean isLoadTest) at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestRunner.Run(UnitTestElement test, ITestContext testContext, Boolean isLoadTest)
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestRunner.Run(UnitTestElement test, ITestContext testContext, Boolean isLoadTest)
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestAdapter.Run(ITestElement testElement, ITestContext testContext, Boolean isLoadTest)
[E, 5612, 18, 2007/03/05 15:37:50.666 57004720906536] vstesthost.exe: Unit Test Adapter threw exception: System.NullReferenceException: Object reference not set to an instance of an object.
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestRunner.Run(UnitTestElement test, ITestContext testContext, Boolean isLoadTest)
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestRunner.Run(UnitTestElement test, ITestContext testContext, Boolean isLoadTest)
at Microsoft.VisualStudio.TestTools.TestTypes.Unit.UnitTestAdapter.Run(ITestElement testElement, ITestContext testContext, Boolean isLoadTest)
[V, 5612, 18, 2007/03/05 15:37:50.666 57004723028112] vstesthost.exe: Enqueing message kind: Result
[V, 5612, 15, 2007/03/05 15:37:50.666 57004723312528] vstesthost.exe: Dequeing message kind: Result
[V, 5612, 15, 2007/03/05 15:37:50.666 57004723485976] vstesthost.exe: Broadcasting message kind: Result
[V, 5612, 15, 2007/03/05 15:37:50.666 57004723682672] vstesthost.exe: Enqueing message kind: Result
[V, 5612, 15, 2007/03/05 15:37:50.666 57004723822864] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.666 57004723967504] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.666 57004724099768] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 17, 2007/03/05 15:37:50.666 57004727327368] vstesthost.exe: Enqueing message kind: TestEnd
[V, 5612, 10, 2007/03/05 15:37:50.666 57004734247896] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.666 57004734575720] vstesthost.exe: Time to send TRM to HA: 16
[V, 5612, 10, 2007/03/05 15:37:50.666 57004734799024] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.666 57004734996288] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.666 57004737053648] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[I, 5612, 17, 2007/03/05 15:37:50.666 57004737463968] vstesthost.exe: Agent Object cleaning up adapters
[V, 5612, 10, 2007/03/05 15:37:50.682 57004768820440] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.682 57004769171560] vstesthost.exe: Time to send TRM to HA: 15
[V, 5612, 10, 2007/03/05 15:37:50.682 57004769395856] vstesthost.exe: Dequeing message kind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.682 57004769599400] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TextMessage
[V, 5612, 10, 2007/03/05 15:37:50.682 57004771686464] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 17, 2007/03/05 15:37:50.682 57004776224128] vstesthost.exe: Enqueing message kind: RunOutput
[I, 5612, 17, 2007/03/05 15:37:50.682 57004783897208] vstesthost.exe: UnitTestAdapter.Cleanup called
[V, 5612, 17, 2007/03/05 15:37:50.682 57004784154200] vstesthost.exe: UnitTestAdapter.Cleanup: unloading AppDomain...
[V, 5612, 15, 2007/03/05 15:37:50.682 57004784493264] vstesthost.exe: Dequeing message kind: TestEnd
[V, 5612, 15, 2007/03/05 15:37:50.682 57004784672800] vstesthost.exe: Broadcasting message kind: TestEnd
[V, 5612, 15, 2007/03/05 15:37:50.682 57004784868920] vstesthost.exe: Enqueing message kind: TestEnd
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785011920] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785145160] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785287504] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785443176] vstesthost.exe: Dequeing message kind: RunOutput
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785598576] vstesthost.exe: Broadcasting message kind: RunOutput
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785813072] vstesthost.exe: Enqueing message kind: RunOutput
[V, 5612, 15, 2007/03/05 15:37:50.682 57004785951080] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.682 57004786082720] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.682 57004786215160] vstesthost.exe: Time to send TRM to Controller: 0
[V, 5612, 17, 2007/03/05 15:37:50.682 57004799057528] vstesthost.exe: UnitTestAdapter.Cleanup: unloading AppDomain succeeded.
[V, 5612, 17, 2007/03/05 15:37:50.682 57004799407512] vstesthost.exe: UnitTestAdapter.Cleanup finished successfully
[V, 5612, 10, 2007/03/05 15:37:50.682 57004803786184] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.682 57004804103000] vstesthost.exe: Time to send TRM to HA: 0
[V, 5612, 10, 2007/03/05 15:37:50.682 57004804328416] vstesthost.exe: Dequeing message kind: Result
[V, 5612, 17, 2007/03/05 15:37:50.682 57004804334304] vstesthost.exe: Agent Object: TestRunComplete called: stop == False
[V, 5612, 17, 2007/03/05 15:37:50.682 57004804694056] vstesthost.exe: Checking list count:0
[V, 5612, 17, 2007/03/05 15:37:50.682 57004804845424] vstesthost.exe: Clear: restartdata being deleted.
[V, 5612, 10, 2007/03/05 15:37:50.697 57004807356368] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: Result, Outcome: Error
[V, 5612, 17, 2007/03/05 15:37:50.697 57004808856064] vstesthost.exe: CleanupPlugin called
[V, 5612, 17, 2007/03/05 15:37:50.697 57004809180968] vstesthost.exe: CleanupPlugin count:System.Collections.ArrayList
[V, 5612, 10, 2007/03/05 15:37:50.697 57004809576456] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 17, 2007/03/05 15:37:50.697 57004820025392] vstesthost.exe: Cleaning up global adapters
[I, 5612, 16, 2007/03/05 15:37:50.697 57004823985880] vstesthost.exe: Monitor thread triggered to exit, m_stop = True
[I, 5612, 16, 2007/03/05 15:37:50.697 57004824341752] vstesthost.exe: Sending RunEndEvent
[V, 5612, 16, 2007/03/05 15:37:50.697 57004827295784] vstesthost.exe: SendRunEndEvent called.
[V, 5612, 16, 2007/03/05 15:37:50.697 57004828185832] vstesthost.exe: Enqueing message kind: RunEnd
[V, 5612, 16, 2007/03/05 15:37:50.697 57004829784008] vstesthost.exe: MonitorExecutionThread: exiting.
[V, 5612, 15, 2007/03/05 15:37:50.697 57004831053288] vstesthost.exe: Dequeing message kind: RunEnd
[V, 5612, 15, 2007/03/05 15:37:50.697 57004831283568] vstesthost.exe: Broadcasting message kind: RunEnd
[V, 5612, 15, 2007/03/05 15:37:50.697 57004832590408] vstesthost.exe: NotifyHostApplication called.
[V, 5612, 15, 2007/03/05 15:37:50.697 57004834211672] vstesthost.exe: Enqueing message kind: RunEnd
[V, 5612, 15, 2007/03/05 15:37:50.697 57004834538904] vstesthost.exe: Time For ControllerTask to queue message: 0
[V, 5612, 15, 2007/03/05 15:37:50.697 57004834682624] vstesthost.exe: Total Time for controllertask to process message: 0
[V, 5612, 15, 2007/03/05 15:37:50.697 57004834815008] vstesthost.exe: AgentResultSink thread exiting
[V, 5612, 10, 2007/03/05 15:37:50.697 57004835822784] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.697 57004836000232] vstesthost.exe: Time to send TRM to HA: 16
[V, 5612, 10, 2007/03/05 15:37:50.697 57004836181576] vstesthost.exe: Dequeing message kind: TestEnd
[V, 5612, 10, 2007/03/05 15:37:50.697 57004839219504] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test 'TTraceInfo' with id {404bd687-9b58-7965-5351-785a16a4e41f}: MessageKind: TestEnd
[V, 5612, 10, 2007/03/05 15:37:50.697 57004841451592] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 10, 2007/03/05 15:37:50.697 57004845458056] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.697 57004845744736] vstesthost.exe: Time to send TRM to HA: 0
[V, 5612, 10, 2007/03/05 15:37:50.697 57004845937288] vstesthost.exe: Dequeing message kind: RunOutput
[V, 5612, 10, 2007/03/05 15:37:50.697 57004846136136] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test '' with id {00000000-0000-0000-0000-000000000000}: MessageKind: RunOutput
[V, 5612, 10, 2007/03/05 15:37:50.697 57004848283592] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 10, 2007/03/05 15:37:50.697 57004853217168] vstesthost.exe: ControllerJob.CallListeners: eventListener.ControllerEvent: success
[V, 5612, 10, 2007/03/05 15:37:50.697 57004853483704] vstesthost.exe: Time to send TRM to HA: 0
[V, 5612, 10, 2007/03/05 15:37:50.697 57004853676112] vstesthost.exe: Dequeing message kind: RunEnd
[I, 5612, 10, 2007/03/05 15:37:50.697 57004853809520] vstesthost.exe: received runcomplete from: HEDGEHOG
[V, 5612, 10, 2007/03/05 15:37:50.697 57004855248960] vstesthost.exe: TestRun complete called: HEDGEHOG
[V, 5612, 10, 2007/03/05 15:37:50.713 57004861636672] vstesthost.exe: TestRunComplete called for agent: HEDGEHOG
[V, 5612, 10, 2007/03/05 15:37:50.713 57004861888976] vstesthost.exe: Releasing all agents for task in job 0af0faa5-8998-47ec-9e1c-568b9d066d98
[V, 5612, 10, 2007/03/05 15:37:50.713 57004865925816] vstesthost.exe: Unregistering for timeout callbacks
[I, 5612, 10, 2007/03/05 15:37:50.713 57004870883544] vstesthost.exe: Controller Object cleaning up adapters
[I, 5612, 10, 2007/03/05 15:37:50.713 57004902512168] vstesthost.exe: LocalExecution: TestRunComplete called
[V, 5612, 10, 2007/03/05 15:37:50.728 57004909741224] vstesthost.exe: ControllerJob.CallListeners: calling eventListener.ControllerEvent: run id {0af0faa5-8998-47ec-9e1c-568b9d066d98}, test '' with id {00000000-0000-0000-0000-000000000000}: MessageKind: RunEnd
[V, 5612, 10, 2007/03/05 15:37:50.728 57004912273088] vstesthost.exe: CallListener - user after impersonation: REDMOND\qinzhang
[V, 5612, 1, 2007/03/05 15:37:50.728 57004915269256] vstesthost.exe: Host process: Got 'go ahead and exit' signal.
[V, 5612, 1, 2007/03/05 15:37:50.728 57004917960720] vstesthost.exe: Host process: Exiting with exit code: 0.
[V, 5612, 2, 2007/03/05 15:37:50.728 57004925895824] vstesthost.exe: UnitTestAdapter.~UnitTestAdapter called: context: (null), map count: 0

QinZhang at 2007-9-6 > top of Msdn Tech,Visual Studio Team System,Visual Studio Team System - Web and Load Testing...
# 5

As I figured out, Qin's test was for the tracing component and it removed all listeners by calling Trace.Listeners.Clear(). This caused removing Unit Test engine internal listener which caused NullReferenceException. As a workaroung, if you register your own listeners in the test, please remove them one by one by calling Trace.Listeners.Remove(string listenerName).

Thank you,
Michael

MichaelKoltachev-MSFT at 2007-9-6 > top of Msdn Tech,Visual Studio Team System,Visual Studio Team System - Web and Load Testing...

Visual Studio Team System

Site Classified