Submit My Question - Recent Questions - Recent Answer
Msdn Tech >> Visual Studio Team System >> Team Foundation Server - Build Automation

Publish operation failed

Good day everyone,

I have an odd problem when publishing unit test results from both the build server and the developer's desktop.

Initial note:
All builds and unit test results were succeeding and successfully dropping to the fileserver in the past. In the case of unit tests, even failures were posted to the dropzone (by design, of course ;)).

However... recently things have 'gone sideways' :(... here are some symptoms:

Build server (unit test publishing):
- At build time, I see the test phase start and I can even watch the fileserver's dropzone structure for that particular build and see the TestResults folder created and the subsequent files are copied over (In/Out/binaries etc...).
- As soon as the test completes, the structure is removed from the dropzone (the empty TestResults folder is all that remains).
- The rest of the build completes successfully. Meaning all targets are dropped, including our packaging bits (msi).
- Unfortunately due to the publish failure, all builds receive a failed status and workitems continue to accumulate (I actually turned UTs off for now)
- Running the tests manually on the build server results in a clean run...

Desktop (unit test publishing):
- Same symptoms as seen during the automated build process... the user can execute the publish operation (rights are established in the project's Contributors group).
- The TestResults folder is created, In/Out/binaries etc... are copied over.
- Publish operations returns "failed" and all the contents of the TestResults folder are removed.

The 'disconnect' seems to be betweend #4 and #5 below... but I don't understand why the files which are successfully created under the TestResults structure would be removed :(

1. Visual Studio client (the publishing client) sends a publish request to the Team Foundation Server publishing web service
2. The publishing web service authenticates the user against ‘Publish Test Results’ permission
3. It then creates an appropriate testresults folder under the build drop location and gives NTFS full control access to the publishing client
4. The publishing client copies the test results to the drop location
5. Once the copying is done, the publishing web service revokes the NTFS permissions that were granted before.


Log snippet:
Results file: D:\Build\Stable\Kerrisdale\Stable_Nightly\TestResults\builder_VMSVRBUILD2 2006-09-19 23_06_32_Any CPU_Release.trx
Run Configuration: localtestrun
Waiting to publish...
Publishing results of test runbuilder@VMSVRBUILD2 2006-09-19 23:06:32_Any CPU_Release tohttp://dev001:8080/Build/v1.0/PublishTestResultsBuildService.asmx...
Publish operation failed.
MSBUILD : warning : Publish operation failed.
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".
Done executing task "TestToolsTask" -- FAILED.
Task "TestToolsTask" skipped, due to false condition; ( '$(IsDesktopBuild)'!='false' ) was evaluated as ( 'false'!='false' ).
Done building target "RunTestWithConfiguration" in project "TFSBuild.proj".

NOTE1:
Permissions have been setup using the step by step blog posted by Nagaraju Palla:
http://blogs.msdn.com/nagarajp/archive/2005/10/19/482885.aspx

NOTE2:
Build Server and Fileserver (dropzone) are separate machines with an existing share in place, on the fileserver side.

NOTE3:
The account used to run the Team Build Service (service), has Full NTFS permissions and is the "owner" of the share structure, including all child objects.

I don’t think it’s an NTFS permissions problem and the accounts in TFS seem to be fine.

I'm manually posting TRX files right now... please help me stop the insanity ;)

I’m still on the B3R, but will hopefully be upgrading at the end of September - early October, we just need to ship this project before I attempt it (again) ;)

thanks,

dto

[5101 byte] By [dto] at [2007-12-24]
«« Exporting subreports to excel ... SOS
»» What constitutes "Commercial"?
# 1

It's not clear at all to me as to what would delete the files. To get more information in the log, you can add the /v:diag setting to the TFSBuild.rsp file in the build type folder.

# This is a response file for MSBuild
# Add custom MSBuild command line options in this file
/v:diag

Buck

BuckHodges at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 2

Hi Buck,

The snippet I provided in the first thread was generated using the /v:diag in the RSP file. There is no other information related to the file's removal from the drop structure, in the log.

It simply reports the operation as "failed", as seen in the previous thread.

I removed everything from the build script with the exception of Release/Debug compile and the VSMDI execution and I still see the same result.

IMHO, I believe the "removal of files" happens at this point:
5. Once the copying is done, the publishing web service revokes the NTFS permissions that were granted before.

If someone can help me with the "behind the scenes" operations related to #5 above, maybe I can narrow this down?

Perhaps there _is_ a permissions issue somewhere in the "house of cards"... I think I've been through it all at least 10 times though.

thanks.

-dto

dto at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 3

Hi Buck,

I enabled verbose logging on the Team Foundation Server box... I've take the TestRun bits from the start of the log and the end of the log, the snippet is separated by "====". I didn't want to send all 58MB of text... it's _very_ verbose ;)

Hopefully this give you more information to 'go on'. Thanks for your help on this.

<start log>

[TB] [V, 2836, 1, 2006/09/22 08:32:20.847 3254715057488] w3wp.exe: Initializing Test Web Service

[V, 2836, 1, 2006/09/22 08:32:20.847 3254715057488] w3wp.exe: Initializing Test Web Service
[TB] [I, 2836, 1, 2006/09/22 08:32:20.863 3254753076075] w3wp.exe: Found build connection string: Server=90DSDEV001;Database=TfsBuild;Integrated Security=SSPI

[I, 2836, 1, 2006/09/22 08:32:20.863 3254753076075] w3wp.exe: Found build connection string: Server=90DSDEV001;Database=TfsBuild;Integrated Security=SSPI
[TB] [V, 2836, 1, 2006/09/22 08:32:20.863 3254756337473] w3wp.exe: Test Web Service initialized

[V, 2836, 1, 2006/09/22 08:32:20.863 3254756337473] w3wp.exe: Test Web Service initialized
[TB] [V, 2836, 1, 2006/09/22 08:32:20.863 3254777655855] w3wp.exe: PrepareToPublish: Preparing to publish run e0c0f95f-96c6-4147-8f42-4e37721b9bbd to build 09222006_152335_85793

[V, 2836, 1, 2006/09/22 08:32:20.863 3254777655855] w3wp.exe: PrepareToPublish: Preparing to publish run e0c0f95f-96c6-4147-8f42-4e37721b9bbd to build 09222006_152335_85793
[TB] [V, 2836, 1, 2006/09/22 08:32:20.863 3254783317035] w3wp.exe: GetProjectUriFromBuildId(09222006_152335_85793)

[V, 2836, 1, 2006/09/22 08:32:20.863 3254783317035] w3wp.exe: GetProjectUriFromBuildId(09222006_152335_85793)
[TB] [I, 2836, 1, 2006/09/22 08:32:20.878 3254799347835] w3wp.exe: SQL: select TeamProject from dbo.Builds where BuildUri = @buildId

[I, 2836, 1, 2006/09/22 08:32:20.878 3254799347835] w3wp.exe: SQL: select TeamProject from dbo.Builds where BuildUri = @buildId
[TB] [I, 2836, 1, 2006/09/22 08:32:20.878 3254829241545] w3wp.exe: SQL: 1 rows returned

[I, 2836, 1, 2006/09/22 08:32:20.878 3254829241545] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:32:20.878 3254829792848] w3wp.exe: PrepareToPublish: The project URI is vstfs:///Classification/TeamProject/1ea09b3d-217d-44d2-b271-a8d110359ec6

[V, 2836, 1, 2006/09/22 08:32:20.878 3254829792848] w3wp.exe: PrepareToPublish: The project URI is vstfs:///Classification/TeamProject/1ea09b3d-217d-44d2-b271-a8d110359ec6
[TB] [V, 2836, 1, 2006/09/22 08:32:21.019 3255250002533] w3wp.exe: PrepareToPublish: Run state set to processing.

[V, 2836, 1, 2006/09/22 08:32:21.019 3255250002533] w3wp.exe: PrepareToPublish: Run state set to processing.
[TB] [I, 2836, 1, 2006/09/22 08:32:21.019 3255252945158] w3wp.exe: SQL: select RunId from dbo.TestRun where RunId = @runId

[I, 2836, 1, 2006/09/22 08:32:21.019 3255252945158] w3wp.exe: SQL: select RunId from dbo.TestRun where RunId = @runId
[TB] [I, 2836, 1, 2006/09/22 08:32:21.050 3255357435585] w3wp.exe: SQL: 0 rows returned

[I, 2836, 1, 2006/09/22 08:32:21.050 3255357435585] w3wp.exe: SQL: 0 rows returned
[TB] [I, 2836, 1, 2006/09/22 08:32:21.066 3255363021555] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri

[I, 2836, 1, 2006/09/22 08:32:21.066 3255363021555] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri
[TB] [I, 2836, 1, 2006/09/22 08:32:21.066 3255373111875] w3wp.exe: SQL: 1 rows returned

[I, 2836, 1, 2006/09/22 08:32:21.066 3255373111875] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:32:21.066 3255397750883] w3wp.exe: PrepareToPublish: This is the first run published. Creating TestResults directory.

[V, 2836, 1, 2006/09/22 08:32:21.066 3255397750883] w3wp.exe: PrepareToPublish: This is the first run published. Creating TestResults directory.
[TB] [I, 2836, 1, 2006/09/22 08:32:21.066 3255398399063] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri

[I, 2836, 1, 2006/09/22 08:32:21.066 3255398399063] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri
[TB] [I, 2836, 1, 2006/09/22 08:32:21.066 3255401225678] w3wp.exe: SQL: 1 rows returned

[I, 2836, 1, 2006/09/22 08:32:21.066 3255401225678] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:32:21.097 3255455913990] w3wp.exe: PrepareToPublish: Created TestResults directory.

[V, 2836, 1, 2006/09/22 08:32:21.097 3255455913990] w3wp.exe: PrepareToPublish: Created TestResults directory.
[TB] [V, 2836, 1, 2006/09/22 08:32:21.129 3255569531610] w3wp.exe: PrepareToPublish: Created the results directory.

[V, 2836, 1, 2006/09/22 08:32:21.129 3255569531610] w3wp.exe: PrepareToPublish: Created the results directory.
[TB] [V, 2836, 5, 2006/09/22 08:32:24.951 3266979478493] w3wp.exe: Initializing Test Web Service

[V, 2836, 5, 2006/09/22 08:32:24.951 3266979478493] w3wp.exe: Initializing Test Web Service
[TB] [I, 2836, 5, 2006/09/22 08:32:24.951 3266980865565] w3wp.exe: Found build connection string: Server=90DSDEV001;Database=TfsBuild;Integrated Security=SSPI

[I, 2836, 5, 2006/09/22 08:32:24.951 3266980865565] w3wp.exe: Found build connection string: Server=90DSDEV001;Database=TfsBuild;Integrated Security=SSPI
[TB] [V, 2836, 5, 2006/09/22 08:32:24.951 3266981184668] w3wp.exe: Test Web Service initialized

[V, 2836, 5, 2006/09/22 08:32:24.951 3266981184668] w3wp.exe: Test Web Service initialized
[TB] [V, 2836, 5, 2006/09/22 08:32:24.966 3267008548845] w3wp.exe: PublishRun: Publishing run e0c0f95f-96c6-4147-8f42-4e37721b9bbd to build 09222006_152335_85793 with results file builder_VMBUILD1 2006-09-22 08_30_58_Any CPU_Release.trx

[V, 2836, 5, 2006/09/22 08:32:24.966 3267008548845] w3wp.exe: PublishRun: Publishing run e0c0f95f-96c6-4147-8f42-4e37721b9bbd to build 09222006_152335_85793 with results file builder_VMBUILD1 2006-09-22 08_30_58_Any CPU_Release.trx
[TB] [V, 2836, 5, 2006/09/22 08:32:24.966 3267009085733] w3wp.exe: GetProjectUriFromBuildId(09222006_152335_85793)

[V, 2836, 5, 2006/09/22 08:32:24.966 3267009085733] w3wp.exe: GetProjectUriFromBuildId(09222006_152335_85793)
[TB] [I, 2836, 5, 2006/09/22 08:32:24.966 3267009310425] w3wp.exe: SQL: select TeamProject from dbo.Builds where BuildUri = @buildId

[I, 2836, 5, 2006/09/22 08:32:24.966 3267009310425] w3wp.exe: SQL: select TeamProject from dbo.Builds where BuildUri = @buildId
[TB] [I, 2836, 5, 2006/09/22 08:32:24.966 3267012233663] w3wp.exe: SQL: 1 rows returned

[I, 2836, 5, 2006/09/22 08:32:24.966 3267012233663] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 5, 2006/09/22 08:32:24.966 3267012662513] w3wp.exe: PublishRun: The project URI is vstfs:///Classification/TeamProject/1ea09b3d-217d-44d2-b271-a8d110359ec6

[V, 2836, 5, 2006/09/22 08:32:24.966 3267012662513] w3wp.exe: PublishRun: The project URI is vstfs:///Classification/TeamProject/1ea09b3d-217d-44d2-b271-a8d110359ec6
[TB] [I, 2836, 5, 2006/09/22 08:32:24.966 3267049573058] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri

[I, 2836, 5, 2006/09/22 08:32:24.966 3267049573058] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri
[TB] [I, 2836, 5, 2006/09/22 08:32:24.982 3267052730153] w3wp.exe: SQL: 1 rows returned

[I, 2836, 5, 2006/09/22 08:32:24.982 3267052730153] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 5, 2006/09/22 08:32:25.060 3267301146353] w3wp.exe: PublishRun: Updated the run directory security from the TestResults directory.

[V, 2836, 5, 2006/09/22 08:32:25.060 3267301146353] w3wp.exe: PublishRun: Updated the run directory security from the TestResults directory.
[TB] [V, 2836, 5, 2006/09/22 08:32:25.060 3267311727053] w3wp.exe: PublishRun: Moved results file to the TestResults directory.

[V, 2836, 5, 2006/09/22 08:32:25.060 3267311727053] w3wp.exe: PublishRun: Moved results file to the TestResults directory.
[TB] [V, 2836, 5, 2006/09/22 08:32:25.092 3267395415773] w3wp.exe: <NAME> Tests

[V, 2836, 5, 2006/09/22 08:32:25.092 3267395415773] w3wp.exe: <NAME> Tests
[TB] [V, 2836, 5, 2006/09/22 08:32:25.092 3267395940720] w3wp.exe: <NAME> edtdocversion

[V, 2836, 5, 2006/09/22 08:32:25.092 3267395940720] w3wp.exe: <NAME> edtdocversion
[TB] [V, 2836, 5, 2006/09/22 08:32:25.092 3267398234145] w3wp.exe: <NAME> TestRun

[V, 2836, 5, 2006/09/22 08:32:25.092 3267398234145] w3wp.exe: <NAME> TestRun
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267532079738] w3wp.exe: ** Created FileCopyService w security: null

[V, 2836, 5, 2006/09/22 08:32:25.139 3267532079738] w3wp.exe: ** Created FileCopyService w security: null
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267532889355] w3wp.exe: ** Created FileCopyService w2

[V, 2836, 5, 2006/09/22 08:32:25.139 3267532889355] w3wp.exe: ** Created FileCopyService w2
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267538959165] w3wp.exe: <NAME> id

[V, 2836, 5, 2006/09/22 08:32:25.139 3267538959165] w3wp.exe: <NAME> id
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267552068430] w3wp.exe: <TEXT> e0c0f95f-96c6-4147-8f42-4e37721b9bbd

[V, 2836, 5, 2006/09/22 08:32:25.139 3267552068430] w3wp.exe: <TEXT> e0c0f95f-96c6-4147-8f42-4e37721b9bbd
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267553822995] w3wp.exe: </NAME> id

[V, 2836, 5, 2006/09/22 08:32:25.139 3267553822995] w3wp.exe: </NAME> id
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267554106720] w3wp.exe: <NAME> name

[V, 2836, 5, 2006/09/22 08:32:25.139 3267554106720] w3wp.exe: <NAME> name
[TB] [V, 2836, 5, 2006/09/22 08:32:25.139 3267554494418] w3wp.exe: <TEXT> builder@VMBUILD1 2006-09-22 08:30:58_Any CPU_Release


====


[I, 2836, 1, 2006/09/22 08:35:11.836 3765726583905] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:35:11.836 3765727117320] w3wp.exe: Getting all runs for the build

[V, 2836, 1, 2006/09/22 08:35:11.836 3765727117320] w3wp.exe: Getting all runs for the build
[TB] [I, 2836, 1, 2006/09/22 08:35:11.836 3765735145170] w3wp.exe: SQL: select CurrentState from dbo.RunState where RunId = @runId

[I, 2836, 1, 2006/09/22 08:35:11.836 3765735145170] w3wp.exe: SQL: select CurrentState from dbo.RunState where RunId = @runId
[TB] [I, 2836, 1, 2006/09/22 08:35:11.836 3765737039918] w3wp.exe: SQL: 1 rows returned

[I, 2836, 1, 2006/09/22 08:35:11.836 3765737039918] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:35:11.836 3765737418938] w3wp.exe: Run not found, inserting new object

[V, 2836, 1, 2006/09/22 08:35:11.836 3765737418938] w3wp.exe: Run not found, inserting new object
[TB] [V, 2836, 1, 2006/09/22 08:35:11.836 3765737852835] w3wp.exe: Adding run row

[V, 2836, 1, 2006/09/22 08:35:11.836 3765737852835] w3wp.exe: Adding run row
[TB] [V, 2836, 1, 2006/09/22 08:35:11.836 3765738103170] w3wp.exe: Updating run table

[V, 2836, 1, 2006/09/22 08:35:11.836 3765738103170] w3wp.exe: Updating run table
[TB] [I, 2836, 1, 2006/09/22 08:35:11.836 3765753850260] w3wp.exe: SQL: select CurrentState from dbo.RunState where RunId = @runId

[I, 2836, 1, 2006/09/22 08:35:11.836 3765753850260] w3wp.exe: SQL: select CurrentState from dbo.RunState where RunId = @runId
[TB] [I, 2836, 1, 2006/09/22 08:35:11.836 3765755960235] w3wp.exe: SQL: 1 rows returned

[I, 2836, 1, 2006/09/22 08:35:11.836 3765755960235] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:35:11.836 3765756382545] w3wp.exe: Getting result records...

[V, 2836, 1, 2006/09/22 08:35:11.836 3765756382545] w3wp.exe: Getting result records...
[TB] [E, 2836, 1, 2006/09/22 08:35:42.281 3856736031765] w3wp.exe: InsertRun: Exception: System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.SqlDataReader.ConsumeMetaData()
at System.Data.SqlClient.SqlDataReader.get_MetaData()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.FillInternal(DataSet dataset, DataTable[] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, String srcTable)
at Microsoft.VisualStudio.TestTools.TeamSystem.Server.SqlAccess.InsertRun(String projectUri, String user, String buildUri, Int64 buildId, TestRunAndResults runAndRes, String resultsFilePath, Boolean runHasCoverage)

[E, 2836, 1, 2006/09/22 08:35:42.281 3856736031765] w3wp.exe: InsertRun: Exception: System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.SqlDataReader.ConsumeMetaData()
at System.Data.SqlClient.SqlDataReader.get_MetaData()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.FillInternal(DataSet dataset, DataTable[] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, String srcTable)
at Microsoft.VisualStudio.TestTools.TeamSystem.Server.SqlAccess.InsertRun(String projectUri, String user, String buildUri, Int64 buildId, TestRunAndResults runAndRes, String resultsFilePath, Boolean runHasCoverage)
[TB] [V, 2836, 1, 2006/09/22 08:35:42.281 3856736959883] w3wp.exe: Rolling back transaction.

[V, 2836, 1, 2006/09/22 08:35:42.281 3856736959883] w3wp.exe: Rolling back transaction.
[TB] [V, 2836, 1, 2006/09/22 08:35:42.281 3856739155613] w3wp.exe: PublishRun: Failed to publish the run. Attempting to clean up.

[V, 2836, 1, 2006/09/22 08:35:42.281 3856739155613] w3wp.exe: PublishRun: Failed to publish the run. Attempting to clean up.
[TB] [I, 2836, 1, 2006/09/22 08:35:42.281 3856739615610] w3wp.exe: SQL: select BuildUri from dbo.TestRun where RunId = @runId

[I, 2836, 1, 2006/09/22 08:35:42.281 3856739615610] w3wp.exe: SQL: select BuildUri from dbo.TestRun where RunId = @runId
[TB] [I, 2836, 1, 2006/09/22 08:35:42.281 3856742236890] w3wp.exe: SQL: 0 rows returned

[I, 2836, 1, 2006/09/22 08:35:42.281 3856742236890] w3wp.exe: SQL: 0 rows returned
[TB] [I, 2836, 1, 2006/09/22 08:35:42.281 3856742687363] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri

[I, 2836, 1, 2006/09/22 08:35:42.281 3856742687363] w3wp.exe: SQL: select DropLocation from dbo.Builds where BuildUri = @buildUri
[TB] [I, 2836, 1, 2006/09/22 08:35:42.281 3856745132558] w3wp.exe: SQL: 1 rows returned

[I, 2836, 1, 2006/09/22 08:35:42.281 3856745132558] w3wp.exe: SQL: 1 rows returned
[TB] [V, 2836, 1, 2006/09/22 08:35:42.281 3856746510713] w3wp.exe: Remove Run Data: Starting transaction.

[V, 2836, 1, 2006/09/22 08:35:42.281 3856746510713] w3wp.exe: Remove Run Data: Starting transaction.
[TB] [E, 2836, 1, 2006/09/22 08:35:42.281 3856752992348] w3wp.exe: Remove Run Data: Exception: Microsoft.VisualStudio.TestTools.Common.Warehouse.RunDoesNotExistException: Run with id 550f0cef-852c-42db-9348-ad48ef9dd5ea is not in the Publish database.
at Microsoft.VisualStudio.TestTools.TeamSystem.Server.SqlAccess.RemoveRunData(Guid runId)

[E, 2836, 1, 2006/09/22 08:35:42.281 3856752992348] w3wp.exe: Remove Run Data: Exception: Microsoft.VisualStudio.TestTools.Common.Warehouse.RunDoesNotExistException: Run with id 550f0cef-852c-42db-9348-ad48ef9dd5ea is not in the Publish database.
at Microsoft.VisualStudio.TestTools.TeamSystem.Server.SqlAccess.RemoveRunData(Guid runId)
[TB] [W, 2836, 1, 2006/09/22 08:35:42.281 3856755682433] w3wp.exe: Caught exception removing run data. There is already an open DataReader associated with this Command which must be closed first.

[W, 2836, 1, 2006/09/22 08:35:42.281 3856755682433] w3wp.exe: Caught exception removing run data. There is already an open DataReader associated with this Command which must be closed first.
[TB] [V, 2836, 1, 2006/09/22 08:35:42.390 3857066336708] w3wp.exe: PublishRun: Removed the run.

[V, 2836, 1, 2006/09/22 08:35:42.390 3857066336708] w3wp.exe: PublishRun: Removed the run.
[TB] [E, 2836, 1, 2006/09/22 08:35:42.390 3857067617760] w3wp.exe: PublishRun: Unexpected exception: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

[E, 2836, 1, 2006/09/22 08:35:42.390 3857067617760] w3wp.exe: PublishRun: Unexpected exception: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

<end log>

thanks again,
-dto

dto at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 4

That server trace is very helpful. Thanks for posting it.

There appears to be a bug in the server for publishing test runs.

at Microsoft.VisualStudio.TestTools.TeamSystem.Server.SqlAccess.InsertRun(String projectUri, String user, String buildUri, Int64 buildId, TestRunAndResults runAndRes, String resultsFilePath, Boolean runHasCoverage)

I'll ping someone familiar with that code.

Buck

BuckHodges at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 5

Hello Dto,

Which version of TFS do you have installed? Is this still a Beta? I was not able to follow the traces throughout the RTM code base. We used to have bugs with the timeouts (essentially too short) in the pre-released bits, which you may be hitting.

Thanks,

Boris

BorisVidolovMSFT at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 6

I’m still on the B3R, but will hopefully be upgrading at the end of September - early October, we just need to ship this project before I attempt it (again) ;)

Can I change the timeout threshold somewhere in the B3R build... I just need to get through this project.

thanks

dto

dto at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 7

This is a bit of a wild guess, but you could try turning off warehouse processing by stopping the TFS Server Scheduler service on the application tier. That may help the situation.

Buck

BuckHodges at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 8

Thanks for the effort Buck, but unfortunately stopping the TFS Server Scheduler did not change the results :(

I guess I'll have to get to RTM before I can have automated unit test runs published.

-dto

dto at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
# 9

We are too still running on b3r and publishing tests from the BuildServer has suddenly started to fail.

Only error I get from the build log is this

MSBUILD : warning : PublishRun: Server was unable to process request. > Method failed with unexpected error code 53.

Doing manual publishing mostly(!) works.

Any thoughts ?

borge3000

borge3000 at 2007-8-31 > top of Msdn Tech,Visual Studio Team System,Team Foundation Server - Build Automation...
Visual Studio Team System
Team Foundation Server - Build Automation

Visual Studio Team System Hot Topic

Visual Studio Team System New Topic

Visual Studio Team System

Java / MSDN / Linux Tech / PHP Tech / MSDN DotNet / MSDN TECH / Health Library / Programmers Tech / visual basic Tech / Developer Tech / Ipod faqs / Msdn China Tech

Site Classified