Git slower on windows when Teamcity build agent is run as service as opposed to as console

Answered

We have general git slowness under windows using TeamCity Enterprise 9.1.1 (build 37059) with our builds taking about 5 times longer than on other operating systems.  In investigating this I found that a lot of the time in Git is taken up doing submodule init, sync and update --force about 5 times.  Technically this should be a no op however I found that if I run the build agent as console instead of service by stopping the service and running it from a dos prompt with this command line:

c:\BuildAgent\launcher\bin\TeamCityAgentService-windows-x86-32.exe -c c:\BuildAgent\launcher\conf\wrapper.conf

It takes about 1 minute instead of 4 minutes which is a significant performance boost.

I noticed that the wrapper version you are using is 3.2.3 and the latest is 3.5.28.  I tried replacing the wrapper.jar with the latest from here:

https://wrapper.tanukisoftware.com/

But it looks like part of the wrapper is build into the TeamcityBuildAgent.exe as I get the following version mismatch error:

WARNING - The Wrapper jar file currently in use is version "3.5.28"
INFO | jvm 1 | 2016/03/11 14:28:18 | WrapperManager: while the version of the Wrapper which launched this JVM is
INFO | jvm 1 | 2016/03/11 14:28:18 | WrapperManager: "3.2.3".
INFO | jvm 1 | 2016/03/11 14:28:18 | WrapperManager: The Wrapper may appear to work correctly but some features may
INFO | jvm 1 | 2016/03/11 14:28:18 | WrapperManager: not function correctly. This configuration has not been tested
INFO | jvm 1 | 2016/03/11 14:28:18 | WrapperManager: and is not supported.

Looking at the release notes for wrapper it's possible they've fixed this problem.  So wondering if it would be possible to get a matching agent with the latest wrapper code built in.  Any other advice for making git faster under windows would be appreciated as well.

One other interesting data point.  The performance gains by running as console were maintained until a reboot if the console was run under the same account as the services.  So if you log in under the services account, run as console, switch back to run the service the service now runs faster.  If you use another account the performance gains go away as soon as you switch back to service.

Thanks a lot.

5 comments

Hi Andrew,

please provide agent logs covering the build executed as a server and the build executed from console.

0

Run as service log:

[2016-03-24 09:20:06,299] INFO - ldServer.AGENT.PollingProtocol - New command is received from server "runBuild" {id = 1}
[2016-03-24 09:20:06,377] INFO - jetbrains.buildServer.AGENT -



[2016-03-24 09:20:06,377] INFO - jetbrains.buildServer.AGENT - ===================================================
[2016-03-24 09:20:06,377] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 4435785, buildTypeId=bt112952
[2016-03-24 09:20:06,377] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build context id=4435785: startup date [Thu Mar 24 09:20:06 PDT 2016]; parent: jetbrains.buildServer.agent.AgentMain2$2@1c79255
[2016-03-24 09:20:06,799] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2016-03-24 09:20:06,814] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2016-03-24 09:20:06,814] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 09:20:06,861] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2016-03-24 09:20:06,877] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2016-03-24 09:20:06,892] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2016-03-24 09:20:06,970] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2016-03-24 09:20:06,970] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2016-03-24 09:20:06,970] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2016-03-24 09:20:06,970] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: D:\temp\buildTmp
[2016-03-24 09:20:06,986] INFO - rectories.DirectoryCleanerImpl - Move directory D:\temp\buildTmp to D:\temp\.old\buildTmp_0 for cleaning
[2016-03-24 09:20:07,001] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 128.33 GB, required 18 GB.
[2016-03-24 09:20:07,001] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 09:20:07,001] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2016-03-24 09:20:07,064] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 09:20:07,064] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [D:\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2016-03-24 09:20:07,064] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2016-03-24 09:20:07,064] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:20:07,064] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:20:07,064] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 09:20:07,064] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 09:20:07,079] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 128.33 GB, required 18 GB.
[2016-03-24 09:20:07,079] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2016-03-24 09:20:07,079] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2016-03-24 09:20:07,079] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\work\1dd3d5f85bbc88f0
[2016-03-24 09:20:07,079] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromAgent
[2016-03-24 09:20:07,079] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: agent side checkout
[2016-03-24 09:20:07,079] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 4435785
[2016-03-24 09:20:07,095] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2016-03-24 09:20:07,111] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:20:07,189] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2016-03-24 09:20:07,189] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:20:07,189] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2016-03-24 09:20:07,220] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 09:20:07,345] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir 1dd3d5f85bbc88f0 for build 4435785 dirty
[2016-03-24 09:20:07,345] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["client-engineering" {internal id=4968, properties: [agentCleanFilesPolicy=ALL_UNTRACKED; agentCleanPolicy=ALWAYS; authMethod=TEAMCITY_SSH_KEY; branch=refs/heads/master; ignoreKnownHosts=true; submoduleCheckout=CHECKOUT; teamcity:branchSpec=+:refs/heads/*
+:refs/(pull-requests/*)/from
-:refs/heads/release/scrt/r2_2; teamcity:vcsRootName=client-engineering; teamcitySshKey=TeamCity key; url=git:tera/client-engineering.git; useAlternates=true; userForTags=TeamCity Minion <teamcity-minion@teradici.local>; usernameStyle=USERID; vcs=jetbrains.git; ]}; Checkout rules: ]]]
[2016-03-24 09:20:07,345] INFO - jetbrains.buildServer.AGENT - Recording vcs state: revision: fe20f604d9a3c43f7a1351031ad072919a3b6491, VCS root signature: cccc74a29abf45fb, checkout rules: =>
[2016-03-24 09:20:07,345] INFO - jetbrains.buildServer.AGENT - Moved configuration file 1dd3d5f85bbc88f0.xml to old
[2016-03-24 09:20:07,345] INFO - jetbrains.buildServer.AGENT - Stored new configuration file 1dd3d5f85bbc88f0.xml
[2016-03-24 09:20:07,345] INFO - pl.patch.ProjectSourcesOnAgent - Updating sources for root id=4968; name=client-engineering; revision: fe20f604d9a3c43f7a1351031ad072919a3b6491
[2016-03-24 09:20:07,407] INFO - vcs.git.agent.PluginConfigImpl - Use the mirrors option specified in the VCS root
[2016-03-24 09:20:07,407] INFO - cs.git.agent.UpdaterWithMirror - Update local mirror of root client-engineering at D:\system\git\git-FAB7A35C.git
[2016-03-24 09:20:12,296] INFO - gers.vcs.git.agent.UpdaterImpl - Starting update of root client-engineering in D:\work\1dd3d5f85bbc88f0 to revision fe20f604d9a3c43f7a1351031ad072919a3b6491
[2016-03-24 09:25:41,910] INFO - jetbrains.buildServer.AGENT - Patch applied for build with id 4435785
[2016-03-24 09:25:41,910] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir 1dd3d5f85bbc88f0 for build 4435785 clean
[2016-03-24 09:25:41,910] INFO - jetbrains.buildServer.AGENT - newConfigurationFile.exists(): true, newConfigurationFile.renameTo(currentConfigurationFile): true
[2016-03-24 09:25:41,910] INFO - l.patch.UpdateSourcesFromAgent - Agent sources updated successfully
[2016-03-24 09:25:41,910] INFO - ch.UpdateSourcesBuildStageBase - Sources updated for 5m:34s
[2016-03-24 09:25:41,910] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ResetAgentDirectoryDirtyState
[2016-03-24 09:25:41,925] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 129.39 GB, required 18 GB.
[2016-03-24 09:25:41,925] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.AppendBuildParametersFromFileStage
[2016-03-24 09:25:41,925] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReplaceReferencesInArtifactDependenciesStage
[2016-03-24 09:25:41,925] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage
[2016-03-24 09:25:41,941] INFO - jetbrains.buildServer.AGENT - Resolving artifact dependencies...
[2016-03-24 09:25:41,941] INFO - jetbrains.buildServer.AGENT - Started downloading files from <Teradici Client Engineering :: Desktop Client Builds :: Client Binaries :: Client Binaries - Get Virtual Channel Plugins, build #fe20f604d9a3c43f7a1351031ad072919a3b6491 [id 4433740]>
[2016-03-24 09:25:52,736] INFO - jetbrains.buildServer.AGENT - 17 files retrieved from <Teradici Client Engineering :: Desktop Client Builds :: Client Binaries :: Client Binaries - Get Virtual Channel Plugins, build #fe20f604d9a3c43f7a1351031ad072919a3b6491 [id 4433740]> for pattern [vchan.zip!**=>product]
[2016-03-24 09:25:52,736] INFO - jetbrains.buildServer.AGENT - Finished resolving artifacts
[2016-03-24 09:25:52,752] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 129.31 GB, required 18 GB.
[2016-03-24 09:25:52,752] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReportPreparationEndStage
[2016-03-24 09:25:52,752] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.BuildRunTimeoutTimer
[2016-03-24 09:25:52,752] INFO - gent.impl.BuildRunTimeoutTimer - Build execution timeout is set to: 720 minutes
[2016-03-24 09:25:52,752] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.steps.ForEachBuildRunnerStage
[2016-03-24 09:25:52,752] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build runner context id=4435785 runner 1 of 2: startup date [Thu Mar 24 09:25:52 PDT 2016]; parent: SubContext: running build context id=4435785
[2016-03-24 09:25:52,877] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CreateBuildWorkingDirectoryStage
[2016-03-24 09:25:52,908] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 09:25:52,908] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 09:25:52,908] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 09:25:52,908] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.RegisterPerBuildFileWriterPropertiesRunnerStage
[2016-03-24 09:25:52,908] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.FireBeforeRunnerStartedStage
[2016-03-24 09:25:52,924] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallBuildRunnerPrecondition
[2016-03-24 09:25:52,924] INFO - rt.CallBuildRunnerPrecondition - Call BuildRunnerPrecondition: class jetbrains.buildServer.agent.feature.RubyEnvConfiguratorService
[2016-03-24 09:25:52,924] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PerformFinalParametersResolveStage
[2016-03-24 09:25:52,924] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.SavePropertiesToFilesStage
[2016-03-24 09:25:53,017] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallRunnerStage
[2016-03-24 09:25:53,017] INFO - .impl.runner.CallRunnerService - Found runner python for 4435785
[2016-03-24 09:25:53,017] INFO - erStages.start.CallRunnerStage - Found runner python for 4435785
[2016-03-24 09:25:53,017] INFO - erStages.start.CallRunnerStage - Start build runner for build 4435785 python
[2016-03-24 09:25:53,017] INFO - erStages.start.CallRunnerStage - ----------------------------------------- [ Build Agent Testing::Client Binaries - Build - Windows - Release 32-bit #fe20f604d9a3c43f7a1351031ad072919a3b6491 (buildId = 4435785) ] -----------------------------------------
[2016-03-24 09:25:53,048] INFO - nner2.OsProcessHandlerListener - C:\Python27\python.exe .script.py
[2016-03-24 09:36:12,013] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.UnsubscribePropertiesFileUpdaterRunnedFStage
[2016-03-24 09:36:12,013] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FlushBuildLogRunnerFStage
[2016-03-24 09:36:12,044] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FireRunnerFinishedFStage
[2016-03-24 09:36:12,059] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build runner context id=4435785 runner 1 of 2: startup date [Thu Mar 24 09:25:52 PDT 2016]; parent: SubContext: running build context id=4435785
[2016-03-24 09:36:12,075] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build runner context id=4435785 runner 2 of 2: startup date [Thu Mar 24 09:36:12 PDT 2016]; parent: SubContext: running build context id=4435785
[2016-03-24 09:36:12,200] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CreateBuildWorkingDirectoryStage
[2016-03-24 09:36:12,215] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 09:36:12,215] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 09:36:12,215] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 09:36:12,231] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.RegisterPerBuildFileWriterPropertiesRunnerStage
[2016-03-24 09:36:12,231] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.FireBeforeRunnerStartedStage
[2016-03-24 09:36:12,247] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallBuildRunnerPrecondition
[2016-03-24 09:36:12,247] INFO - rt.CallBuildRunnerPrecondition - Call BuildRunnerPrecondition: class jetbrains.buildServer.agent.feature.RubyEnvConfiguratorService
[2016-03-24 09:36:12,262] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PerformFinalParametersResolveStage
[2016-03-24 09:36:12,262] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.SavePropertiesToFilesStage
[2016-03-24 09:36:12,293] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallRunnerStage
[2016-03-24 09:36:12,293] INFO - .impl.runner.CallRunnerService - Found runner python for 4435785
[2016-03-24 09:36:12,293] INFO - erStages.start.CallRunnerStage - Found runner python for 4435785
[2016-03-24 09:36:12,293] INFO - erStages.start.CallRunnerStage - Start build runner for build 4435785 python
[2016-03-24 09:36:12,293] INFO - erStages.start.CallRunnerStage - ----------------------------------------- [ Build Agent Testing::Client Binaries - Build - Windows - Release 32-bit #0.0.0_master@38676-fe20f60 (buildId = 4435785) ] -----------------------------------------
[2016-03-24 09:36:12,293] INFO - nner2.OsProcessHandlerListener - C:\Python27\python.exe .script.py
[2016-03-24 09:36:12,350] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.AgentBuildStepStatusFixer
[2016-03-24 09:36:12,350] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.UnsubscribePropertiesFileUpdaterRunnedFStage
[2016-03-24 09:36:12,366] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FlushBuildLogRunnerFStage
[2016-03-24 09:36:12,382] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FireRunnerFinishedFStage
[2016-03-24 09:36:12,382] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build runner context id=4435785 runner 2 of 2: startup date [Thu Mar 24 09:36:12 PDT 2016]; parent: SubContext: running build context id=4435785
[2016-03-24 09:36:12,382] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FlushBuildLogFStage
[2016-03-24 09:36:12,397] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireBeforeBuildFinishFStage
[2016-03-24 09:36:12,413] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.PublishBuildPropertiesFStage
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [D:\temp\agentTmp\build.finish.properties.gz=>.teamcity/properties]
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:36:12,460] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.PublishArtifactsFStage
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [teamcity-info.xml]
[2016-03-24 09:36:12,460] INFO - jetbrains.buildServer.AGENT - Internal artifact path teamcity-info.xml not found
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [0] files
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:36:12,460] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:36:12,460] INFO - jetbrains.buildServer.AGENT - Publishing artifacts process started
[2016-03-24 09:36:12,460] INFO - jetbrains.buildServer.AGENT - Start: Searching for artifacts to publish in [.\product => artifacts.zip;_tempInstallerWorkingdir/PCoIP_Client_installer.exe]
[2016-03-24 09:36:12,491] INFO - jetbrains.buildServer.AGENT - Done: Searching for artifacts to publish, found [229] files
[2016-03-24 09:36:12,491] INFO - jetbrains.buildServer.AGENT - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:36:14,441] INFO - jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='tc-w2k8-agent34', AgentId=1628, BuildId=4435785, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='8UC2rCMY56DWikwX7syOD56mBjVCSiz8'}
[2016-03-24 09:36:16,501] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2016-03-24 09:36:16,516] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:36:16,657] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.finish.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2016-03-24 09:36:16,657] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.finish.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:36:16,657] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2016-03-24 09:36:16,688] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 09:36:16,735] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 09:36:39,717] INFO - jetbrains.buildServer.AGENT - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:36:39,717] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.WaitForArtifactsPublishedFStage
[2016-03-24 09:36:39,733] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using WebPublisher
[2016-03-24 09:36:39,748] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:36:56,162] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [_tempInstallerWorkingdir/PCoIP_Client_installer.exe] using 'WebPublisher', total files published: 1
[2016-03-24 09:36:56,162] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [_tempInstallerWorkingdir/PCoIP_Client_installer.exe] using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:36:56,162] INFO - jetbrains.buildServer.AGENT - Done: Publishing files
[2016-03-24 09:36:56,162] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using WebPublisher
[2016-03-24 09:36:56,178] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:38:34,562] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [product] to [artifacts.zip], using 'WebPublisher', total files published: 1
[2016-03-24 09:38:34,562] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [product] to [artifacts.zip], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:38:34,562] INFO - jetbrains.buildServer.AGENT - Done: Publishing files
[2016-03-24 09:38:34,562] INFO - jetbrains.buildServer.AGENT - Publishing artifacts process finished
[2016-03-24 09:38:34,593] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.RevertPersonalChangesFStage
[2016-03-24 09:38:34,593] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireAfterArtifactsPublishedFStage
[2016-03-24 09:38:34,593] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.SendBuildInterruptedIfNeededFStage
[2016-03-24 09:38:34,593] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FinishBuildOnAgentFStage
[2016-03-24 09:38:34,593] INFO - jetbrains.buildServer.AGENT - Build finished, build id 4435785
[2016-03-24 09:38:34,624] INFO - nt.impl.BuildRunAgentStateImpl - Disposing build context
[2016-03-24 09:38:34,624] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build context id=4435785: startup date [Thu Mar 24 09:20:06 PDT 2016]; parent: jetbrains.buildServer.agent.AgentMain2$2@1c79255
[2016-03-24 09:38:34,624] INFO - ent.impl.BuildAgentStateHolder - Build data was released for buildId= 4435785
[2016-03-24 09:38:34,624] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireBuildFinishedFStage
[2016-03-24 09:38:34,624] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.RegisterPropertiesFileNamesFStage
[2016-03-24 09:38:35,139] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 09:38:35,170] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 65 items removed
[2016-03-24 09:38:35,170] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 09:38:35,170] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 09:38:35,217] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 09:38:35,217] INFO - dDirectoryBasedCleanupRegistry - Start deleting files from D:\temp\.old
[2016-03-24 09:38:35,248] INFO - dDirectoryBasedCleanupRegistry - Stop deleting files from D:\temp\.old. 0 file(s) were deleted.
[2016-03-24 09:39:28,558] INFO - ldServer.AGENT.PollingProtocol - New command is received from server "runBuild" {id = 2}
[2016-03-24 09:39:28,589] INFO - jetbrains.buildServer.AGENT -



[2016-03-24 09:39:28,589] INFO - jetbrains.buildServer.AGENT - ===================================================
[2016-03-24 09:39:28,589] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 4435814, buildTypeId=bt112952
[2016-03-24 09:39:28,589] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build context id=4435814: startup date [Thu Mar 24 09:39:28 PDT 2016]; parent: jetbrains.buildServer.agent.AgentMain2$2@1c79255
[2016-03-24 09:39:28,776] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2016-03-24 09:39:28,776] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2016-03-24 09:39:28,776] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 09:39:28,823] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2016-03-24 09:39:28,839] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2016-03-24 09:39:28,854] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2016-03-24 09:39:28,870] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2016-03-24 09:39:28,870] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2016-03-24 09:39:28,870] INFO - rectories.DirectoryCleanerImpl - Move directory D:\temp\agentTmp to D:\temp\.old\agentTmp_0 for cleaning
[2016-03-24 09:39:28,870] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2016-03-24 09:39:28,870] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: D:\temp\buildTmp
[2016-03-24 09:39:28,870] INFO - rectories.DirectoryCleanerImpl - Move directory D:\temp\buildTmp to D:\temp\.old\buildTmp_0 for cleaning
[2016-03-24 09:39:28,886] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 127.98 GB, required 18 GB.
[2016-03-24 09:39:28,886] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 09:39:28,886] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2016-03-24 09:39:28,932] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 09:39:28,932] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [D:\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2016-03-24 09:39:28,932] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2016-03-24 09:39:28,932] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:39:28,932] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:39:28,932] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 09:39:28,932] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 09:39:28,948] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 127.98 GB, required 18 GB.
[2016-03-24 09:39:28,948] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2016-03-24 09:39:28,948] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2016-03-24 09:39:28,948] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\work\1dd3d5f85bbc88f0
[2016-03-24 09:39:28,948] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromAgent
[2016-03-24 09:39:28,948] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: agent side checkout
[2016-03-24 09:39:28,948] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 4435814
[2016-03-24 09:39:28,964] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2016-03-24 09:39:28,979] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:39:29,026] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2016-03-24 09:39:29,026] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:39:29,026] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2016-03-24 09:39:29,057] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 09:39:29,213] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir 1dd3d5f85bbc88f0 for build 4435814 dirty
[2016-03-24 09:39:29,213] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["client-engineering" {internal id=4968, properties: [agentCleanFilesPolicy=ALL_UNTRACKED; agentCleanPolicy=ALWAYS; authMethod=TEAMCITY_SSH_KEY; branch=refs/heads/master; ignoreKnownHosts=true; submoduleCheckout=CHECKOUT; teamcity:branchSpec=+:refs/heads/*
+:refs/(pull-requests/*)/from
-:refs/heads/release/scrt/r2_2; teamcity:vcsRootName=client-engineering; teamcitySshKey=TeamCity key; url=git:tera/client-engineering.git; useAlternates=true; userForTags=TeamCity Minion <teamcity-minion@teradici.local>; usernameStyle=USERID; vcs=jetbrains.git; ]}; Checkout rules: ]]]
[2016-03-24 09:39:29,213] INFO - jetbrains.buildServer.AGENT - Recording vcs state: revision: fe20f604d9a3c43f7a1351031ad072919a3b6491, VCS root signature: cccc74a29abf45fb, checkout rules: =>
[2016-03-24 09:39:29,213] INFO - jetbrains.buildServer.AGENT - Moved configuration file 1dd3d5f85bbc88f0.xml to old
[2016-03-24 09:39:29,213] INFO - jetbrains.buildServer.AGENT - Stored new configuration file 1dd3d5f85bbc88f0.xml
[2016-03-24 09:39:29,213] INFO - pl.patch.ProjectSourcesOnAgent - Updating sources for root id=4968; name=client-engineering; revision: fe20f604d9a3c43f7a1351031ad072919a3b6491
[2016-03-24 09:39:29,260] INFO - vcs.git.agent.PluginConfigImpl - Use the mirrors option specified in the VCS root
[2016-03-24 09:39:29,260] INFO - cs.git.agent.UpdaterWithMirror - Update local mirror of root client-engineering at D:\system\git\git-FAB7A35C.git
[2016-03-24 09:39:30,589] INFO - cs.git.agent.UpdaterWithMirror - No fetch required for revision 'fe20f604d9a3c43f7a1351031ad072919a3b6491' in local mirror of root client-engineering at D:\system\git\git-FAB7A35C.git
[2016-03-24 09:39:30,620] INFO - gers.vcs.git.agent.UpdaterImpl - Starting update of root client-engineering in D:\work\1dd3d5f85bbc88f0 to revision fe20f604d9a3c43f7a1351031ad072919a3b6491
[2016-03-24 09:44:31,914] INFO - jetbrains.buildServer.AGENT - Patch applied for build with id 4435814
[2016-03-24 09:44:31,914] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir 1dd3d5f85bbc88f0 for build 4435814 clean
[2016-03-24 09:44:31,914] INFO - jetbrains.buildServer.AGENT - newConfigurationFile.exists(): true, newConfigurationFile.renameTo(currentConfigurationFile): true
[2016-03-24 09:44:31,914] INFO - l.patch.UpdateSourcesFromAgent - Agent sources updated successfully
[2016-03-24 09:44:31,914] INFO - ch.UpdateSourcesBuildStageBase - Sources updated for 5m:02s
[2016-03-24 09:44:31,914] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ResetAgentDirectoryDirtyState
[2016-03-24 09:44:31,930] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 129.1 GB, required 18 GB.
[2016-03-24 09:44:31,930] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.AppendBuildParametersFromFileStage
[2016-03-24 09:44:31,930] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReplaceReferencesInArtifactDependenciesStage
[2016-03-24 09:44:31,930] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage
[2016-03-24 09:44:31,930] INFO - jetbrains.buildServer.AGENT - Resolving artifact dependencies...
[2016-03-24 09:44:31,930] INFO - jetbrains.buildServer.AGENT - Started downloading files from <Teradici Client Engineering :: Desktop Client Builds :: Client Binaries :: Client Binaries - Get Virtual Channel Plugins, build #fe20f604d9a3c43f7a1351031ad072919a3b6491 [id 4433740]>
[2016-03-24 09:44:32,725] INFO - jetbrains.buildServer.AGENT - 17 files retrieved from <Teradici Client Engineering :: Desktop Client Builds :: Client Binaries :: Client Binaries - Get Virtual Channel Plugins, build #fe20f604d9a3c43f7a1351031ad072919a3b6491 [id 4433740]> for pattern [vchan.zip!**=>product]
[2016-03-24 09:44:32,725] INFO - jetbrains.buildServer.AGENT - Finished resolving artifacts
[2016-03-24 09:44:32,741] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 129.04 GB, required 18 GB.
[2016-03-24 09:44:32,741] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReportPreparationEndStage
[2016-03-24 09:44:32,741] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.BuildRunTimeoutTimer
[2016-03-24 09:44:32,741] INFO - gent.impl.BuildRunTimeoutTimer - Build execution timeout is set to: 720 minutes
[2016-03-24 09:44:32,741] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.steps.ForEachBuildRunnerStage
[2016-03-24 09:44:32,741] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build runner context id=4435814 runner 1 of 2: startup date [Thu Mar 24 09:44:32 PDT 2016]; parent: SubContext: running build context id=4435814
[2016-03-24 09:44:32,850] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CreateBuildWorkingDirectoryStage
[2016-03-24 09:44:32,866] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 09:44:32,866] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 09:44:32,866] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 09:44:32,866] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.RegisterPerBuildFileWriterPropertiesRunnerStage
[2016-03-24 09:44:32,866] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.FireBeforeRunnerStartedStage
[2016-03-24 09:44:32,881] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallBuildRunnerPrecondition
[2016-03-24 09:44:32,881] INFO - rt.CallBuildRunnerPrecondition - Call BuildRunnerPrecondition: class jetbrains.buildServer.agent.feature.RubyEnvConfiguratorService
[2016-03-24 09:44:32,881] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PerformFinalParametersResolveStage
[2016-03-24 09:44:32,881] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.SavePropertiesToFilesStage
[2016-03-24 09:44:32,944] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallRunnerStage
[2016-03-24 09:44:32,944] INFO - .impl.runner.CallRunnerService - Found runner python for 4435814
[2016-03-24 09:44:32,944] INFO - erStages.start.CallRunnerStage - Found runner python for 4435814
[2016-03-24 09:44:32,944] INFO - erStages.start.CallRunnerStage - Start build runner for build 4435814 python
[2016-03-24 09:44:32,944] INFO - erStages.start.CallRunnerStage - ----------------------------------------- [ Build Agent Testing::Client Binaries - Build - Windows - Release 32-bit #fe20f604d9a3c43f7a1351031ad072919a3b6491 (buildId = 4435814) ] -----------------------------------------
[2016-03-24 09:44:32,944] INFO - nner2.OsProcessHandlerListener - C:\Python27\python.exe .script.py
[2016-03-24 09:54:41,931] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.UnsubscribePropertiesFileUpdaterRunnedFStage
[2016-03-24 09:54:41,931] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FlushBuildLogRunnerFStage
[2016-03-24 09:54:41,978] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FireRunnerFinishedFStage
[2016-03-24 09:54:41,994] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build runner context id=4435814 runner 1 of 2: startup date [Thu Mar 24 09:44:32 PDT 2016]; parent: SubContext: running build context id=4435814
[2016-03-24 09:54:41,994] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build runner context id=4435814 runner 2 of 2: startup date [Thu Mar 24 09:54:41 PDT 2016]; parent: SubContext: running build context id=4435814
[2016-03-24 09:54:42,150] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CreateBuildWorkingDirectoryStage
[2016-03-24 09:54:42,165] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 09:54:42,165] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 09:54:42,165] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 09:54:42,181] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.RegisterPerBuildFileWriterPropertiesRunnerStage
[2016-03-24 09:54:42,181] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.FireBeforeRunnerStartedStage
[2016-03-24 09:54:42,212] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallBuildRunnerPrecondition
[2016-03-24 09:54:42,212] INFO - rt.CallBuildRunnerPrecondition - Call BuildRunnerPrecondition: class jetbrains.buildServer.agent.feature.RubyEnvConfiguratorService
[2016-03-24 09:54:42,212] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PerformFinalParametersResolveStage
[2016-03-24 09:54:42,212] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.SavePropertiesToFilesStage
[2016-03-24 09:54:42,243] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallRunnerStage
[2016-03-24 09:54:42,243] INFO - .impl.runner.CallRunnerService - Found runner python for 4435814
[2016-03-24 09:54:42,243] INFO - erStages.start.CallRunnerStage - Found runner python for 4435814
[2016-03-24 09:54:42,243] INFO - erStages.start.CallRunnerStage - Start build runner for build 4435814 python
[2016-03-24 09:54:42,243] INFO - erStages.start.CallRunnerStage - ----------------------------------------- [ Build Agent Testing::Client Binaries - Build - Windows - Release 32-bit #0.0.0_master@38676-fe20f60 (buildId = 4435814) ] -----------------------------------------
[2016-03-24 09:54:42,243] INFO - nner2.OsProcessHandlerListener - C:\Python27\python.exe .script.py
[2016-03-24 09:54:42,303] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.AgentBuildStepStatusFixer
[2016-03-24 09:54:42,303] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.UnsubscribePropertiesFileUpdaterRunnedFStage
[2016-03-24 09:54:42,303] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FlushBuildLogRunnerFStage
[2016-03-24 09:54:42,335] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FireRunnerFinishedFStage
[2016-03-24 09:54:42,335] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build runner context id=4435814 runner 2 of 2: startup date [Thu Mar 24 09:54:41 PDT 2016]; parent: SubContext: running build context id=4435814
[2016-03-24 09:54:42,335] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FlushBuildLogFStage
[2016-03-24 09:54:42,350] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireBeforeBuildFinishFStage
[2016-03-24 09:54:42,366] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.PublishBuildPropertiesFStage
[2016-03-24 09:54:42,413] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 09:54:42,413] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [D:\temp\agentTmp\build.finish.properties.gz=>.teamcity/properties]
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:54:42,428] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.PublishArtifactsFStage
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [teamcity-info.xml]
[2016-03-24 09:54:42,428] INFO - jetbrains.buildServer.AGENT - Internal artifact path teamcity-info.xml not found
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [0] files
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:54:42,428] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:54:42,428] INFO - jetbrains.buildServer.AGENT - Publishing artifacts process started
[2016-03-24 09:54:42,428] INFO - jetbrains.buildServer.AGENT - Start: Searching for artifacts to publish in [.\product => artifacts.zip;_tempInstallerWorkingdir/PCoIP_Client_installer.exe]
[2016-03-24 09:54:42,428] INFO - jetbrains.buildServer.AGENT - Done: Searching for artifacts to publish, found [229] files
[2016-03-24 09:54:42,428] INFO - jetbrains.buildServer.AGENT - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:54:42,803] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2016-03-24 09:54:42,818] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:54:42,959] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.finish.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2016-03-24 09:54:42,959] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.finish.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:54:42,959] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2016-03-24 09:54:42,990] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 09:54:43,037] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 09:54:44,394] INFO - jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='tc-w2k8-agent34', AgentId=1628, BuildId=4435814, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='8UC2rCMY56DWikwX7syOD56mBjVCSiz8'}
[2016-03-24 09:55:10,759] INFO - jetbrains.buildServer.AGENT - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 09:55:10,759] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.WaitForArtifactsPublishedFStage
[2016-03-24 09:55:10,775] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using WebPublisher
[2016-03-24 09:55:10,790] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:55:29,823] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [_tempInstallerWorkingdir/PCoIP_Client_installer.exe] using 'WebPublisher', total files published: 1
[2016-03-24 09:55:29,823] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [_tempInstallerWorkingdir/PCoIP_Client_installer.exe] using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:55:29,823] INFO - jetbrains.buildServer.AGENT - Done: Publishing files
[2016-03-24 09:55:29,823] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using WebPublisher
[2016-03-24 09:55:29,839] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 09:57:13,319] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [product] to [artifacts.zip], using 'WebPublisher', total files published: 1
[2016-03-24 09:57:13,319] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [product] to [artifacts.zip], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 09:57:13,319] INFO - jetbrains.buildServer.AGENT - Done: Publishing files
[2016-03-24 09:57:13,319] INFO - jetbrains.buildServer.AGENT - Publishing artifacts process finished
[2016-03-24 09:57:13,335] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.RevertPersonalChangesFStage
[2016-03-24 09:57:13,335] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireAfterArtifactsPublishedFStage
[2016-03-24 09:57:13,335] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.SendBuildInterruptedIfNeededFStage
[2016-03-24 09:57:13,335] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FinishBuildOnAgentFStage
[2016-03-24 09:57:13,335] INFO - jetbrains.buildServer.AGENT - Build finished, build id 4435814
[2016-03-24 09:57:13,366] INFO - nt.impl.BuildRunAgentStateImpl - Disposing build context
[2016-03-24 09:57:13,366] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build context id=4435814: startup date [Thu Mar 24 09:39:28 PDT 2016]; parent: jetbrains.buildServer.agent.AgentMain2$2@1c79255
[2016-03-24 09:57:13,366] INFO - ent.impl.BuildAgentStateHolder - Build data was released for buildId= 4435814
[2016-03-24 09:57:13,366] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireBuildFinishedFStage
[2016-03-24 09:57:13,366] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.RegisterPropertiesFileNamesFStage
[2016-03-24 09:57:13,881] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 09:57:13,881] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 09:57:13,881] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 09:57:13,881] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 09:57:13,928] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 09:57:13,928] INFO - dDirectoryBasedCleanupRegistry - Start deleting files from D:\temp\.old
[2016-03-24 09:57:13,990] INFO - dDirectoryBasedCleanupRegistry - Stop deleting files from D:\temp\.old. 0 file(s) were deleted.
[2016-03-24 10:02:13,900] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:02:13,900] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:02:13,900] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:02:13,900] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:02:13,947] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:07:13,911] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:07:13,911] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:07:13,911] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:07:13,911] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:07:13,958] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:12:13,911] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:12:13,911] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:12:13,911] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:12:13,911] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:12:14,035] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:17:13,930] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:17:13,930] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:17:13,930] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:17:13,930] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:17:13,976] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:17:55,568] INFO - jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='tc-w2k8-agent34', AgentId=1628, BuildId=null, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='8UC2rCMY56DWikwX7syOD56mBjVCSiz8'}
[2016-03-24 10:22:13,949] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:22:13,949] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:22:13,949] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:22:13,949] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:22:13,995] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:27:13,968] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:27:13,968] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:27:13,968] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:27:13,968] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:27:13,999] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:29:17,651] INFO - jetbrains.buildServer.AGENT - Received stop command from launcher
[2016-03-24 10:29:17,651] INFO - jetbrains.buildServer.AGENT - Stop command was not performed. No build to stop with reason: BuildInterruptReason.AGENT_SHUTDOWN
[2016-03-24 10:29:17,651] INFO - jetbrains.buildServer.AGENT - Starting agent shutdown sequence, reason: Stop command called
[2016-03-24 10:29:17,651] INFO - agent.impl.AgentPortFileWriter - Delete agent runtime file from C:\BuildAgent\logs\buildAgent.xmlRpcPort
[2016-03-24 10:29:46,044] INFO - jetbrains.buildServer.AGENT - Unregistering from the server. Agent id: 1628
[2016-03-24 10:29:46,060] INFO - jetbrains.buildServer.AGENT - Shutdown agent WebServer start
[2016-03-24 10:29:46,060] INFO - jetbrains.buildServer.AGENT - Shutdown agent WebServer finish
[2016-03-24 10:29:46,060] INFO - jetbrains.buildServer.AGENT - Shutdown agent finish
[2016-03-24 10:29:46,060] INFO - jetbrains.buildServer.AGENT - Shutdown agent agent and exit with code DIE_USER_COMMAND
[2016-03-24 10:29:46,060] INFO - ent.impl.upgrade.AgentExitCode - Agent exited. Stop command called

0

Run as console log:

[2016-03-24 10:29:53,414] INFO - s.buildServer.agent.AgentMain2 - Agent home is C:\BuildAgent
[2016-03-24 10:29:53,460] INFO - jetbrains.buildServer.SERVER - Starting TeamCity agent
[2016-03-24 10:29:53,460] INFO - s.buildServer.agent.AgentMain2 -

 

 


[2016-03-24 10:29:53,460] INFO - s.buildServer.agent.AgentMain2 - ===========================================================
[2016-03-24 10:29:53,476] INFO - s.buildServer.agent.AgentMain2 - TeamCity Build Agent 9.1.1 (build 37059), OS: Windows Server 2008 R2, User: ajinks, JRE: 1.8.0_45-b15 Java HotSpot(TM) Client VM (32 bit), JVM parameters: -ea -Xmx512m -XX:+HeapDumpOnOutOfMemoryError -Xrs -Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml -Dteamcity_logs=../logs/
[2016-03-24 10:29:53,476] INFO - s.buildServer.agent.AgentMain2 - Starting...
[2016-03-24 10:29:53,554] INFO - buildServer.agent.AgentMain2$2 - Refreshing jetbrains.buildServer.agent.AgentMain2$2@1c79255: startup date [Thu Mar 24 10:29:53 PDT 2016]; root of context hierarchy
[2016-03-24 10:29:54,553] INFO - jetbrains.buildServer.AGENT - Calculating CPU benchmark index...
[2016-03-24 10:30:00,231] INFO - jetbrains.buildServer.AGENT - CPU benchmark index is set to 559
[2016-03-24 10:30:00,372] INFO - dAgentConfigurationInitializer - Loading build agent configuration from ..\conf\buildAgent.properties
[2016-03-24 10:30:00,450] INFO - s.buildServer.agent.AgentMain2 - Working dir: D:\work
[2016-03-24 10:30:00,450] INFO - s.buildServer.agent.AgentMain2 - Temp dir: D:\temp
[2016-03-24 10:30:00,450] INFO - rver.plugins.PluginManagerImpl - ===========================================================
[2016-03-24 10:30:00,450] INFO - rver.plugins.PluginManagerImpl - Plugins initialization started...
[2016-03-24 10:30:00,450] INFO - rver.plugins.PluginManagerImpl - Scanning plugins folders
[2016-03-24 10:30:00,450] INFO - .plugins.files.JarSearcherBase - Scanning plugin folder: C:\BuildAgent\plugins
[2016-03-24 10:30:00,528] INFO - .plugins.files.JarSearcherBase - Scanning plugin folder: C:\BuildAgent\tools
[2016-03-24 10:30:00,559] INFO - rver.plugins.PluginManagerImpl - Found 62 plugins: [agentSystemInfo, amazonEC2, ant, ant-net-tasks, antPlugin, assembly-info-patcher, atfRunner, clearcase-agent, cmake-runner, commandLineRunner, coveragePlugin, crashDetector, cvsAgent, dotCover, dotnet-tools, dotnetPlugin, dotNetRunners, duplicatePlugin, environment-fetcher, file-content-replacer, fxcop, gant, gantPlugin, gradle-runner, idea, idea-runner, inspectionPlugin, ipr-runner, jacoco, java-dowser, jetbrains.git, jirareporter, jps, jps-old, junitPlugin, jvm-update, linux-system-properties, maven, maven3, maven3_1, maven3_2, mavenPlugin, mercurial, meta-runner, nuget-agent, perfmon, perforce-agent, powershell-agent, python-agent, rake-runner, remoteAccess, sbt-runner-agent, ssh-manager, stacktracesPlugin, svnAgent, swabra, testNGPlugin, tfs-agent, visualstudiotest, vmware-cloud, xcode-runner, xml-report-plugin]
[2016-03-24 10:30:00,559] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\ant
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\antRun
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\ant.bat
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\ant.cmd
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\antenv.cmd
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\envset.cmd
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\lcp.bat
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\runrc.cmd
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\antRun.pl
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\complete-ant-cmd.pl
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\runant.pl
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\plugins\ant\bin\runant.py
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\tools\maven\bin\mvn
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\tools\gant\bin\gant
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\tools\gant\bin\startGroovy
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\tools\maven3\bin\mvn
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\tools\maven3_1\bin\mvn
[2016-03-24 10:30:00,574] INFO - les.ExecutableAttributesSetter - Setting executable bit for: C:\BuildAgent\tools\maven3_2\bin\mvn
[2016-03-24 10:30:00,574] INFO - rver.plugins.PluginsCollection - Load shared classloader for 33 plugins [agentSystemInfo, amazonEC2, ant, assembly-info-patcher, atfRunner, clearcase-agent, commandLineRunner, crashDetector, cvsAgent, dotnet-tools, dotnetPlugin, dotNetRunners, duplicatePlugin, environment-fetcher, file-content-replacer, fxcop, gradle-runner, inspectionPlugin, java-dowser, jetbrains.git, jirareporter, linux-system-properties, mercurial, perfmon, powershell-agent, python-agent, remoteAccess, ssh-manager, stacktracesPlugin, swabra, tfs-agent, vmware-cloud, xml-report-plugin]
[2016-03-24 10:30:00,606] INFO - rver.plugins.PluginsCollection - Load standalone classloaders for 18 plugins [antPlugin, cmake-runner, coveragePlugin, gantPlugin, idea-runner, ipr-runner, junitPlugin, jvm-update, mavenPlugin, meta-runner, nuget-agent, perforce-agent, rake-runner, sbt-runner-agent, svnAgent, testNGPlugin, visualstudiotest, xcode-runner]
[2016-03-24 10:30:02,493] INFO - IN.linuxSystemProperties.AGENT - Initializing linux-system-properties agent extension.
[2016-03-24 10:30:03,164] INFO - .vmware.VMWarePropertiesReader - VSphere plugin initializing...
[2016-03-24 10:30:03,336] INFO - rver.plugins.PluginManagerImpl - Plugins initialization completed:
[2016-03-24 10:30:03,336] INFO - rver.plugins.PluginManagerImpl - Loaded 62 plugins: [agentSystemInfo, amazonEC2, ant, ant-net-tasks, antPlugin, assembly-info-patcher, atfRunner, clearcase-agent, cmake-runner, commandLineRunner, coveragePlugin, crashDetector, cvsAgent, dotCover, dotnet-tools, dotnetPlugin, dotNetRunners, duplicatePlugin, environment-fetcher, file-content-replacer, fxcop, gant, gantPlugin, gradle-runner, idea, idea-runner, inspectionPlugin, ipr-runner, jacoco, java-dowser, jetbrains.git, jirareporter, jps, jps-old, junitPlugin, jvm-update, linux-system-properties, maven, maven3, maven3_1, maven3_2, mavenPlugin, mercurial, meta-runner, nuget-agent, perfmon, perforce-agent, powershell-agent, python-agent, rake-runner, remoteAccess, sbt-runner-agent, ssh-manager, stacktracesPlugin, svnAgent, swabra, testNGPlugin, tfs-agent, visualstudiotest, vmware-cloud, xcode-runner, xml-report-plugin]
[2016-03-24 10:30:03,336] INFO - rver.plugins.PluginManagerImpl - ===========================================================
[2016-03-24 10:30:03,367] INFO - jetbrains.buildServer.AGENT - Build Agent version: 37059, plugins signature: 37059-md5-e18d2fe6d01814004a2955b4362d08af
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 2.0(2.0.50727) x32 at C:\Windows\Microsoft.NET\Framework\v2.0.50727
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 3.0(3.0.30729.5420) x32 at C:\Windows\Microsoft.NET\Framework\v3.0
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 3.5(3.5.30729.5420) x32 at C:\Windows\Microsoft.NET\Framework\v3.5
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 4.0(4.0.30319) x32 at C:\Windows\Microsoft.NET\Framework\v4.0.30319
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 4.5(4.5.50938) x32 at C:\Windows\Microsoft.NET\Framework\v4.0.30319
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 2.0(2.0.50727) x64 at C:\Windows\Microsoft.NET\Framework64\v2.0.50727
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 3.0(3.0.30729.5420) x64 at C:\Windows\Microsoft.NET\Framework64\v3.0
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 3.5(3.5.30729.5420) x64 at C:\Windows\Microsoft.NET\Framework64\v3.5
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 4.0(4.0.30319) x64 at C:\Windows\Microsoft.NET\Framework64\v4.0.30319
[2016-03-24 10:30:04,506] INFO - etFrameworkPropertiesExtension - Found .Net Framework 4.5(4.5.50938) x64 at C:\Windows\Microsoft.NET\Framework64\v4.0.30319
[2016-03-24 10:30:04,599] INFO - gent.detect.PowerShellDetector - Found: PowerShell v3.0 x86(C:\Windows\SysWOW64\WindowsPowerShell\v1.0)
[2016-03-24 10:30:04,693] INFO - gent.detect.PowerShellDetector - Found: PowerShell v3.0 x64(C:\Windows\System32\WindowsPowerShell\v1.0)
[2016-03-24 10:30:05,432] INFO - javaDowser.JavaDowserAgentImpl - JavaDowser: Found 2 java installations:
1.8/32 (1.8.0_73) at C:\Program Files (x86)\Java\jre1.8.0_73 (JRE) [200]
1.8/64 (1.8.0_73) at C:\Program Files\Java\jre1.8.0_73 (JRE) [300]
[2016-03-24 10:30:05,432] INFO - IN.linuxSystemProperties.AGENT - Loading additional system properties.
[2016-03-24 10:30:05,744] INFO - ggers.vcs.mercurial.HgDetector - Cannot detect installed mercurial
[2016-03-24 10:30:05,744] INFO - dAgentConfigurationInitializer - Loading build agent configuration from ..\conf\buildAgent.properties
[2016-03-24 10:30:05,791] INFO - r.mono.MonoPropertiesExtension - HKLM\SOFTWARE\Novell\Mono\DefaultCLR wasn't found => no mono
[2016-03-24 10:30:05,838] INFO - .agent.AgentStartupGitDetector - Detect git at C:\Program Files (x86)\Git\bin\git.exe
[2016-03-24 10:30:12,858] INFO - t.AmazonInstanceMetadataReader - Amazon is not available. Amazon EC2 integration is not active: Failed to connect to http://169.254.169.254/2009-04-04. The host did not accept the connection within timeout of 7000 ms
[2016-03-24 10:30:12,858] INFO - .agent.AmazonPropertiesUpdater - Fetched AmazonEC2 instance metadata:
[2016-03-24 10:30:12,858] INFO - zon.agent.AmazonMetadataChecks - Amazon EC instance metadata contains no keys
[2016-03-24 10:30:12,858] WARN - .agent.AmazonPropertiesUpdater - Fetched Amazon EC2 instance metadata does not contain required values. Probably this agent was not started inside Amazon EC2. Is proxy server used?
[2016-03-24 10:30:12,858] INFO - .vmware.VMWarePropertiesReader - VMWare tools installed. Will attempt to authorize agent as VMWare cloud agent
[2016-03-24 10:30:12,858] INFO - .vmware.VMWarePropertiesReader - [C:\Program Files\VMware\VMware Tools\rpctool.exe, info-get guestinfo.tcServerUrl]
[2016-03-24 10:30:12,889] INFO - .vmware.VMWarePropertiesReader - Unable to read property guestinfo.tcServerUrl. VMWare integration is disabled
[2016-03-24 10:30:12,921] INFO - cher.DotNetPropertiesExtension - Start Microsoft .NET Framework SDK Search
[2016-03-24 10:30:12,983] INFO - cher.DotNetPropertiesExtension - Finished Microsoft .NET Framework SDK Search
[2016-03-24 10:30:12,983] INFO - cher.DotNetPropertiesExtension - Start Microsoft Visual Studio Search
[2016-03-24 10:30:13,202] INFO - cher.DotNetPropertiesExtension - Found Microsoft Visual Studio 2013 at C:\Program Files (x86)\Microsoft Visual Studio 12.0\Common7\IDE
[2016-03-24 10:30:13,202] INFO - cher.DotNetPropertiesExtension - Found Microsoft Visual Studio 2008 at C:\Program Files (x86)\Microsoft Visual Studio 9.0\Common7\IDE
[2016-03-24 10:30:13,202] INFO - cher.DotNetPropertiesExtension - Finished Microsoft Visual Studio Search
[2016-03-24 10:30:13,202] INFO - cher.DotNetPropertiesExtension - Start Microsoft Windows SDK Search
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Windows SDK v6.0A
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Microsoft .NET Framework SDK v2.0
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Windows SDK v7.1A
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Windows SDK v8.0
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Windows SDK v8.0A
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Windows SDK v8.1
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Found Windows SDK v8.1A
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Finished Microsoft Windows SDK Search
[2016-03-24 10:30:14,403] INFO - cher.DotNetPropertiesExtension - Start MSBuild Search
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 12.0 (x86) at C:\Program Files (x86)\MSBuild\12.0\bin
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 2.0 (x86) at C:\Windows\Microsoft.NET\Framework\v2.0.50727
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 3.5 (x86) at C:\Windows\Microsoft.NET\Framework\v3.5
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 4.0 (x86) at C:\Windows\Microsoft.NET\Framework\v4.0.30319
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 12.0 (x64) at C:\Program Files (x86)\MSBuild\12.0\bin\amd64
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 2.0 (x64) at C:\Windows\Microsoft.NET\Framework64\v2.0.50727
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 3.5 (x64) at C:\Windows\Microsoft.NET\Framework64\v3.5
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Found MSBuild Toolset 4.0 (x64) at C:\Windows\Microsoft.NET\Framework64\v4.0.30319
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Finished MSBuild Search
[2016-03-24 10:30:14,715] INFO - cher.DotNetPropertiesExtension - Start MSTest Searcher
[2016-03-24 10:30:15,276] INFO - cher.DotNetPropertiesExtension - Found MSTest 12.0
[2016-03-24 10:30:15,276] INFO - cher.DotNetPropertiesExtension - Finished MSTest Searcher
[2016-03-24 10:30:15,276] INFO - cher.DotNetPropertiesExtension - Start VSTest.Console Searcher
[2016-03-24 10:30:15,370] INFO - cher.DotNetPropertiesExtension - Found VSTest 2013 at C:\Program Files (x86)\Microsoft Visual Studio 12.0\Common7\IDE\CommonExtensions\Microsoft\TestWindow
[2016-03-24 10:30:15,370] INFO - cher.DotNetPropertiesExtension - Finished VSTest.Console Searcher
[2016-03-24 10:30:15,401] INFO - rver.fxcop.agent.FxCopSearcher - .fxcop file association wasn't found in CLASSES_ROOT
[2016-03-24 10:30:15,401] INFO - rver.fxcop.agent.FxCopSearcher - VS2015_Path configuration parameter was not found
[2016-03-24 10:30:15,401] INFO - rver.fxcop.agent.FxCopSearcher - FxCopCmd.exe found at path "C:\Program Files (x86)\Microsoft Visual Studio 12.0\Common7\IDE\..\..\Team Tools\Static Analysis Tools\FxCop\FxCopCmd.exe"
[2016-03-24 10:30:15,401] INFO - rver.fxcop.agent.FxCopSearcher - Found FxCopCmd file version: 12.0.21005.1
[2016-03-24 10:30:15,401] INFO - jetbrains.buildServer.AGENT - Start build agent
[2016-03-24 10:30:15,432] INFO - jetbrains.buildServer.AGENT - Agent Web server started on port 9090
[2016-03-24 10:30:15,432] INFO - agent.impl.AgentDetailsFactory - Build agent ownAddress will be defined by the server. Define 'ownAddress' property in the conf/buildAgent.properties file
[2016-03-24 10:30:15,573] INFO - agent.impl.AgentPortFileWriter - Writing agent runtime file to C:\BuildAgent\logs\buildAgent.xmlRpcPort
[2016-03-24 10:30:15,573] INFO - agent.impl.AgentPortFileWriter - Launcher version is 37059
[2016-03-24 10:30:15,573] INFO - agent.impl.AgentPortFileWriter - Writing agent runtime file to C:\BuildAgent\logs\buildAgent.xmlRpcPort :DONE!
[2016-03-24 10:30:15,588] INFO - jetbrains.buildServer.AGENT - Build agent started
[2016-03-24 10:30:15,698] INFO - vcs.tfs.SimpleTfsProcessRunner - TFS command finished. command: C:\BuildAgent\plugins\tfs-agent\bin\tfs-native.exe @@D:\temp\globalTmp\TC-TFS-9-615_1\command.params, in file: {/CheckApi}, completed in: 0 second(s)
stdout: TFS Native Verifier v10.0 Copyright (C) 2006-2013 JetBrains s.r.o.
Running under .NET Framework 4.0.30319.18444
INFO -
INFO - Use Team Explorer 2013
INFO -
INFO - Tfs API available.
TfsVersion=12.0
[2016-03-24 10:30:15,713] INFO - se.agent.ClearCaseAgentSupport - ClearCase agent checkout is disabled: Could not find executable: 'cleartool'. Original message: Cannot run program "cleartool" (in directory "."): CreateProcess error=2, The system cannot find the file specified
[2016-03-24 10:30:15,713] INFO - buildServer.AGENT.registration - Registering on server https://teamcity.teradici.com, AgentDetails{Name='tc-w2k8-agent34', AgentId=null, BuildId=null, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='e3DBr59HrLF6hUXJaL5i2w3Zeah6uTtW'}
[2016-03-24 10:30:15,729] INFO - buildServer.AGENT.registration - Using communication protocols from the Agent's internal property: [polling]
[2016-03-24 10:30:15,729] INFO - buildServer.AGENT.registration - Trying to register using 'polling' protocol.
[2016-03-24 10:30:15,947] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:30:15,978] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 65 items removed
[2016-03-24 10:30:15,994] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:30:15,994] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:30:16,025] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:30:16,540] INFO - ldServer.AGENT.PollingProtocol - Start polling server for commands
[2016-03-24 10:30:16,540] INFO - buildServer.AGENT.registration - Registered: id:1628, authorizationToken:0b8ca15208e5bb73204662667f39ee30
[2016-03-24 10:30:16,540] INFO - buildServer.AGENT.registration - If this is the first time this agent registered on the server make sure it is authorized by administrator in the server web UI.
[2016-03-24 10:30:18,615] INFO - jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='tc-w2k8-agent34', AgentId=1628, BuildId=null, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='e3DBr59HrLF6hUXJaL5i2w3Zeah6uTtW'}
[2016-03-24 10:30:33,810] INFO - ldServer.AGENT.PollingProtocol - New command is received from server "runBuild" {id = 1}
[2016-03-24 10:30:33,857] INFO - jetbrains.buildServer.AGENT -



[2016-03-24 10:30:33,857] INFO - jetbrains.buildServer.AGENT - ===================================================
[2016-03-24 10:30:33,857] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 4436035, buildTypeId=bt112952
[2016-03-24 10:30:33,857] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build context id=4436035: startup date [Thu Mar 24 10:30:33 PDT 2016]; parent: jetbrains.buildServer.agent.AgentMain2$2@1c79255
[2016-03-24 10:30:34,216] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2016-03-24 10:30:34,231] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2016-03-24 10:30:34,231] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:30:34,341] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2016-03-24 10:30:34,356] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2016-03-24 10:30:34,372] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2016-03-24 10:30:34,434] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2016-03-24 10:30:34,497] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2016-03-24 10:30:34,497] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2016-03-24 10:30:34,497] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: D:\temp\buildTmp
[2016-03-24 10:30:34,497] INFO - rectories.DirectoryCleanerImpl - Move directory D:\temp\buildTmp to D:\temp\.old\buildTmp_0 for cleaning
[2016-03-24 10:30:34,512] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 127.96 GB, required 18 GB.
[2016-03-24 10:30:34,512] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 10:30:34,512] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2016-03-24 10:30:34,590] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 10:30:34,590] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [D:\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2016-03-24 10:30:34,590] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2016-03-24 10:30:34,590] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:30:34,590] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:30:34,590] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 10:30:34,590] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 10:30:34,590] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 127.96 GB, required 18 GB.
[2016-03-24 10:30:34,590] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2016-03-24 10:30:34,606] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2016-03-24 10:30:34,606] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\work\1dd3d5f85bbc88f0
[2016-03-24 10:30:34,606] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromAgent
[2016-03-24 10:30:34,606] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: agent side checkout
[2016-03-24 10:30:34,606] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 4436035
[2016-03-24 10:30:34,621] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 10:30:34,637] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2016-03-24 10:30:34,653] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 10:30:34,949] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2016-03-24 10:30:34,949] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2016-03-24 10:30:34,980] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 10:30:35,136] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir 1dd3d5f85bbc88f0 for build 4436035 dirty
[2016-03-24 10:30:35,136] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["client-engineering" {internal id=4968, properties: [agentCleanFilesPolicy=ALL_UNTRACKED; agentCleanPolicy=ALWAYS; authMethod=TEAMCITY_SSH_KEY; branch=refs/heads/master; ignoreKnownHosts=true; submoduleCheckout=CHECKOUT; teamcity:branchSpec=+:refs/heads/*
+:refs/(pull-requests/*)/from
-:refs/heads/release/scrt/r2_2; teamcity:vcsRootName=client-engineering; teamcitySshKey=TeamCity key; url=git:tera/client-engineering.git; useAlternates=true; userForTags=TeamCity Minion <teamcity-minion@teradici.local>; usernameStyle=USERID; vcs=jetbrains.git; ]}; Checkout rules: ]]]
[2016-03-24 10:30:35,136] INFO - jetbrains.buildServer.AGENT - Recording vcs state: revision: fe20f604d9a3c43f7a1351031ad072919a3b6491, VCS root signature: cccc74a29abf45fb, checkout rules: =>
[2016-03-24 10:30:35,136] INFO - jetbrains.buildServer.AGENT - Moved configuration file 1dd3d5f85bbc88f0.xml to old
[2016-03-24 10:30:35,136] INFO - jetbrains.buildServer.AGENT - Stored new configuration file 1dd3d5f85bbc88f0.xml
[2016-03-24 10:30:35,136] INFO - pl.patch.ProjectSourcesOnAgent - Updating sources for root id=4968; name=client-engineering; revision: fe20f604d9a3c43f7a1351031ad072919a3b6491
[2016-03-24 10:30:35,167] INFO - vcs.git.agent.PluginConfigImpl - Use the mirrors option specified in the VCS root
[2016-03-24 10:30:35,183] INFO - cs.git.agent.UpdaterWithMirror - Update local mirror of root client-engineering at D:\system\git\git-FAB7A35C.git
[2016-03-24 10:30:36,590] INFO - cs.git.agent.UpdaterWithMirror - No fetch required for revision 'fe20f604d9a3c43f7a1351031ad072919a3b6491' in local mirror of root client-engineering at D:\system\git\git-FAB7A35C.git
[2016-03-24 10:30:36,621] INFO - gers.vcs.git.agent.UpdaterImpl - Starting update of root client-engineering in D:\work\1dd3d5f85bbc88f0 to revision fe20f604d9a3c43f7a1351031ad072919a3b6491
[2016-03-24 10:31:58,965] INFO - jetbrains.buildServer.AGENT - Patch applied for build with id 4436035
[2016-03-24 10:31:58,965] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir 1dd3d5f85bbc88f0 for build 4436035 clean
[2016-03-24 10:31:58,965] INFO - jetbrains.buildServer.AGENT - newConfigurationFile.exists(): true, newConfigurationFile.renameTo(currentConfigurationFile): true
[2016-03-24 10:31:58,965] INFO - l.patch.UpdateSourcesFromAgent - Agent sources updated successfully
[2016-03-24 10:31:58,965] INFO - ch.UpdateSourcesBuildStageBase - Sources updated for 1m:24s
[2016-03-24 10:31:58,965] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ResetAgentDirectoryDirtyState
[2016-03-24 10:31:58,981] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 129.08 GB, required 18 GB.
[2016-03-24 10:31:58,981] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.AppendBuildParametersFromFileStage
[2016-03-24 10:31:58,981] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReplaceReferencesInArtifactDependenciesStage
[2016-03-24 10:31:58,981] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage
[2016-03-24 10:31:58,997] INFO - jetbrains.buildServer.AGENT - Resolving artifact dependencies...
[2016-03-24 10:31:58,997] INFO - jetbrains.buildServer.AGENT - Started downloading files from <Teradici Client Engineering :: Desktop Client Builds :: Client Binaries :: Client Binaries - Get Virtual Channel Plugins, build #fe20f604d9a3c43f7a1351031ad072919a3b6491 [id 4433740]>
[2016-03-24 10:31:59,933] INFO - jetbrains.buildServer.AGENT - 17 files retrieved from <Teradici Client Engineering :: Desktop Client Builds :: Client Binaries :: Client Binaries - Get Virtual Channel Plugins, build #fe20f604d9a3c43f7a1351031ad072919a3b6491 [id 4433740]> for pattern [vchan.zip!**=>product]
[2016-03-24 10:31:59,933] INFO - jetbrains.buildServer.AGENT - Finished resolving artifacts
[2016-03-24 10:31:59,948] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\work\1dd3d5f85bbc88f0 is 129.01 GB, required 18 GB.
[2016-03-24 10:31:59,948] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReportPreparationEndStage
[2016-03-24 10:31:59,948] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.BuildRunTimeoutTimer
[2016-03-24 10:31:59,948] INFO - gent.impl.BuildRunTimeoutTimer - Build execution timeout is set to: 720 minutes
[2016-03-24 10:31:59,948] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.steps.ForEachBuildRunnerStage
[2016-03-24 10:31:59,948] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build runner context id=4436035 runner 1 of 2: startup date [Thu Mar 24 10:31:59 PDT 2016]; parent: SubContext: running build context id=4436035
[2016-03-24 10:32:00,057] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CreateBuildWorkingDirectoryStage
[2016-03-24 10:32:00,073] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 10:32:00,073] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 10:32:00,089] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 10:32:00,089] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.RegisterPerBuildFileWriterPropertiesRunnerStage
[2016-03-24 10:32:00,089] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.FireBeforeRunnerStartedStage
[2016-03-24 10:32:00,104] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallBuildRunnerPrecondition
[2016-03-24 10:32:00,104] INFO - rt.CallBuildRunnerPrecondition - Call BuildRunnerPrecondition: class jetbrains.buildServer.agent.feature.RubyEnvConfiguratorService
[2016-03-24 10:32:00,104] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PerformFinalParametersResolveStage
[2016-03-24 10:32:00,104] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.SavePropertiesToFilesStage
[2016-03-24 10:32:00,213] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallRunnerStage
[2016-03-24 10:32:00,213] INFO - .impl.runner.CallRunnerService - Found runner python for 4436035
[2016-03-24 10:32:00,213] INFO - erStages.start.CallRunnerStage - Found runner python for 4436035
[2016-03-24 10:32:00,213] INFO - erStages.start.CallRunnerStage - Start build runner for build 4436035 python
[2016-03-24 10:32:00,213] INFO - erStages.start.CallRunnerStage - ----------------------------------------- [ Build Agent Testing::Client Binaries - Build - Windows - Release 32-bit #fe20f604d9a3c43f7a1351031ad072919a3b6491 (buildId = 4436035) ] -----------------------------------------
[2016-03-24 10:32:00,245] INFO - nner2.OsProcessHandlerListener - C:\Python27\python.exe .script.py
[2016-03-24 10:42:54,019] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.UnsubscribePropertiesFileUpdaterRunnedFStage
[2016-03-24 10:42:54,019] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FlushBuildLogRunnerFStage
[2016-03-24 10:42:54,268] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FireRunnerFinishedFStage
[2016-03-24 10:42:54,300] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build runner context id=4436035 runner 1 of 2: startup date [Thu Mar 24 10:31:59 PDT 2016]; parent: SubContext: running build context id=4436035
[2016-03-24 10:42:54,300] INFO - mpl$TeamCitySpringSubContainer - Refreshing SubContext: running build runner context id=4436035 runner 2 of 2: startup date [Thu Mar 24 10:42:54 PDT 2016]; parent: SubContext: running build context id=4436035
[2016-03-24 10:42:54,393] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CreateBuildWorkingDirectoryStage
[2016-03-24 10:42:54,409] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2016-03-24 10:42:54,409] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2016-03-24 10:42:54,409] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2016-03-24 10:42:54,409] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.RegisterPerBuildFileWriterPropertiesRunnerStage
[2016-03-24 10:42:54,409] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.FireBeforeRunnerStartedStage
[2016-03-24 10:42:54,424] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallBuildRunnerPrecondition
[2016-03-24 10:42:54,424] INFO - rt.CallBuildRunnerPrecondition - Call BuildRunnerPrecondition: class jetbrains.buildServer.agent.feature.RubyEnvConfiguratorService
[2016-03-24 10:42:54,424] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PerformFinalParametersResolveStage
[2016-03-24 10:42:54,424] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.SavePropertiesToFilesStage
[2016-03-24 10:42:54,456] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.CallRunnerStage
[2016-03-24 10:42:54,456] INFO - .impl.runner.CallRunnerService - Found runner python for 4436035
[2016-03-24 10:42:54,456] INFO - erStages.start.CallRunnerStage - Found runner python for 4436035
[2016-03-24 10:42:54,456] INFO - erStages.start.CallRunnerStage - Start build runner for build 4436035 python
[2016-03-24 10:42:54,456] INFO - erStages.start.CallRunnerStage - ----------------------------------------- [ Build Agent Testing::Client Binaries - Build - Windows - Release 32-bit #0.0.0_master@38676-fe20f60 (buildId = 4436035) ] -----------------------------------------
[2016-03-24 10:42:54,471] INFO - nner2.OsProcessHandlerListener - C:\Python27\python.exe .script.py
[2016-03-24 10:42:54,528] INFO - ildStages.RunnerStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.start.AgentBuildStepStatusFixer
[2016-03-24 10:42:54,528] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.UnsubscribePropertiesFileUpdaterRunnedFStage
[2016-03-24 10:42:54,544] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FlushBuildLogRunnerFStage
[2016-03-24 10:42:54,559] INFO - ges.RunnerFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.runnerStages.finish.FireRunnerFinishedFStage
[2016-03-24 10:42:54,575] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build runner context id=4436035 runner 2 of 2: startup date [Thu Mar 24 10:42:54 PDT 2016]; parent: SubContext: running build context id=4436035
[2016-03-24 10:42:54,575] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FlushBuildLogFStage
[2016-03-24 10:42:54,591] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireBeforeBuildFinishFStage
[2016-03-24 10:42:54,591] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.PublishBuildPropertiesFStage
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [D:\temp\agentTmp\build.finish.properties.gz=>.teamcity/properties]
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:42:54,653] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.PublishArtifactsFStage
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [teamcity-info.xml]
[2016-03-24 10:42:54,653] INFO - jetbrains.buildServer.AGENT - Internal artifact path teamcity-info.xml not found
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [0] files
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:42:54,653] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:42:54,653] INFO - jetbrains.buildServer.AGENT - Publishing artifacts process started
[2016-03-24 10:42:54,653] INFO - jetbrains.buildServer.AGENT - Start: Searching for artifacts to publish in [.\product => artifacts.zip;_tempInstallerWorkingdir/PCoIP_Client_installer.exe]
[2016-03-24 10:42:54,669] WARN - jetbrains.buildServer.AGENT - Artifacts path '_tempInstallerWorkingdir/PCoIP_Client_installer.exe' not found
[2016-03-24 10:42:54,669] INFO - jetbrains.buildServer.AGENT - Done: Searching for artifacts to publish, found [229] files
[2016-03-24 10:42:54,669] INFO - jetbrains.buildServer.AGENT - Start: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:42:56,634] INFO - jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='tc-w2k8-agent34', AgentId=1628, BuildId=4436035, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='e3DBr59HrLF6hUXJaL5i2w3Zeah6uTtW'}
[2016-03-24 10:42:58,959] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 10:42:58,974] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2016-03-24 10:42:58,990] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.finish.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 10:42:59,505] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/temp/agentTmp/build.finish.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2016-03-24 10:42:59,505] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2016-03-24 10:42:59,536] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 10:42:59,583] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2016-03-24 10:43:22,392] INFO - jetbrains.buildServer.AGENT - Done: Pre-processing artifacts if needed (archiving)
[2016-03-24 10:43:22,392] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.WaitForArtifactsPublishedFStage
[2016-03-24 10:43:22,392] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using ArtifactsCachePublisher
[2016-03-24 10:43:22,407] INFO - jetbrains.buildServer.AGENT - Start: Publishing files using WebPublisher
[2016-03-24 10:43:22,563] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [product] to [artifacts.zip], using 'ArtifactsCachePublisher', total files published: 1
[2016-03-24 10:44:41,473] INFO - jetbrains.buildServer.AGENT - Done publishing artifacts from [product] to [artifacts.zip], using 'WebPublisher', total files published: 1
[2016-03-24 10:44:41,473] INFO - jetbrains.buildServer.AGENT - Done: Publishing files
[2016-03-24 10:44:41,473] INFO - jetbrains.buildServer.AGENT - Publishing artifacts process finished
[2016-03-24 10:44:41,489] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.RevertPersonalChangesFStage
[2016-03-24 10:44:41,489] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireAfterArtifactsPublishedFStage
[2016-03-24 10:44:41,489] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.SendBuildInterruptedIfNeededFStage
[2016-03-24 10:44:41,489] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FinishBuildOnAgentFStage
[2016-03-24 10:44:41,489] INFO - jetbrains.buildServer.AGENT - Build finished, build id 4436035
[2016-03-24 10:44:41,520] INFO - nt.impl.BuildRunAgentStateImpl - Disposing build context
[2016-03-24 10:44:41,520] INFO - mpl$TeamCitySpringSubContainer - Closing SubContext: running build context id=4436035: startup date [Thu Mar 24 10:30:33 PDT 2016]; parent: jetbrains.buildServer.agent.AgentMain2$2@1c79255
[2016-03-24 10:44:41,520] INFO - ent.impl.BuildAgentStateHolder - Build data was released for buildId= 4436035
[2016-03-24 10:44:41,520] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.FireBuildFinishedFStage
[2016-03-24 10:44:41,520] INFO - ages.BuildFinishStagesExecutor - Call finish stage jetbrains.buildServer.agent.impl.buildStages.finishStages.RegisterPropertiesFileNamesFStage
[2016-03-24 10:44:42,035] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:44:42,035] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:44:42,035] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:44:42,035] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:44:42,066] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:44:42,066] INFO - dDirectoryBasedCleanupRegistry - Start deleting files from D:\temp\.old
[2016-03-24 10:44:42,113] INFO - dDirectoryBasedCleanupRegistry - Stop deleting files from D:\temp\.old. 0 file(s) were deleted.
[2016-03-24 10:49:42,056] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:49:42,056] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:49:42,056] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:49:42,056] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:49:42,134] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:54:42,059] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:54:42,059] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:54:42,059] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:54:42,059] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:54:42,121] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 10:59:42,078] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 10:59:42,078] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 10:59:42,078] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 10:59:42,078] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 10:59:42,125] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 11:00:05,698] INFO - jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='tc-w2k8-agent34', AgentId=1628, BuildId=null, AgentOwnAddress='null', AlternativeAddresses=[10.0.104.27], Port=9090, Version='37059', PluginsVersion='37059-md5-e18d2fe6d01814004a2955b4362d08af', AvailableRunners=[Ant, atfRunner, dotnet-tools-dupfinder, dotnet-tools-inspectcode, Duplicator, FxCop, gradle-runner, Inspection, Ipr, jb.nuget.installer, jb.nuget.pack, jb.nuget.publish, jetbrains-cmake-build, jetbrains-cmake-conf, jetbrains-cmake-gnumake, jetbrains.dotNetGenericRunner, jetbrains.mspec, jetbrains_powershell, jirareporter, JPS, Maven2, MSBuild, NAnt, NUnit, python, rake-runner, SBT, simpleRunner, sln2003, VisualStudioTest, VS.Solution], AvailableVcs=[tfs, cvs, jetbrains.git, mercurial, svn, perforce], AuthorizationToken='0b8ca15208e5bb73204662667f39ee30', PingCode='e3DBr59HrLF6hUXJaL5i2w3Zeah6uTtW'}
[2016-03-24 11:04:42,091] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 11:04:42,091] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 11:04:42,091] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old
[2016-03-24 11:04:42,091] INFO - l.directories.DirectoryMapImpl - Cleaning up old checkout directories. Default lifetime = 192 hour(s)
[2016-03-24 11:04:42,137] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\temp\.old
[2016-03-24 11:09:42,100] INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds
[2016-03-24 11:09:42,100] INFO - r.artifacts.impl.HttpDiskCache - Finished cleaning up expired items, 0 items removed
[2016-03-24 11:09:42,100] INFO - dDirectoryBasedCleanupRegistry - Removing files from D:\work\.old

0

Also note I've opened a JetBrains ticket as well here:

https://youtrack.jetbrains.com/issue/TW-44630

Don't know if that should be consolidated somehow with this one.  Also we are on a Teamcity support contract so should I open a support ticket instead?

Thanks a lot.

0

Hi Andrew,

sorry for delay. Please watch for the issue you opened in youtrack, we will provide you with instructions on how to update the wrapper. The responsible developer is on vacation till the next week.

0

Please sign in to leave a comment.