Perforce updating: cannot allocate memory

Hi all -

We're running TC on Linux and seem to continually hit a memory problem after a day or two. It's not a java.lang.OutOfMemory... it's a problem when trying to fork a process. Here's the stack trace:

perforce: perforce.nexvu.com:1666
java.io.IOException: Cannot allocate memory
jetbrains.buildServer.vcs.VcsException: com.intellij.execution.process.ProcessNotCreatedException: java.io.IOException: Cannot allocate memory
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:79)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:98)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.getCurrentVersion(PerforceConnection.java:99)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceSupport.getCurrentVersion(PerforceSupport.java:112)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.loadChanges(VcsChangesLoader.java:9)
at jetbrains.buildServer.serverSide.impl.ProjectImpl.loadChanges(ProjectImpl.java:111)
at jetbrains.buildServer.serverSide.impl.ProjectImpl.checkForModifications(ProjectImpl.java:107)
at jetbrains.buildServer.serverSide.impl.BuildServerImpl$6.run(BuildServerImpl.java:8)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Caused by: com.intellij.execution.process.ProcessNotCreatedException: java.io.IOException: Cannot allocate memory
at com.intellij.execution.configurations.GeneralCommandLine.createProcess(GeneralCommandLine.java:113)
at jetbrains.buildServer.buildTriggers.vcs.perforce.P4CommandLineConnection.runP4Command(P4CommandLineConnection.java:9)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:183)
... 13 more
com.intellij.execution.process.ProcessNotCreatedException: java.io.IOException: Cannot allocate memory
at com.intellij.execution.configurations.GeneralCommandLine.createProcess(GeneralCommandLine.java:113)
at jetbrains.buildServer.buildTriggers.vcs.perforce.P4CommandLineConnection.runP4Command(P4CommandLineConnection.java:9)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:183)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:98)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.getCurrentVersion(PerforceConnection.java:99)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceSupport.getCurrentVersion(PerforceSupport.java:112)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.loadChanges(VcsChangesLoader.java:9)
at jetbrains.buildServer.serverSide.impl.ProjectImpl.loadChanges(ProjectImpl.java:111)
at jetbrains.buildServer.serverSide.impl.ProjectImpl.checkForModifications(ProjectImpl.java:107)
at jetbrains.buildServer.serverSide.impl.BuildServerImpl$6.run(BuildServerImpl.java:8)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)


Here's some system info:

  1. cat /etc/redhat-release

Fedora Core release 5 (Bordeaux)

  1. uname -a

Linux centauri.nexvu.com 2.6.17-1.2187_FC5 #1 Mon Sep 11 01:17:06 EDT 2006 i686 athlon i386 GNU/Linux

  1. java -version

java version "1.5.0_09"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_09-b01)
Java HotSpot(TM) Client VM (build 1.5.0_09-b01, mixed mode, sharing)

  1. p4 -V

Perforce - The Fast Software Configuration Management System.
Copyright 1995-2006 Perforce Software. All rights reserved.
Rev. P4/LINUX26X86/2006.1/101890 (2006/06/21).


Here's our startup script (note: we disabled the agent on this machine):
-


#!/bin/sh

export JAVA_HOME=/usr/java/current

if [ "" == "$1" ]; then
echo "Run as $0 (start|stop)"
exit 1
fi

#cd `dirname $0`
cd /data/tomcat/bin

mkdir ../logs 2>/dev/null

JAVA_OPTS="-Xmx512m -Xms256m -XX:MaxPermSize=128m -Dteamcity.data.path=/data/teamcity_data"
CATALINA_HOME=./..
CATALINA_BASE=./..
export JAVA_OPTS

./catalina.sh $1

  1. NOTE: disable agent on Centauri

#cd ../buildAgent/bin
#./agent.sh $1
-



We've tried increasing various memory options to no avail.

Here's some typical output from the teamcity-vcs.log:
-


DEBUG - buildserver.VcsActivities - Collecting changes for Monarch; from version 22875; root=client-mapping=//depot/monarch/src/... //team-city-agent/src/...
//depot/monarch/lib/... //team-city-agent/lib/...
//depot/monarch/test/... //team-city-agent/test/...
//depot/monarch/build.xml //team-city-agent/build.xml
//depot/monarch/build.props //team-city-agent/build.props
//depot/monarch/build-properties.xml //team-city-agent/build-properties.xml
//depot/monarch/build-tests.xml //team-city-agent/build-tests.xml
//depot/monarch/build-docs.xml //team-city-agent/build-docs.xml
//depot/monarch/build-publish.xml //team-city-agent/build-publish.xml
p4-exe=/usr/bin/p4
port=perforce.nexvu.com:1666
use-client=false
user=daemon

DEBUG - buildserver.VcsActivities - Vcs connection problem: java.io.IOException: Cannot allocate memory
jetbrains.buildServer.vcs.VcsException: com.intellij.execution.process.ProcessNotCreatedException: java.io.IOException: Cannot allocate memory
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:79)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:98)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.getCurrentVersion(PerforceConnection.java:99)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceSupport.getCurrentVersion(PerforceSupport.java:112)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.loadChanges(VcsChangesLoader.java:9)
at jetbrains.buildServer.serverSide.impl.ProjectImpl.loadChanges(ProjectImpl.java:111)
at jetbrains.buildServer.serverSide.impl.ProjectImpl.checkForModifications(ProjectImpl.java:107)
at jetbrains.buildServer.serverSide.impl.BuildServerImpl$6.run(BuildServerImpl.java:8)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Caused by: com.intellij.execution.process.ProcessNotCreatedException: java.io.IOException: Cannot allocate memory
at com.intellij.execution.configurations.GeneralCommandLine.createProcess(GeneralCommandLine.java:113)
at jetbrains.buildServer.buildTriggers.vcs.perforce.P4CommandLineConnection.runP4Command(P4CommandLineConnection.java:9)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:183)
... 13 more
-


12 comments
Comment actions Permalink

Oh, I should add that it looks like a CVS-based project was dead at the same time, so all VCS access was dead with the same symptoms.

0
Comment actions Permalink

Hello,

Could you please check how many processes exist in your system when failure occures? Try running something like "ps aux" to get this info.
Please also run 'free' utility to check available memory.

Regards,
KIR

0
Comment actions Permalink

Sorry, had to wait for it to happen again and of course it takes longer when I'm waiting for it. :-P

Here's the info:

# free
total used free shared buffers cached
Mem: 775336 753296 22040 0 13300 60600
-/+ buffers/cache: 679396 95940
Swap: 1044208 537548 506660

# ps -ef | wc -l
118

# ps -ef | grep java
root 31218 1 3 Nov29 ? 04:16:03 /usr/java/current/bin/java -Xmx512m -Xms256m -XX:MaxPermSize=128m -Dteamcity.data.path=/data/teamcity_data -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/data/tomcat/conf/logging.properties -Djava.endorsed.dirs=/data/tomcat/common/endorsed -classpath :/data/tomcat/bin/bootstrap.jar:/data/tomcat/bin/commons-logging-api.jar -Dcatalina.base=/data/tomcat -Dcatalina.home=/data/tomcat -Djava.io.tmpdir=/data/tomcat/temp org.apache.catalina.startup.Bootstrap start
root 21331 21208 0 13:30 pts/0 00:00:00 grep java

Other info:
load average: 0.00, 0.03, 0.05

VM Flags:
-Xmx512m -Xms256m -XX:MaxPermSize=128m -Dteamcity.data.path=/data/teamcity_data -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/data/tomcat/conf/logging.properties -Djava.endorsed.dirs=/data/tomcat/common/endorsed -Dcatalina.base=/data/tomcat -Dcatalina.home=/data/tomcat -Djava.io.tmpdir=/data/tomcat/temp



# jstat -gc 31218
S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT
1984.0 1984.0 266.7 0.0 16256.0 1808.8 241984.0 54004.2 19712.0 19584.0 5192 56.491 14 18.141 74.632
# jstat -gccapacity 31218
NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC PGCMN PGCMX PGC PC YGC FGC
20160.0 40320.0 20224.0 1984.0 1984.0 16256.0 241984.0 483968.0 241984.0 241984.0 8192.0 131072.0 19712.0 19712.0 5192 14
# jstat -gccause 31218
S0 S1 E O P YGC YGCT FGC FGCT GCT LGCC GCC
13.44 0.00 21.11 22.32 99.35 5192 56.491 14 18.141 74.632 unknown GCCause No GC
# jstat -gcnew 31218
S0C S1C S0U S1U TT MTT DSS EC EU YGC YGCT
1984.0 1984.0 266.7 0.0 15 15 992.0 16256.0 4025.5 5192 56.491
# jstat -gcnewcapacity 31218
NGCMN NGCMX NGC S0CMX S0C S1CMX S1C ECMX EC YGC FGC
20160.0 40320.0 20224.0 1984.0 4032.0 4032.0 1984.0 32256.0 16256.0 5192 14
# jstat -gcold 31218
PC PU OC OU YGC FGC FGCT GCT
19712.0 19584.0 241984.0 54004.2 5192 14 18.141 74.632
# jstat -gcoldcapacity 31218
OGCMN OGCMX OGC OC YGC FGC FGCT GCT
241984.0 483968.0 241984.0 241984.0 5192 14 18.141 74.632
# jstat -gcpermcapacity 31218
PGCMN PGCMX PGC PC YGC FGC FGCT GCT
8192.0 131072.0 19712.0 19712.0 5192 14 18.141 74.632
# jstat -gcutil 31218
S0 S1 E O P YGC YGCT FGC FGCT GCT
13.44 0.00 45.73 22.32 99.35 5192 56.491 14 18.141 74.632


# jmap -heap 31218
Attaching to process ID 31218, please wait...
Debugger attached successfully.
Client compiler detected.
JVM version is 1.5.0_09-b01

using thread-local object allocation.
Mark Sweep Compact GC

Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 536870912 (512.0MB)
NewSize = 655360 (0.625MB)
MaxNewSize = 4294901760 (4095.9375MB)
OldSize = 1441792 (1.375MB)
NewRatio = 12
SurvivorRatio = 8
PermSize = 8388608 (8.0MB)
MaxPermSize = 134217728 (128.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
capacity = 18677760 (17.8125MB)
used = 15010200 (14.314842224121094MB)
free = 3667560 (3.4976577758789062MB)
80.36402652138158% used
Eden Space:
capacity = 16646144 (15.875MB)
used = 14737056 (14.054351806640625MB)
free = 1909088 (1.820648193359375MB)
88.53134996309055% used
From Space:
capacity = 2031616 (1.9375MB)
used = 273144 (0.26049041748046875MB)
free = 1758472 (1.6770095825195312MB)
13.444666708669354% used
To Space:
capacity = 2031616 (1.9375MB)
used = 0 (0.0MB)
free = 2031616 (1.9375MB)
0.0% used
tenured generation:
capacity = 247791616 (236.3125MB)
used = 55300312 (52.738487243652344MB)
free = 192491304 (183.57401275634766MB)
22.31726516525886% used
Perm Generation:
capacity = 20185088 (19.25MB)
used = 20053984 (19.124969482421875MB)
free = 131104 (0.125030517578125MB)
99.35049081777598% used


The perm heap being at 99% is the only thing that jumps out at me, but the max size is set to 128M and it's only using 20... so I don't think that's the issue.

0
Comment actions Permalink

Also might be helpful (from top)

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
31218 root 15 0 1700m 533m 7528 S 0.3 70.5 256:05.70 java

0
Comment actions Permalink

/bump

Any thoughts?

0
Comment actions Permalink

R. Eden wrote:

/bump

Any thoughts?


Sorry, I've missed your post. Will try to
investigate in the nearest time.

Regards,
KIR


--
Kirill Maximov
JetBrains, Inc.
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

Could you please tell me which TeamCity version do you have installed?

0
Comment actions Permalink

1.1.1, although it's happened on all version so far.

0
Comment actions Permalink

No worries. I know you guys are busy. Thanks for the help.

0
Comment actions Permalink

R. Eden wrote:

1.1.1, although it's happened on all version so far.


Looks something similar to http://forum.java.sun.com/thread.jspa?threadID=665350 .
Will try to find out more.

KIR


--
Kirill Maximov
JetBrains, Inc.
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

Bump again.

So, is anyone else using TC on linux? Am I the only one experiencing this problem? I really can't keep this thing running. It's stopping every other day. If it's working for other people, could you tell me what Linux and JVM you're using? Thanks.

Rob

0
Comment actions Permalink

I'm running server & clients on Linux fine (RH Linux FC3, JVM 1.5.0_08).
We're not using Perforce though, we're SVN.
HTH,
R

0

Please sign in to leave a comment.