Agent performance problem

Hi

I have major performance issues in one of Teamcity's agent.

We just reinstalled the machine and, If we launch tests (using ant scripts) from teamcity the time to execute a command is 50 times longer than directly exectued in the machine.
sql queries are also verry slow.

Other agents behave normaly with same tests.

I dont think it's a HD problem as i just reinstalled the machine.

could you please help me fix this issue.

BR

5 comments
Comment actions Permalink

Let me precise a bit my above statements.

I built a debug.xml ant file that contains dummy tasks to compare between command line run and TC agent run. I basically did :

<target name="foreach">
   <foreach target="fotarget" param="theFile">
 <path>
 <fileset dir="c:/rp3/rp/lib/ext" includes="*.*"/>
 </path>
   </foreach>
</target>


<target name="fotarget">
 <tstamp><format property="stampx" pattern="H:m:s:S"/></tstamp>
 <echo message="timex is ${stampx} file was ${theFile}"/>


 <tstamp><format property="stampy" pattern="H:m:s:S"/></tstamp>
 <echo message="timey is ${stampy}"/>
</target>


Running this from the command line takes around 7 seconds, while within TC it takes 6 minutes ! Rerunning the same task on another of our agent takes around 10 seconds ! Before re-installing this machine, we didn't have the issue at all either.

A huge amount of time is spent between each ant command execution and I have no idea where this time is lost. The agent is of course totally unusable in this state.

Consider the two echo of the timestamps : while on the command line they usually occur in the next millisecond, there are 2.5 seconds spent between each call with Teamcity.

I attach all I could gather : debug.xml ant file, my timings summarized in an excel sheet and the agent logs at debug level.

Within the XLS, find following sheets :
- foreach tc bad - the teamcity build log on the machine showing the performance issue for the foreach loop described above
- foreach tc good - same but on another agent
- foreach console - ant run output from the console when running as command line on the "bad" machine
- other tasks : some timings for the other tasks contained in the debug.xml ant file also showing big deltas.

Your help would be greatly appreciated : it's already the 3rd machine that shows this behaviour and we cannot find any way out of it except moving the agent to another machine - and we're out of them ;)

We are using Win7 64 bits, TC 6.0.2 / 15857. I tried running the agent 32 or 64 bits, service or console, to no avail.

Thanks for your help,

Ali


Attachment(s):
tcagent.xlsx
teamcity-build.log.zip
teamcity-agent.log.zip
debug.xml
0
Comment actions Permalink

Hello Ali,

Sorry for the delay in replying and thank you for the detailed report.

Since only some machines are involved, there should be something different in the environment. As this is not a known issue, I'd suggest try to figure out what is different in the environment.
Can you please look through the section and doublecheck that this is not an OS-user-specific issue and not a Windows service one? I'd also repeat the console and agent builds ensuring that they use the same Ant and JVM.

To investigate the build itself, please take several thread dumps of the build (you can do this from TeamCity UI on the build results page while the build is running) and attach them here.

0
Comment actions Permalink

Hello,

I am pretty sure that something somewhere in that machine is wrong - but I have no clue as to where. Trust me I already compare with care several times all environements settings with other machines - without further hints.

I followed the process on the page you describe; I tried re-running the exact command line that was given in the build log :

[10:09:07]: Starting: "C:\Program Files\Java\jdk1.6.0_21\bin\java.exe" -Dagent.home.dir=C:\BuildAgent -Dagent.name=LAU-RP07 -Dagent.ownPort=9090 -Dagent.work.dir=C:\BuildAgent\work -Dant.home=C:\BuildAgent\work\f84f2a742524597a\tungsten\ext\ant\ant-1.8.0 -Dbuild.number=20 -Dbuild.vcs.number=30755 -Dbuild.vcs.number.1=30755 -Dbuild.vcs.number.RP3_SVN_Repository=30755 -Dfile.encoding=Cp1252 -Dfile.separator=\ -Djava.io.tmpdir=C:\BuildAgent\temp\buildTmp -Dos.arch=x86 "-Dos.name=Windows 7" -Dos.version=6.1 -Dpath.separator=; -Dteamcity.agent.cpuBenchmark=371 -Dteamcity.agent.dotnet.agent_url=http://localhost:9090/RPC2 -Dteamcity.agent.dotnet.build_id=26735 -Dteamcity.auth.password=5S8qLlLB7BwMSs6BA4bsHkvdam8Vpjrf -Dteamcity.auth.userId=TeamCityBuildId=26735 -Dteamcity.build.changedFiles.file=C:\BuildAgent\temp\buildTmp\changedFiles3817494584624143933.txt -Dteamcity.build.checkoutDir=C:\BuildAgent\work\f84f2a742524597a -Dteamcity.build.id=26735 -Dteamcity.build.properties.file=C:\BuildAgent\temp\buildTmp\teamcity.build3808938142531673229.properties -Dteamcity.build.tempDir=C:\BuildAgent\temp\buildTmp -Dteamcity.build.workingDir=C:\BuildAgent\work\f84f2a742524597a "-Dteamcity.buildConfName=TeamCity Debug" -Dteamcity.buildType.id=bt100 -Dteamcity.configuration.properties.file=C:\BuildAgent\temp\buildTmp\teamcity.config5680402980877910568.properties -Dteamcity.dotnet.nunitaddin=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.TeamCity.NUnitAddin-NUnit -Dteamcity.dotnet.nunitlauncher=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher.exe -Dteamcity.dotnet.nunitlauncher.msbuild.task=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.MSBuildLoggers.dll -Dteamcity.dotnet.nunitlauncher1.1=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher1.1.exe -Dteamcity.dotnet.nunitlauncher2.0=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher2.0.exe -Dteamcity.dotnet.nunitlauncher2.0.vsts=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.BuildServer.NUnitLauncher2.0.VSTS.exe -Dteamcity.dotnet.platform=C:\BuildAgent\plugins\dotnetPlugin\bin\JetBrains.TeamCity.PlatformProcessRunner.1.1.exe -Dteamcity.idea.home=C:\BuildAgent/plugins/idea -Dteamcity.projectName=Sandbox -Dteamcity.runner.properties.file=C:\BuildAgent\temp\buildTmp\teamcity.runner8714920724714776431.properties -Dteamcity.runtime.props.file=C:\BuildAgent\temp\agentTmp\ant921426314199781432runtime -Dteamcity.tests.recentlyFailedTests.file=C:\BuildAgent\temp\buildTmp\testsToRunFirst6742146679022110954.txt "-Dteamcity.version=6.0.2 (build 15857)" -Duser.country=US -Duser.home=C:\Users\riskpro-test -Duser.language=en -Duser.name=riskpro-test -Duser.timezone=Europe/Berlin -Duser.variant= -Xmx1024m -classpath C:\BuildAgent\work\f84f2a742524597a\tungsten\ext\ant\ant-1.8.0\lib\ant-launcher.jar org.apache.tools.ant.launch.Launcher -lib C:/BuildAgent/plugins/antPlugin/lib/buildServerAntRuntime.jar;C:/BuildAgent/lib/runtime-util.jar -listener jetbrains.buildServer.agent.ant.AgentBuildListener -buildfile C:\BuildAgent\work\f84f2a742524597a\debug.xml
[10:09:07]: in directory: C:\BuildAgent\work\f84f2a742524597a

As a result, it took the same amount of time as when running it from within TeamCity - 6 minutes.
If instead I directly type :
C:\BuildAgent\work\f84f2a742524597a>tungsten\ext\ant\ant-1.8.0\bin\ant.bat -buildfile debug.xml
Buildfile: C:\BuildAgent\work\f84f2a742524597a\debug.xml

I get :
BUILD SUCCESSFUL
Total time: 7 seconds


I attach the stack dumps - all of them show that the agent is waiting on some socket connections, so before you ask : yes, all machine are located on the same physical Gigabit network switch within the same subnet :) Pinging the server shows a <1ms reply.

It seems in my opinion that it is not the task execution itself that is taking more time than usual, but some other activities run between each ant execution lines, as if some bad network connectivity slowed it all down. Like when the ant result is logged back to the Teamcity server. But I can't see any - and I can't see either how I could debug this further - if you have any hints.

Thanks for your help.




Attachment(s):
stacks.zip
0
Comment actions Permalink

Ali,

Thank you for the thread dump.

The information you provided does point out to TeamCIty agent: seems like TCP communications between the Ant process (and TeamCity listener in it) and the TeamCIty agent are to blame.

Can you please reproduce the issue once more and take thread dumps of the TeamCity agent process while the build is running that slow?

My current guess on suspicious places to check:
- antivirus or any other network-monitoring applications that might be running on the machine
- any unusual network configuration on the machine

0
Comment actions Permalink

The dicussion continued via email and ended up discovering that completely turning off antivirus services on the machine solves the issue.

0

Please sign in to leave a comment.