Install of TC 7.0, VCS(svn) triggers failing with "Handshake failed"....
Upgraded to TC 7.0 and the VCS triggering fails with "Error while appliying patch" and
[Updating sources] Failed to perform checkout on agent: java.lang.RuntimeException: svn: E210004: Handshake failed, received: '
Log files show that the recieved is 8K of [NUL].
The failure is sporadic, but consistent and across the board.
I added a similiar bug (TW-20903) yesterday for the one failure I can reproduce at will.
Usually, but by no means always, a manual restart of the configuration results in a good build.
TC server / agent 7.0 on windows OSes
SVN 1.6.6 on fedora (11, Leonitis)
Any suggestions to help define the matter better?
This is critical for the dev/qa departments, as bad builds close them down.
greg myers
Please sign in to leave a comment.
Hello Greg,
I've answered in the issue.
Regards,
KIR
This is a snippet of the log file, from a run of the reproduceable failure configuration I have...trying to trim this down to the specifics....make noise if the trimming is too tight.
The '[2012-04-11 07:12:57,020] ' entry shows the large block of null around the handshake failure....
thanks,
g
[2012-04-11 07:12:18,016] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:18,016] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 4 msec
[2012-04-11 07:12:18,031] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:18,031] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 7 msec
[2012-04-11 07:12:21,531] DEBUG - ity.BuildQueuePriorityOrdering - Current item priorities: {317770=0.0}, new item QueuedBuildImpl{myBuildType=TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts {id=bt1594},ItemId=317770} with weight 0.0 inserted at position 0
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,547] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,610] INFO - tbrains.buildServer.ACTIVITIES - Build of "TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts" was added to queue by "Greg Myers"
[2012-04-11 07:12:21,625] INFO - tbrains.buildServer.ACTIVITIES - Configuration added to queue; name=TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts {id=bt1594}; requestor=Greg Myers; promotion id=317770
[2012-04-11 07:12:21,625] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:21,625] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:21,625] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor start: 0 msec
[2012-04-11 07:12:21,625] DEBUG - Side.impl.BuildTriggersChecker - Start triggers polling for 476 active build configuration
[2012-04-11 07:12:21,625] DEBUG - Side.impl.BuildTriggersChecker - Finished triggers polling for active build configurations
[2012-04-11 07:12:21,625] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor done: 2 msec
[2012-04-11 07:12:21,625] DEBUG - ains.buildServer.util.WatchDog - Ping start: 0 msec
[2012-04-11 07:12:21,625] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 4 msec
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,641] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,656] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: QueuedBuildImpl{myBuildType=TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts {id=bt1594},ItemId=317770} are: [VCS640Build 3 registered: true authorized: true], already distributed agents: []
[2012-04-11 07:12:21,672] DEBUG - jetbrains.buildServer.SERVER - Initializing Running build bt1594 on VCS640Build:255367
[2012-04-11 07:12:21,672] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,672] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,672] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,672] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,672] DEBUG - jetbrains.buildServer.SERVER - Associating build promotion 317770 with build 255367
[2012-04-11 07:12:21,735] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,735] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,735] DEBUG - buildLog.MessagesStateProvider - Flow: -642892918 not found, creating it in flow: null
[2012-04-11 07:12:21,781] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,781] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,781] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,781] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,797] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,797] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,797] INFO - tbrains.buildServer.ACTIVITIES - Build started; name=TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts, personal=false, buildId=255367
[2012-04-11 07:12:21,797] DEBUG - jetbrains.buildServer.SERVER - SearchService: buildStarted Running build bt1594 on VCS640Build:255367
[2012-04-11 07:12:21,797] DEBUG - jetbrains.buildServer.SERVER - SearchService: addBuild 255367
[2012-04-11 07:12:21,797] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:21,797] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:21,797] INFO - tbrains.buildServer.ACTIVITIES - Configuration removed from queue; name=TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts, requestor=Greg Myers, comment=null, user=null, promotion id=317770
[2012-04-11 07:12:21,797] DEBUG - jetbrains.buildServer.SERVER - Starting a new build: QueuedBuildImpl{myBuildType=TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts {id=bt1594},ItemId=317770}
[2012-04-11 07:12:21,797] INFO - jetbrains.buildServer.SERVER - Flush queue finished, number of builds started: 1
[2012-04-11 07:12:21,797] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 175 msec
[2012-04-11 07:12:22,125] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCS631Build{id=2} at address: 172.25.4.65:9090
[2012-04-11 07:12:22,141] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCS631Build{id=2}:OK
[2012-04-11 07:12:22,141] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCS640Build{id=3} at address: 172.25.4.38:9090
[2012-04-11 07:12:22,156] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCS640Build{id=3}:OK
[2012-04-11 07:12:22,156] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCSBUILDMASTER{id=4} at address: 127.0.0.1:9090
[2012-04-11 07:12:22,172] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCSBUILDMASTER{id=4}:OK
[2012-04-11 07:12:22,172] DEBUG - ains.buildServer.util.WatchDog - Ping done: 538 msec
[2012-04-11 07:12:22,672] DEBUG - jetbrains.buildServer.SERVER - SearchService.createWriter
[2012-04-11 07:12:22,672] DEBUG - jetbrains.buildServer.SERVER - Wed Apr 11 07:12:22 PDT 2012 SearchService.indexBuilds (1 left)
[2012-04-11 07:12:22,813] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:22,813] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:22,860] DEBUG - jetbrains.buildServer.SERVER - SearchService.closeWriter
[2012-04-11 07:12:22,860] DEBUG - jetbrains.buildServer.SERVER - SearchService.updateSearcher
[2012-04-11 07:12:22,875] DEBUG - jetbrains.buildServer.SERVER - SearchService: changesLoaded Running build bt1594 on VCS640Build:255367
[2012-04-11 07:12:22,875] DEBUG - jetbrains.buildServer.SERVER - SearchService: deleteBuild 255367
[2012-04-11 07:12:22,875] DEBUG - jetbrains.buildServer.SERVER - SearchService: addBuild 255367
[2012-04-11 07:12:22,891] DEBUG - utoincrementPropertiesProvider - Processing build #10 {build id=255367} for autoincrement parameters.
[2012-04-11 07:12:22,891] DEBUG - utoincrementPropertiesProvider - No autoincrement parameters found in [/p:ItemForStaging=CDTemplates, DeliverToStaging, DelivertoStaging, %build.number%, %env.2012Q3CheckOutDirectory%\VersionFiles, d:\TeamCity\MSBuild\2012Q3TeamCity_Staging.msbuild, bt1594, 7.0.2 (build 21349), %env.TEAMCITY_BUILDCONF_NAME%, //ias .*, DeliverToStagingRecursive, selected, %env.TEAMCITY_PROJECT_NAME%, /p:ItemForStaging=AdditionalThirdpartyStaticArtifacts, /p:ItemforStaging=OfficeAddins2007PIA, none, /p:ItemForStaging=AdditionalThirdpartyStaticArtifactsSMO4BI, //or FullCoverageReport:Html:{teamcity.report.path}, /p:ItemForStaging=AdditionalThirdpartyStaticArtifactsBin, /p:ItemForStaging=AdditionalThirdpartyStaticArtifactsCrytalTroubleshooter, /p:ItemForStaging=OfficeAddinsVSTOR, 0AC1MVZaNdYLBijhLiHVMv0IH5o6yrBx, TeamCityBuildId=255367, 4.0, /p:ItemForStaging=AdditionalThirdpartySSRSGAC_Artifacts, /p:ItemForStaging=AdditionalThirdpartyStaticArtifactsRemote, ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts, 66706, 2.0, /p:ItemForStaging=fonts, /p:ItemForStaging=AdditionalThirdpartyStaticArtifactsMSReportingServicesToClient, x86, /p:ItemforStaging=AdditionalThirdpartyStaticArtifactsSMO, [*]*, 10, 1, v2.0, 0, %system.build.number%, 255367, d:\teamcity\msbuild\2012Q3TeamCity_Staging.msbuild, TRUNK - 6.5.0, /p:ItemForStaging=ThirdPartyConnects, d:\teamcity\msbuild\2012Q3Teamcity_Staging.msbuild]
[2012-04-11 07:12:22,953] DEBUG - jetbrains.buildServer.SERVER - SearchService.getIndexSearcher - NEW - size:669001
[2012-04-11 07:12:22,969] DEBUG - jetbrains.buildServer.SERVER - sleeping for 297
[2012-04-11 07:12:22,991] INFO - jetbrains.buildServer.SERVER - Running build saved to DB: TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts {id=bt1594} #10 {build id=255367}, promotion id 317770, on agent VCS640Build, triggered by ##userId='27'
[2012-04-11 07:12:23,083] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:23,083] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:23,083] DEBUG - buildLog.MessagesStateProvider - Flow started for already existing flow: -642892918, parent flow: -642892918
[2012-04-11 07:12:23,084] DEBUG - buildLog.MessagesStateProvider - Flow started: 860372860, parent flow: -642892918
[2012-04-11 07:12:23,084] DEBUG - buildLog.MessagesStateProvider - Flow: 860372860 not found, creating it in flow: FlowMessagesState{myFlowId=-642892918, myParentState=null, myChildStates=[]}
[2012-04-11 07:12:23,099] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:23,099] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:23,103] DEBUG - facts.ArtifactUploadController - Publishing '.teamcity/properties/build.start.properties.gz' for build #10 {build id=255367}
[2012-04-11 07:12:23,115] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:23,115] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:23,131] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:23,131] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:23,131] DEBUG - buildLog.MessagesStateProvider - Flow finished: 860372860
[2012-04-11 07:12:23,147] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:23,147] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:24,252] DEBUG - jetbrains.buildServer.SERVER - SearchService.createWriter
[2012-04-11 07:12:24,268] DEBUG - jetbrains.buildServer.SERVER - SearchService.deleteBuild #255367
[2012-04-11 07:12:24,268] DEBUG - jetbrains.buildServer.SERVER - SearchService.updateSearcher
[2012-04-11 07:12:24,268] DEBUG - jetbrains.buildServer.SERVER - Wed Apr 11 07:12:24 PDT 2012 SearchService.indexBuilds (1 left)
[2012-04-11 07:12:24,346] DEBUG - jetbrains.buildServer.SERVER - SearchService.closeWriter
[2012-04-11 07:12:24,346] DEBUG - jetbrains.buildServer.SERVER - SearchService.updateSearcher
[2012-04-11 07:12:24,533] DEBUG - jetbrains.buildServer.SERVER - SearchService.getIndexSearcher - NEW - size:669001
[2012-04-11 07:12:24,533] DEBUG - jetbrains.buildServer.SERVER - sleeping for 281
[2012-04-11 07:12:26,628] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:26,628] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 14 msec
[2012-04-11 07:12:26,800] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:26,800] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 8 msec
[2012-04-11 07:12:26,831] DEBUG - impl.MavenMetadataProviderImpl - Starting check for failed triggering attempts
[2012-04-11 07:12:26,831] DEBUG - impl.MavenMetadataProviderImpl - Retriggering maven metadata generation: 0 failed entries found
[2012-04-11 07:12:26,831] DEBUG - impl.MavenMetadataProviderImpl - Retriggering maven metadata generation: finished
[2012-04-11 07:12:28,206] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:28,206] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:28,206] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:28,206] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:31,628] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor start: 0 msec
[2012-04-11 07:12:31,628] DEBUG - Side.impl.BuildTriggersChecker - Start triggers polling for 476 active build configuration
[2012-04-11 07:12:31,628] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - Help MadCap - Build and Deploy to Help folder {id=bt1388}, no new builds found
[2012-04-11 07:12:31,628] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:31,628] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 5 msec
[2012-04-11 07:12:31,628] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - RemoteHelperCS {id=bt1595}, no new builds found
[2012-04-11 07:12:31,628] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - RemoteService {id=bt1405}, no new builds found
[2012-04-11 07:12:31,644] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - VP {id=bt1426}, no new builds found
[2012-04-11 07:12:31,644] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Deploy - Reports - Deploy SSRS Reports from SVN to DEV {id=bt1444}, no new builds found
[2012-04-11 07:12:31,644] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Deploy - Reports - Deploy SSRS Reports from SVN to QA {id=bt1445}, no new builds found
[2012-04-11 07:12:31,644] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Deploy - Reports - Deploy SSRS Reports from SVN to QA {id=bt1445}, no new builds found
[2012-04-11 07:12:31,660] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Testing - VCSReportUtilizer Reporting {id=bt1472}, no new builds found
[2012-04-11 07:12:31,660] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: zProxy start (quick build core) {id=bt1482}, no new builds found
[2012-04-11 07:12:31,691] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 01. CI - VCSServerIntegration {id=bt1521}, no new builds found
[2012-04-11 07:12:31,707] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 02. CI - VCSIntegration.DocumentManagement {id=bt1522}, no new builds found
[2012-04-11 07:12:31,707] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 03. CI - IPortalHelper {id=bt1545}, no new builds found
[2012-04-11 07:12:31,707] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 04. CI - IRemoteHelper {id=bt1523}, no new builds found
[2012-04-11 07:12:31,722] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 05. CI - VPIntegration {id=bt1524}, no new builds found
[2012-04-11 07:12:31,722] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 06. CI - ServerConfiguration {id=bt1525}, no new builds found
[2012-04-11 07:12:31,722] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 07. CI - VPServiceLibrary {id=bt1526}, no new builds found
[2012-04-11 07:12:31,722] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 08. CI - RecordingFramework {id=bt1527}, no new builds found
[2012-04-11 07:12:31,738] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 09. CI - WCF Classes {id=bt1528}, no new builds found
[2012-04-11 07:12:31,738] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 10. CI - RecordingForms {id=bt1529}, no new builds found
[2012-04-11 07:12:31,753] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 11. CI - VCSSec {id=bt1530}, no new builds found
[2012-04-11 07:12:31,753] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 12. CI - VPStandards {id=bt1531}, no new builds found
[2012-04-11 07:12:31,753] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 13. CI - VCSPDF {id=bt1532}, no new builds found
[2012-04-11 07:12:31,769] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 14. CI - Standards {id=bt1533}, no new builds found
[2012-04-11 07:12:31,769] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 15. CI - VCSCrystalReports {id=bt1534}, no new builds found
[2012-04-11 07:12:31,800] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:31,800] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 16. CI - Reports {id=bt1535}, no new builds found
[2012-04-11 07:12:31,800] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 17. CI - UserConfig {id=bt1536}, no new builds found
[2012-04-11 07:12:31,816] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 18. CI - VCSPartCanvas {id=bt1537}, no new builds found
[2012-04-11 07:12:31,816] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 29 msec
[2012-04-11 07:12:31,832] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 19. CI - VCSCanvasParts {id=bt1538}, no new builds found
[2012-04-11 07:12:31,832] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 20. CI - IUpdaterHelpersHelper {id=bt1539}, no new builds found
[2012-04-11 07:12:31,832] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 21. CI - IUpdaterHelper {id=bt1540}, no new builds found
[2012-04-11 07:12:31,847] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 22. CI - IVPClientUpdater {id=bt1541}, no new builds found
[2012-04-11 07:12:31,847] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 23. CI - ServiceUpdater {id=bt1542}, no new builds found
[2012-04-11 07:12:31,847] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 24. CI - IReportAttachments {id=bt1543}, no new builds found
[2012-04-11 07:12:31,847] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 25. CI - CRUFL6 {id=bt1544}, no new builds found
[2012-04-11 07:12:31,863] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 26. Collect - Commit - Stage {id=bt1547}, no new builds found
[2012-04-11 07:12:31,863] DEBUG - Side.impl.BuildTriggersChecker - Finished triggers polling for active build configurations
[2012-04-11 07:12:31,863] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor done: 237 msec
[2012-04-11 07:12:33,910] DEBUG - lers.viewLog.ViewLogController - ViewLogController.fillModel(TOTAL) start: 0 msec
[2012-04-11 07:12:33,910] DEBUG - lers.viewLog.ViewLogController - ViewLogController.fillModel(TOTAL) stopped: 4 msec
[2012-04-11 07:12:33,925] DEBUG - buildLog.MessagesStateProvider - Flow: -642892918 not found, creating it in flow: null
[2012-04-11 07:12:33,941] DEBUG - buildLog.MessagesStateProvider - Flow: -642892918 not found, creating it in flow: null
[2012-04-11 07:12:33,941] DEBUG - buildLog.MessagesStateProvider - Flow started: 860372860, parent flow: -642892918
[2012-04-11 07:12:33,941] DEBUG - buildLog.MessagesStateProvider - Flow: 860372860 not found, creating it in flow: FlowMessagesState{myFlowId=-642892918, myParentState=null, myChildStates=[]}
[2012-04-11 07:12:33,941] DEBUG - buildLog.MessagesStateProvider - Flow finished: 860372860
[2012-04-11 07:12:36,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:36,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 4 msec
[2012-04-11 07:12:36,816] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:36,816] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 11 msec
[2012-04-11 07:12:41,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:41,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 4 msec
[2012-04-11 07:12:41,816] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:41,816] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 7 msec
[2012-04-11 07:12:41,863] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor start: 0 msec
[2012-04-11 07:12:41,863] DEBUG - Side.impl.BuildTriggersChecker - Start triggers polling for 476 active build configuration
[2012-04-11 07:12:41,863] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2011Q4 - 6.4.1-2-3-4-5 :: Capture SVN Test {id=bt1569}, no new builds found
[2012-04-11 07:12:41,879] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2011Q4 - 6.4.1-2-3-4-5 :: CI - Help MadCap - Build and Deploy to Help folder {id=bt959}, no new builds found
[2012-04-11 07:12:41,879] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2011Q4 - 6.4.1-2-3-4-5 :: Dependency - Reports - Deploy SSRS Reports from SVN to DEV {id=bt1114}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2011Q4 - 6.4.1-2-3-4-5 :: Dependency - Reports - Deploy SSRS Reports from SVN to QA {id=bt1115}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2011Q4 - 6.4.1-2-3-4-5 :: Dependency - Reports - Deploy SSRS Reports from SVN to QA {id=bt1115}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2011Q4 - 6.4.1-2-3-4-5 :: Installer - Build Installers DEVELOPER {id=bt1038}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: CI - Help MadCap - Build and Deploy to Help folder {id=bt1268}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: Dependency - Reports - Deploy SSRS Reports from SVN to DEV {id=bt1324}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: Dependency - Reports - Deploy SSRS Reports from SVN to QA {id=bt1325}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: Dependency - Reports - Deploy SSRS Reports from SVN to QA {id=bt1325}, no new builds found
[2012-04-11 07:12:41,895] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: QA - Deploy646Machines.py {id=bt1517}, no new builds found
[2012-04-11 07:12:41,910] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: Testing - VCSReportUtilizer Reporting {id=bt1352}, no new builds found
[2012-04-11 07:12:41,910] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: Testing - VLAB Installer tests {id=bt1506}, no new builds found
[2012-04-11 07:12:41,910] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration 2012Q2 - 6.4.6 :: zProxy start (quick build core) {id=bt1362}, no new builds found
[2012-04-11 07:12:41,910] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration Data Stewards DBCompares :: DBCompare 2012q3db.Viewpoint & 2012q3db.VPProd {id=bt1568}, no new builds found
[2012-04-11 07:12:41,926] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration Data Stewards DBCompares :: DBCompare 2012q3db.VPTest & 2012q3db.VPProd {id=bt1567}, no new builds found
[2012-04-11 07:12:41,957] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration Regression Manager :: CI : Regression Manager Build {id=bt647}, no new builds found
[2012-04-11 07:12:41,957] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration Regression Manager :: CI : Regression Manager Installer Build {id=bt649}, no new builds found
[2012-04-11 07:12:42,004] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration Regression Manager :: Regression Manager Setup Delivery {id=bt646}, no new builds found
[2012-04-11 07:12:42,004] DEBUG - Side.impl.BuildTriggersChecker - Finished triggers polling for active build configurations
[2012-04-11 07:12:42,004] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor done: 146 msec
[2012-04-11 07:12:42,176] DEBUG - ains.buildServer.util.WatchDog - Ping start: 0 msec
[2012-04-11 07:12:42,676] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCS631Build{id=2} at address: 172.25.4.65:9090
[2012-04-11 07:12:42,691] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCS631Build{id=2}:OK
[2012-04-11 07:12:42,691] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCS640Build{id=3} at address: 172.25.4.38:9090
[2012-04-11 07:12:42,707] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCS640Build{id=3}:OK
[2012-04-11 07:12:42,707] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCSBUILDMASTER{id=4} at address: 127.0.0.1:9090
[2012-04-11 07:12:42,723] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCSBUILDMASTER{id=4}:OK
[2012-04-11 07:12:42,723] DEBUG - ains.buildServer.util.WatchDog - Ping done: 547 msec
[2012-04-11 07:12:46,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:46,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 4 msec
[2012-04-11 07:12:46,754] DEBUG - ide.impl.agent.AgentUpradeTask - Agent VCS631Build: 21349:21349-md5-2bc677c2b4230599c35216a65fd56fb0
[2012-04-11 07:12:46,754] DEBUG - ide.impl.agent.AgentUpradeTask - Agent VCS640Build: 21349:21349-md5-2bc677c2b4230599c35216a65fd56fb0
[2012-04-11 07:12:46,754] DEBUG - ide.impl.agent.AgentUpradeTask - Agent VCSBUILDMASTER: 21349:21349-md5-2bc677c2b4230599c35216a65fd56fb0
[2012-04-11 07:12:46,754] DEBUG - ide.impl.agent.AgentUpradeTask - Server agent information: 21349:21349-md5-2bc677c2b4230599c35216a65fd56fb0
[2012-04-11 07:12:46,817] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:46,817] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 7 msec
[2012-04-11 07:12:51,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:51,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 4 msec
[2012-04-11 07:12:51,817] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:51,817] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 7 msec
[2012-04-11 07:12:52,004] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor start: 0 msec
[2012-04-11 07:12:52,004] DEBUG - Side.impl.BuildTriggersChecker - Start triggers polling for 476 active build configuration
[2012-04-11 07:12:52,004] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - Help MadCap - Build and Deploy to Help folder {id=bt1388}, no new builds found
[2012-04-11 07:12:52,004] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - RemoteHelperCS {id=bt1595}, no new builds found
[2012-04-11 07:12:52,004] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - RemoteService {id=bt1405}, no new builds found
[2012-04-11 07:12:52,020] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: CI - VP {id=bt1426}, no new builds found
[2012-04-11 07:12:52,020] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Deploy - Reports - Deploy SSRS Reports from SVN to DEV {id=bt1444}, no new builds found
[2012-04-11 07:12:52,020] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Deploy - Reports - Deploy SSRS Reports from SVN to QA {id=bt1445}, no new builds found
[2012-04-11 07:12:52,020] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Deploy - Reports - Deploy SSRS Reports from SVN to QA {id=bt1445}, no new builds found
[2012-04-11 07:12:52,020] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: Testing - VCSReportUtilizer Reporting {id=bt1472}, no new builds found
[2012-04-11 07:12:52,020] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 :: zProxy start (quick build core) {id=bt1482}, no new builds found
[2012-04-11 07:12:52,036] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 01. CI - VCSServerIntegration {id=bt1521}, no new builds found
[2012-04-11 07:12:52,036] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 02. CI - VCSIntegration.DocumentManagement {id=bt1522}, no new builds found
[2012-04-11 07:12:52,036] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 03. CI - IPortalHelper {id=bt1545}, no new builds found
[2012-04-11 07:12:52,051] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 04. CI - IRemoteHelper {id=bt1523}, no new builds found
[2012-04-11 07:12:52,051] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 05. CI - VPIntegration {id=bt1524}, no new builds found
[2012-04-11 07:12:52,051] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 06. CI - ServerConfiguration {id=bt1525}, no new builds found
[2012-04-11 07:12:52,051] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 07. CI - VPServiceLibrary {id=bt1526}, no new builds found
[2012-04-11 07:12:52,067] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 08. CI - RecordingFramework {id=bt1527}, no new builds found
[2012-04-11 07:12:52,067] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 09. CI - WCF Classes {id=bt1528}, no new builds found
[2012-04-11 07:12:52,067] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 10. CI - RecordingForms {id=bt1529}, no new builds found
[2012-04-11 07:12:52,082] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 11. CI - VCSSec {id=bt1530}, no new builds found
[2012-04-11 07:12:52,082] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 12. CI - VPStandards {id=bt1531}, no new builds found
[2012-04-11 07:12:52,082] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 13. CI - VCSPDF {id=bt1532}, no new builds found
[2012-04-11 07:12:52,098] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 14. CI - Standards {id=bt1533}, no new builds found
[2012-04-11 07:12:52,098] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 15. CI - VCSCrystalReports {id=bt1534}, no new builds found
[2012-04-11 07:12:52,098] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 16. CI - Reports {id=bt1535}, no new builds found
[2012-04-11 07:12:52,098] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 17. CI - UserConfig {id=bt1536}, no new builds found
[2012-04-11 07:12:52,114] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 18. CI - VCSPartCanvas {id=bt1537}, no new builds found
[2012-04-11 07:12:52,114] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 19. CI - VCSCanvasParts {id=bt1538}, no new builds found
[2012-04-11 07:12:52,114] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 20. CI - IUpdaterHelpersHelper {id=bt1539}, no new builds found
[2012-04-11 07:12:52,129] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 21. CI - IUpdaterHelper {id=bt1540}, no new builds found
[2012-04-11 07:12:52,129] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 22. CI - IVPClientUpdater {id=bt1541}, no new builds found
[2012-04-11 07:12:52,129] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 23. CI - ServiceUpdater {id=bt1542}, no new builds found
[2012-04-11 07:12:52,145] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 24. CI - IReportAttachments {id=bt1543}, no new builds found
[2012-04-11 07:12:52,145] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 25. CI - CRUFL6 {id=bt1544}, no new builds found
[2012-04-11 07:12:52,145] DEBUG - ency.FinishBuildTriggerService - Won't trigger new build in configuration TRUNK - 6.5.0 CommonAssemblies :: 26. Collect - Commit - Stage {id=bt1547}, no new builds found
[2012-04-11 07:12:52,145] DEBUG - Side.impl.BuildTriggersChecker - Finished triggers polling for active build configurations
[2012-04-11 07:12:52,145] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor done: 152 msec
[2012-04-11 07:12:56,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:56,629] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 6 msec
[2012-04-11 07:12:56,817] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:56,817] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 7 msec
[2012-04-11 07:12:56,989] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:56,989] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,004] DEBUG - jetbrains.buildServer.SERVER - Detaching changes from build promotion BuildPromotion{myId=317770, myPersonal=false, myBuildTypeId='bt1594', myModificationId=39093, myRevisions=[BuildRevision[myVcsRootEntry=VcsRootEntry[myVcsRoot=svn: svn://vcssvn.vcs.coaxis.net/_TRUNK {instance id=3453, parent id=149}, myCheckoutRules=Viewpoint/ClientSide/AdditionalRepositoryFiles/CD Templates=>CD Templates
Thirdparty/fonts=>Thirdparty/fonts
Thirdparty/Telerik=>Thirdparty/Telerik
Thirdparty/SyncFusion/Essential PDF=>Thirdparty/SyncFusion/Essential PDF
Thirdparty/Redemption=>Thirdparty/Redemption
Thirdparty/Microsoft/etc=>Thirdparty/Microsoft/etc
Thirdparty/Microsoft/Word 2010=>Thirdparty/Microsoft/Word 2010
Thirdparty/Microsoft/Word 2007 Interop=>Thirdparty/Microsoft/Word 2007 Interop
Thirdparty/Microsoft/VSTO=>Thirdparty/Microsoft/VSTO
Thirdparty/Microsoft/SQLServer.MSXML6_interop=>Thirdparty/Microsoft/SQLServer.MSXML6_interop
Thirdparty/Microsoft/SMO=>Thirdparty/Microsoft/SMO
Thirdparty/Microsoft/ReportingServices=>Thirdparty/Microsoft/ReportingServices
Thirdparty/Microsoft/PrimaryInteropAssembly/PrimaryInteropAssembly=>Thirdparty/Microsoft/PrimaryInteropAssembly/PrimaryInteropAssembly
Thirdparty/Microsoft/Outlook 2007 Interop=>Thirdparty/Microsoft/Outlook 2007 Interop
Thirdparty/Microsoft/Office XP Interop=>Thirdparty/Microsoft/Office XP Interop
Thirdparty/Microsoft/Analysis Services=>Thirdparty/Microsoft/Analysis Services
Thirdparty/Madcap=>Thirdparty/Madcap
Thirdparty/ComponentOne=>Thirdparty/ComponentOne
Thirdparty/Atalasoft=>Thirdparty/Atalasoft
BI/Integration Services/ProcessCubes2008=>PC2008
BI/Integration Services/ProcessCubes2005=>PC2005
], myRevision=RepositoryVersion[myVersion='66706_2012/03/28 08:50:04 -0700', myDisplayVersion='66706']]], myAssociatedBuildId=255367} because promotion is marked as incomplete
[2012-04-11 07:12:57,020] DEBUG - jetbrains.buildServer.SERVER - System problem cleared after #10 {build id=255367}
[2012-04-11 07:12:57,020] DEBUG - jetbrains.buildServer.SERVER - System problem raised after #10 {build id=255367}: Failed to perform checkout on agent: java.lang.RuntimeException: svn: E210004: Handshake failed, received: ' '
[2012-04-11 07:12:57,036] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,036] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,036] DEBUG - buildLog.MessagesStateProvider - Flow started: 32625726, parent flow: -642892918
[2012-04-11 07:12:57,036] DEBUG - buildLog.MessagesStateProvider - Flow: 32625726 not found, creating it in flow: FlowMessagesState{myFlowId=-642892918, myParentState=null, myChildStates=[]}
[2012-04-11 07:12:57,051] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,051] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,067] DEBUG - facts.ArtifactUploadController - Publishing '.teamcity/properties/build.finish.properties.gz' for build #10 {build id=255367}
[2012-04-11 07:12:57,067] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,067] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,083] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,083] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,083] DEBUG - buildLog.MessagesStateProvider - Flow finished: 32625726
[2012-04-11 07:12:57,098] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,098] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,145] INFO - de.impl.history.DBBuildHistory - Start creating history entry for TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts 255367, date: 1334153577109
[2012-04-11 07:12:57,145] INFO - de.impl.history.DBBuildHistory - End creating history entry for TRUNK - 6.5.0 :: ZZZ ALWAYS FAILS MUST FIX THIS!!!! CI - ThirdpartyStaticArtifacts 255367
[2012-04-11 07:12:57,145] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,145] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,161] DEBUG - .PositionAwareSortedCollection - Start PositionAware sorting.
[2012-04-11 07:12:57,161] DEBUG - .PositionAwareSortedCollection - Finished PositionAware sorting. Sorted items: <empty>
[2012-04-11 07:12:57,176] INFO - ndexer.EventBasedBuildsIndexer - Indexing finishing build: #10 {build id=255367}
[2012-04-11 07:12:57,176] DEBUG - NuGetArtifactsMetadataProvider - Looking for NuGet packages in #10 {build id=255367}
[2012-04-11 07:12:57,176] DEBUG - jetbrains.buildServer.SERVER - SearchService: buildFinished Running build bt1594 on VCS640Build:255367
[2012-04-11 07:12:57,176] DEBUG - jetbrains.buildServer.SERVER - SearchService: deleteBuild 255367
[2012-04-11 07:12:57,176] DEBUG - jetbrains.buildServer.SERVER - SearchService: addBuild 255367
[2012-04-11 07:12:57,176] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:12:57,176] INFO - tbrains.buildServer.ACTIVITIES - Finished 255367
[2012-04-11 07:12:57,176] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor start: 0 msec
[2012-04-11 07:12:57,176] DEBUG - Side.impl.BuildTriggersChecker - Start triggers polling for 476 active build configuration
[2012-04-11 07:12:57,176] DEBUG - Side.impl.BuildTriggersChecker - Finished triggers polling for active build configurations
[2012-04-11 07:12:57,176] DEBUG - ains.buildServer.util.WatchDog - Build Triggers Monitor done: 2 msec
[2012-04-11 07:12:57,176] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:12:57,176] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 5 msec
[2012-04-11 07:12:57,176] DEBUG - ains.buildServer.util.WatchDog - Ping start: 0 msec
[2012-04-11 07:12:57,208] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 32 msec
[2012-04-11 07:12:57,645] DEBUG - jetbrains.buildServer.SERVER - SearchService.createWriter
[2012-04-11 07:12:57,645] DEBUG - jetbrains.buildServer.SERVER - SearchService.deleteBuild #255367
[2012-04-11 07:12:57,645] DEBUG - jetbrains.buildServer.SERVER - SearchService.updateSearcher
[2012-04-11 07:12:57,645] DEBUG - jetbrains.buildServer.SERVER - Wed Apr 11 07:12:57 PDT 2012 SearchService.indexBuilds (1 left)
[2012-04-11 07:12:57,676] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCS631Build{id=2} at address: 172.25.4.65:9090
[2012-04-11 07:12:57,692] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCS631Build{id=2}:OK
[2012-04-11 07:12:57,692] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCS640Build{id=3} at address: 172.25.4.38:9090
[2012-04-11 07:12:57,708] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCS640Build{id=3}:OK
[2012-04-11 07:12:57,708] DEBUG - rverSide.impl.XmlRpcBasedAgent - Start pinging agent VCSBUILDMASTER{id=4} at address: 127.0.0.1:9090
[2012-04-11 07:12:57,708] DEBUG - jetbrains.buildServer.SERVER - SearchService.closeWriter
[2012-04-11 07:12:57,708] DEBUG - jetbrains.buildServer.SERVER - SearchService.updateSearcher
[2012-04-11 07:12:57,723] DEBUG - rverSide.impl.XmlRpcBasedAgent - Done pinging VCSBUILDMASTER{id=4}:OK
[2012-04-11 07:12:57,723] DEBUG - ains.buildServer.util.WatchDog - Ping done: 536 msec
[2012-04-11 07:12:57,801] DEBUG - jetbrains.buildServer.SERVER - SearchService.getIndexSearcher - NEW - size:669002
[2012-04-11 07:12:57,801] DEBUG - jetbrains.buildServer.SERVER - sleeping for 156
[2012-04-11 07:12:58,167] DEBUG - buildLog.MessagesStateProvider - Flow: -642892918 not found, creating it in flow: null
[2012-04-11 07:12:58,167] DEBUG - buildLog.MessagesStateProvider - Flow started: 860372860, parent flow: -642892918
[2012-04-11 07:12:58,167] DEBUG - buildLog.MessagesStateProvider - Flow: 860372860 not found, creating it in flow: FlowMessagesState{myFlowId=-642892918, myParentState=null, myChildStates=[]}
[2012-04-11 07:12:58,167] DEBUG - buildLog.MessagesStateProvider - Flow finished: 860372860
[2012-04-11 07:12:58,168] DEBUG - buildLog.MessagesStateProvider - Flow started: 32625726, parent flow: -642892918
[2012-04-11 07:12:58,168] DEBUG - buildLog.MessagesStateProvider - Flow: 32625726 not found, creating it in flow: FlowMessagesState{myFlowId=-642892918, myParentState=null, myChildStates=[]}
[2012-04-11 07:12:58,168] DEBUG - buildLog.MessagesStateProvider - Flow finished: 32625726
[2012-04-11 07:12:58,187] DEBUG - jetbrains.buildServer.SERVER - Loading tests for builds : [[255367]]
[2012-04-11 07:12:58,201] DEBUG - rver.duplicator.DuplicatesInfo - No duplicate_stats for BUILD_ID=255367
[2012-04-11 07:12:58,697] DEBUG - buildLog.MessagesStateProvider - Flow started: 32625726, parent flow: -642892918
[2012-04-11 07:12:58,697] DEBUG - buildLog.MessagesStateProvider - Flow: 32625726 not found, creating it in flow: FlowMessagesState{myFlowId=-642892918, myParentState=null, myChildStates=[]}
[2012-04-11 07:12:58,702] DEBUG - buildLog.MessagesStateProvider - Flow finished: 32625726
[2012-04-11 07:13:02,178] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor start: 0 msec
[2012-04-11 07:13:02,178] DEBUG - ains.buildServer.util.WatchDog - Vcs Monitor done: 9 msec
[2012-04-11 07:13:02,209] DEBUG - ains.buildServer.util.WatchDog - Flush Queue start: 0 msec
[2012-04-11 07:13:02,209] DEBUG - ains.buildServer.util.WatchDog - Flush Queue done: 8 msec
Greg,
We'll continue troubleshooting in the issue TW-20903.