Code Coverage does not run fine with Team Build 2008

Question

We have a problem running the code coverage on our Team Build 2008 Server. Here is the error message :

The process cannot access the file 'C:\TEMP\FFFN\Core\TestResults\X34058_SDWW0209 2008-02-19 10_47_33_Any CPU_Debug\In\SDWW0209\data.coverage' because it is being used by another process.

The process locking this file is VSPerfMon.exe

As soon as this error occurs, we are not able to run the Build process anymore as this one can't delete the "TestResults" folder. To solve this, we try to do a VSPerfCmd /shutdown but we get the following answer :

Microsoft (R) VSPerf Command Version 9.0.21022 x86
Copyright (C) Microsoft Corp. All rights reserved.

Error VSP1306 : Profile Monitor does not appear to be running.

This is not true as we can see a running VSPerfMon.exe using "ProcessExplorer".
And this process as indeed a lock on the 'data.coverage' file.

We have the same problem both on the "Production" Build Server and on the "Test" Build Server.

Notice: we run some unit tests during the Build Process. And in the BuildLog.txt, we can see that before this error, only the first test "passed". The second one was "aborted". And all the following ones were "not executed"... After the unit tests, we can read this :

  Run has the following issue(s):
  Code coverage instrumentation warning while processing file Framework.Factory.dll:
TESTTOOLSTASK : warning VSP2013: Instrumenting this image requires it to run as a 32-bit process.  The CLR header flags have been updated to reflect this.
  Code coverage instrumentation warning while processing file Framework.Diagnostics.dll:
TESTTOOLSTASK : warning VSP2007: C:\TEMP\FFFN\Core\Binaries\Debug\Framework.Diagnostics.dll contains no instrumentable code.
  Test host process exited unexpectedly.

  Waiting to publish...

  Publishing results of test run X34058@SDWW0209 2008-02-19 10:47:33_Any CPU_Debug to http://sdww0208:8080/Build/v1.0/PublishTestResultsBuildService2.asmx...

  .The process cannot access the file 'C:\TEMP\FFFN\Core\TestResults\X34058_SDWW0209 2008-02-19 10_47_33_Any CPU_Debug\In\SDWW0209\data.coverage' because it is being used by another process.

  The process cannot access the file 'C:\TEMP\FFFN\Core\TestResults\X34058_SDWW0209 2008-02-19 10_47_33_Any CPU_Debug\In\SDWW0209\data.coverage' because it is being used by another process.

MSBUILD : warning MSB6006: "MSTest.exe" exited with code 1.
  The previous error was converted to a warning because the task was called with ContinueOnError=true.
  Build continuing because "ContinueOnError" on the task "TestToolsTask" is set to "true".

Final notice : Locally, the developers can run sucessfully the unit tests and the code coverage !

Any help is welcome to find the origin of this problem.

V.

Answer 1

Hmm...  Nobody in Team Build land seems to have any ideas for you...  You might try the Testing forums, at http://forums.microsoft.com/MSDN/ShowForum.aspx?ForumID=19&SiteID=1. 

 

One thing to investigate - the build is running as a different user than individual developers, and as such may be running into some different issues.  Try logging onto the build machine as the build service account and see if you can successfully run tests (and gather code coverage) there without Team Build in the picture. 

 

-Aaron

Answer 2

Thx for this answer and your suggestion. (Un)fortunately, we can't reproduce the problem anymore.

As explained here, we don't have the Unit Tests' error message anymore : Test host process exited unexpectedly.
And since, the code coverage runs fine too. It will possibly still occur if the problem with our references comes back... But in the mean time, we try to figure out the origin this other issue

V.

Answer 3

The problem is back !!!

Here is the build log where you can see that the build fails due to some error in the unit tests : http://valery.letroye.be/temp/BuildLog 1.0.00310.1.zip

And here is the next build log where you can see that the data.coverage file is locked : http://valery.letroye.be/temp/BuildLog 1.0.00310.2.zip

The good news is that we are now able to shutdown the Profile Monitor using a task and then run again the Build and reproduce the locking issue (as the build still fails on the unit tests).

Task "Exec"
  Command:
  VsPerfCmd.exe /shutdown
  Microsoft (R) VSPerf Command Version 9.0.21022 x86
  Copyright (C) Microsoft Corp. All rights reserved.
  
  Shutting down the Profile Monitor
  ------------------------------------------------------------

locally (on a workstation) we found the bug in the "aborted" unit tests : the unit test uses a "factory" to instanciate a class (an ErrorPublisher). The "factory" fails because a required configuration file is missing. Concretly, an exception is thrown by our "Configuration Service" that is catched by the "factory". Then, the factory starts a loop because it needs the ErrorPublisher class to log the exception... Stupid, isn't ?!

However, the data.coverage file should not be locked because we have a bug !

V.

Notice: The task used to shutdown the VsPerfCmd does not always run fine:

Task "Exec"
  Command:
  VsPerfCmd.exe /shutdown
  Microsoft (R) VSPerf Command Version 9.0.21022 x86
  Copyright (C) Microsoft Corp. All rights reserved.
 
 
EXEC : warning VSP1306: Profile Monitor does not appear to be running.
  The previous error was converted to a warning because the task was called with ContinueOnError=true.
  The command "VsPerfCmd.exe /shutdown" exited with code 1.
Done executing task "Exec".

Even if he data.coverage file is well actually locked at the time we run the task...
We use now a task running a "PsKill" to free the data.coverage file

Answer 4

We have the same problem with test and team build and it can be reproducible:

 

Problem description:

 

USER1 checked in changed with build errors. Build failed.

  

USER2 checked in changes which produce UNIT TEST failed.

 

 

One of the background threads threw exception: System.Data.NoNullAllowedException: Column 'DefaultBaseCurrency' does not allow nulls.

 

  Server stack trace:

     at System.Data.DataColumn.CheckNullable(DataRow row)

     at System.Data.DataTable.RaiseRowChanging(DataRowChangeEventArgs args, DataRow eRow, DataRowAction eAction, Boolean fireEvent)

     at System.Data.DataTable.SetNewRecordWorker(DataRow row, Int32 proposedRecord, DataRowAction action, Boolean isInMerge, Int32 position, Boolean fireEvent, Exception& deferredException)

     at System.Data.DataTable.InsertRow(DataRow row, Int32 proposedID, Int32 pos, Boolean fireEvent)

     at System.Data.DataRowCollection.Add(Object[] values)

     at DATABASE.cs:line 10

     at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

     at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

     at System.Runtime.Remoting.Messaging.StackBuilderSink.AsyncProcessMessage(IMessage msg, IMessageSink replySink)

 

  Exception rethrown at [0]:

     at System.Runtime.Remoting.Proxies.RealProxy.EndInvokeHelper(Message reqMsg, Boolean bProxyCase)

     at System.Runtime.Remoting.Proxies.RemotingProxy.Invoke(Object NotUsed, MessageData& msgData)

     at CacheDBInitialiseBase.cs:line 59

     at System.Runtime.Remoting.Messaging.AsyncResult.SyncProcessMessage(IMessage msg)

     at System.Runtime.Remoting.Messaging.StackBuilderSink.AsyncProcessMessage(IMessage msg, IMessageSink replySink)

     at System.Runtime.Remoting.Proxies.AgileAsyncWorkerItem.ThreadPoolCallBack(Object o)

     at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state)

     at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)

     at System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(_ThreadPoolWaitCallback tpWaitCallBack)

     at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state)

  Test host process exited unexpectedly.

  Waiting to publish...

  Publishing results of test run SaxoSvc_FosBuild@SAXOVM102 2008-08-11 14:37:45_Any CPU_Release to https://ZZZZZ/Build/v1.0/PublishTestResultsBuildService2.asmx...

  .The process cannot access the file 'D:\Builds\YYYYY\TestResults\SaxoSvc_FosBuild_SAXOVM102 2008-08-11 14_37_45_Any CPU_Release\In\SAXOVM102\data.coverage' because it is being used by another process.

  The process cannot access the file 'D:\Builds\YYYYYYY\TestResults\SaxoSvc_FosBuild_SAXOVM102 2008-08-11 14_37_45_Any CPU_Release\In\SAXOVM102\data.coverage' because it is being used by another process.

MSBUILD : warning MSB6006: "MSTest.exe" exited with code 1.

 

After that build stop working with error

 

C:\Program Files\MSBuild\Microsoft\VisualStudio\TeamBuild\Microsoft.TeamFoundation.Build.targets(481,5): error MSB3231: Unable to remove directory "D:\Builds\YYYYYY\TestResults". The process cannot access the file 'data.coverage' because it is being used by another process.

 

 

 

Answer 5

Hi

We have been struggling with this problem for weeks now and are now contemplating a move to NCover as a replacement for VSPerfMon/vsinstr. Whether such a replacement is any better is unknown, but on the other hand it can hardly be worse.

To me the situation is simple to describe. This is the process stack shown by ProcExp during test runs with code coverage on our Team Build server:

TFSBuildService
        |_MSTest
                |_VSTestHost
                        |_VSPerfMon

(it's the same for desktop builds except that you would have a Visual Studio command shell hosting MSBuild as the top two layers replacing TFSBuildService)

One question then is whether the CLR inside VSTestHost indeed can survive all attacks (this would be the ideal) from the test classes it is hosting (it needs to in order to keep communicating with the parent process) or, and this is more important, whether it is able to shutdown performance monitoring when the s*** hits the fan.

If VSTestHost for some reason dies (suicide or killed by parent because it has stopped responding) the VSPerfMon process is orphaned and continues to run on it's own. That's when you get the problem descibed in this thread.

There is probably a million reasons for this to happen. Tests starting up threads without a global exception handler is one we have seen (I think the behaviour of thread handling changed slightly on this aspect in FW3.5 (SP1?)?).

Enabling tracing for mstest and vstesthost on our build machine we see quite a few occurences of messages indicating that VSTestHost is beeing killed by mstest (because of misbehaving tests I assume).

What I would expect under such circumstances is to get some diagnostics in the test run output telling me what happened and some possible remedies. Instead the test host just implodes (test result equals [Aborted]) and the rest of the tests are [Not Executed]. Under all circumstances I would want the test results to be published so developers can read them and decide what to do. This is the bare minimum.

It seems to me that MSTest is the more stable family member here and maybe another approach could be to let MSTest be responsible for the parenthood of VSPerfMon so it could control the starting and stopping of profiling (possibly kill the VSPerfMon process) before it attempts to summarize and publish the test results (which is where it fails now on the locked coverage data). As it is now the MSTest process seems to be at the mercy of the unruly companions VSTestHost and VSPerfMon.

Actually MSTest can still control the profiling by calling VSPerfCmd /SHUTDOWN:x (where x is a number) and if that didn't terminate as a success simply nuke it (sighup -9 in the old world). Can we get a patch so we don't have to figure out how to handle this ourselves? Right now I am tweaking around with TestStartup/TestCleanup scripts and it's a mess.

Regards

Martin Moe

Answer 6

Hi

Same kind of problem for me but I try to use covering from CruiseControl.net.

I created ccnet tasks :
First will call vsperfcmd to start monitoring
Second will call MsTest
Third will call vsperfcmd /Shutdown

MSTest & coverage reports are well published in ccnet but a second build will fail, indicating that Dlls (assemblies analyzed previously) are still in use by ccnet service.

I Don't understand why because every task run vsperfcmd or mstest in a separate process that loads each assembly in its own application domain. Application domains are well unloaded after each analysis.

... looks very strange. 

In case you have an idea ... let me know.

Thanks

Bernard Jadot

Answer 7

For information, I still have the problem with Team Build in TFS 2010.

Now, I am using a code activity to kill vsperfom. The difficulty is that we have now multiple builds running in parallel on the controller.

Answer 8

We have the same problem on VS2010 with TFS running the build on a VM.

Any exception on a background thread locks up the code coverage file and halts all CI and nightly builds.

Would love a fix.  My build team is trying the 'kill  VSPerfMon.exe' trick, which is fairly hackish.

---

DAN

Answer 9

MS issued Patch to that bug

http://support.microsoft.com/kb/2544407