High CPU usage
We have noticed the CPU usage of TeamCity increased rather substantially in the last week and it looks to have started at midnight on July the 1st for some reason.
$ ps -ea -o pcpu,cmd | grep teamcity
246 /usr/bin/java -Djava.util.logging.config.file=/opt/TeamCity/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -server -Xmx512m -XX:MaxPermSize=270m -Dlog4j.configuration=file:/opt/TeamCity/bin/../conf/teamcity-server-log4j.xml -Dteamcity_logs=../logs/ -Djava.awt.headless=true -Djava.endorsed.dirs=/opt/TeamCity/endorsed -classpath /opt/TeamCity/bin/bootstrap.jar:/opt/TeamCity/bin/tomcat-juli.jar -Dcatalina.base=/opt/TeamCity -Dcatalina.home=/opt/TeamCity -Djava.io.tmpdir=/opt/TeamCity/temp org.apache.catalina.startup.Bootstrap start
We had been running 7.0.2 and the HSQLDB so we have migrated to a local MySQL database and upgraded to 7.0.3 (after reading through http://youtrack.jetbrains.com/issue/TW-21375)
We also upgraded java to version 1.7.0 incase there was any issues with the java release.
# /usr/lib/jvm/jre-1.6.0-openjdk.x86_64/bin/java -version
java version "1.6.0_17"
OpenJDK Runtime Environment (IcedTea6 1.7.9) (rhel-1.36.b17.el6_0-x86_64)
OpenJDK 64-Bit Server VM (build 14.0-b16, mixed mode)# /usr/java/jdk1.7.0_05/bin/java -version
java version "1.7.0_05"
Java(TM) SE Runtime Environment (build 1.7.0_05-b05)
Java HotSpot(TM) 64-Bit Server VM (build 23.1-b03, mixed mode)
None of these have resolved the problem so its still sitting there sucking CPU time.
Are there any further solutions that we could try?
Please sign in to leave a comment.
Hi Christopher
Could you please capture CPU profiling snapshot as explained in Server Performance article.
Thanks
Just tried to install the performace profiler but the server refused to start when adding the '-agentpath:/opt/TeamCity/bin/libyjpagent.so=disablecounts,disablealloc,disablestacktelemetry,disableexceptiontelemetry,sessionname=TeamCity' option to the startup arguments and I get this error when I take it out and start it.
TeamCity: 7.0.3 (build 21424)
Operating system: Linux (2.6.32-71.29.1.el6.x86_64, amd64)
Java: 1.7.0_05-b05 (Oracle Corporation)
Servlet container: Apache Tomcat/7.0.23
Also just to tag on but I can run the profiler agent by itself
$ java -agentpath:/opt/TeamCity/bin/libyjpagent.so=help
YourKit Java Profiler 8.0.29 JVMTI agent usage: -agentlib:yjpagent=[help]|[<option>, ...]
Option Description
------------------ ----------------------------------------
port=<value> port to listen on (1-65535, by default any free port is chosen)
listen=<ip>:<port> same as 'port', but bind agent socket to particular IP only
onlylocal allow only local connections to profiled application
dir=<custom dir> directory where snapshots are created (by default <user home>/Snapshots)
telemetrylimit=<N> limit telemetry buffer capacity to N hours (approximately)
sampling startup with CPU sampling
tracing startup with CPU tracing
(cannot be used together with 'disablecounts')
noj2ee do not perform J2EE high level profiling
(use only in combination with 'sampling' or 'tracing')
alloceach=<N> startup with object allocation recording: record each N-th allocation;
can be used together with 'allocsizelimit';
cannot be used together with 'disablealloc'
allocsizelimit=<B> startup with object allocation recording: record objects with size >= B bytes
can be used together with 'alloceach';
cannot be used together with 'disablealloc'
monitors startup with monitor usage profiling
usedmem=<percent> capture memory snapshot automatically when used heap memory
reaches the threshold
onexit=memory always capture memory snapshot on exit
onexit=snapshot always capture performance snapshot on exit (i.e. without heap)
disablealloc do not instrument bytecode for object allocation recording
disablecounts do not instrument bytecode for CPU tracing
disablej2ee do not instrument bytecode for J2EE profiling
disablestacktelemetry
do not collect thread stack and status information
quiet suppress diagnostic messages
Please find detailed description in the Help section "Startup options":
http://www.yourkit.com/docs/80/help/additional_agent_options.jsp
Examples:
java -agentlib:yjpagent FooClass
java -agentlib:yjpagent=alloceach=10,allocsizelimit=1000000,dir=c:\MySnapshots FooClass
java -agentlib:yjpagent=usedmem=70 FooClass
Christopher,
Sorry for the inconvenience with the profiling plugin error: it got some code committed compatible only with TeamCity 7.1 EAP. THis is not fixed and you can get a new plugin from http://teamcity.jetbrains.com/viewLog.html?buildId=66995&tab=artifacts&buildTypeId=bt262
Getting profiling snapshot would be perfect, but you can also start with general means like thread dumps, etc.
Thanks Yegor. I have attached the CPU snapshot and the catalina.out with the stack traces. The memory snapshot was too large to attach so let me know if you require it
Attachment(s):
TeamCity-Performance.tar.gz
Christopher,
The snapshot does not reveal any significant load as well as the thread dump.
Was the CPU heavily loaded by TeamCity's java process when you took the snapshot?
Can you doublecheck it's TeamCity server java which is loading the CPU?
If confirmed, please attach CPU load data for the TeamCity java process and take CPU snapshot (start, ensure the process is loading CPU, stop after 5-10 minutes) and attach the data.
WHile most probably not related, I'd recommend to use latest Oracle 1.6 JDK for the server.
Hi Yegor,
I am very sure that it is TeamCity causing the load and its loading the server as it starts rather than needing a trigger to start it off
I have attached an extended CPU profile and put a capture of top from the host running TeamCity
top - 08:20:58 up 271 days, 22:55, 3 users, load average: 34.04, 33.41, 33.31
Tasks: 158 total, 4 running, 154 sleeping, 0 stopped, 0 zombie
Cpu(s): 34.0%us, 65.5%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.5%si, 0.0%st
Mem: 24738248k total, 20788856k used, 3949392k free, 560692k buffers
Swap: 26836984k total, 30276k used, 26806708k free, 17344476k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1491 mavsup 20 0 3157m 744m 13m S 253.6 3.1 15562:56 /usr/bin/java -Djava.util.logging.config.file=/opt/TeamCity/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -server -Xmx512m -XX:MaxPermSize=270m -Dlog4j.configuration=file:/opt/TeamCity/bin/../conf/teamcity-server-log4j.xml -Dteamcity_logs=../logs/ -Djava.awt.headless=true -agentpath:/opt/TeamCity/bin/libyjpagent.so=disab
15048 mavsup 20 0 2722m 264m 14m S 43.7 1.1 3983:52 /usr/java/jdk1.7.0_05/jre/bin/java -ea -Xmx384m -Dteamcity_logs=../logs/ -Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml -classpath /opt/TeamCity/buildAgent/lib/agent.jar:/opt/TeamCity/buildAgent/lib/messages.jar:/opt/TeamCity/buildAgent/lib/jdk-searcher.jar:/opt/TeamCity/buildAgent/lib/xml-rpc-wrapper.jar:/opt/TeamCity/buildAgent/lib/commons-collection
14671 mavsup 20 0 7622m 48m 9752 S 22.4 0.2 2629:52 /usr/bin/../bin/java -ea -cp ../launcher/lib/launcher.jar jetbrains.buildServer.agent.Launcher -ea -Xmx384m -Dteamcity_logs=../logs/ -Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml jetbrains.buildServer.agent.AgentMain -file ../conf/buildAgent.properties
Attachment(s):
TeamCity-2012-07-19-CPU.snapshot.bz2
Christopher,
Still nothing special in the snapshot.
Reading through your "it looks to have started at midnight on July the 1st for some reason" - it looks very much alike the known leap second Linux kernell issue.
e.g. see http://serverfault.com/questions/403732/anyone-else-experiencing-high-rates-of-linux-server-crashes-during-a-leap-second
Thanks Yegor, that worked a treat!