TeamCity crashing nightly

I am not really sure what is going on, I am looking at the teamcity-server.log and I see several errors that look interesting. The first is a loss of communication with MySQL that results in a StackTrace output. But then it comes back on and starts running a clean up process. The cleanup process I think is where the problem may be occuring because after the last entry I then have entries of the server starting up, which is when we go in and start the service manually.

The TeamCity server is running on a Windows 2008 Server, with 4 GB or RAM and 2 processors, it is running under a VMWare VM.

Please help, as we need this server autobuilding and I currently have to restart it every morning.

Thanks

Here is where I think the issue is, it is running a clean up procedure and then after 3 AM I see nothing until it is restarted at 9 PM in this case:

[2014-07-01 03:00:05,396]   INFO - .serverSide.search.SearchIndex - Finished search index optimization

[2014-07-01 03:00:06,801]   INFO -  jetbrains.buildServer.CLEANUP - Removing audit log records for obsolete tests ...

[2014-07-01 03:00:06,832]   INFO -  jetbrains.buildServer.CLEANUP - Removing audit log records for obsolete builds ...

[2014-07-01 03:00:06,885]   INFO -  jetbrains.buildServer.CLEANUP - Start cleaning inspection_data dictionary...

[2014-07-01 03:00:06,885]   INFO -  jetbrains.buildServer.CLEANUP - Lock for the maintenance process released

[2014-07-01 03:00:06,891]   INFO -  jetbrains.buildServer.CLEANUP - Finished cleaning inspection_data dictionary

[2014-07-01 03:00:07,023]   INFO -   jetbrains.buildServer.SERVER - DiskUsage scanning all data finished

[2014-07-01 03:00:08,542]   INFO -   jetbrains.buildServer.SERVER - Huge logs scanning finished

[2014-07-03 21:20:14,183]   INFO -  jetbrains.buildServer.STARTUP -

[2014-07-03 21:20:14,190]   INFO -  jetbrains.buildServer.STARTUP - ===========================================================

[2014-07-03 21:20:14,190]   INFO -  jetbrains.buildServer.STARTUP - Starting TeamCity server

[2014-07-03 21:20:14,346]   INFO -  jetbrains.buildServer.STARTUP - TeamCity version: 8.1.3 (build 30101), data format version 658

[2014-07-03 21:20:14,360]   INFO -  jetbrains.buildServer.STARTUP - OS: Windows Server 2008, User: TSLA$, JRE: 1.7.0_51-b13 Java HotSpot(TM) Server VM

[2014-07-03 21:20:14,361]   INFO -  jetbrains.buildServer.STARTUP - JVM parameters: -Djava.util.logging.config.file=e:\TeamCity\bin\..\conf\logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Xrs -Xmx512m -XX:MaxPermSize=270m -Dlog4j.configuration=file:../conf/teamcity-server-log4j.xml -Dteamcity_logs=../logs/ -Djava.endorsed.dirs=e:\TeamCity\bin\..\endorsed -Dcatalina.base=e:\TeamCity\bin\.. -Dcatalina.home=e:\TeamCity\bin\.. -Djava.io.tmpdir=e:\TeamCity\bin\..\temp


Here is a sequence with the disconnect from the MySQL database, I think this is not the issue but it is here for reference:

[2014-06-30 17:04:33,256]   INFO - tbrains.buildServer.ACTIVITIES - Finished 5268

[2014-06-30 22:13:33,105]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Querying for a single value

SQL query: select last_time from db_heartbeat where starting_code = ?

SQL exception: Communications link failure

The last packet successfully received from the server was 20,065 milliseconds ago.  The last packet sent successfully to the server was 19,065 milliseconds ago.

[2014-06-30 22:13:54,109]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Taking a connection from the data source

SQL exception: Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.

[2014-06-30 22:15:06,659]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Querying for a single value

SQL query: select last_time from db_heartbeat where starting_code = ?

SQL exception: Communications link failure

The last packet successfully received from the server was 1,009 milliseconds ago.  The last packet sent successfully to the server was 1,009 milliseconds ago.

[2014-06-30 22:15:58,648]  ERROR - etbrains.buildServer.HEARTBEAT - Heartbeat pulse error: Unexpected exception MySQLNonTransientConnectionException: SQL error when doing: Commit

SQL exception: Communications link failure during commit(). Transaction resolution unknown.

[2014-06-30 22:15:59,652]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Connection.setAutoCommit(false)

SQL exception: Communications link failure

The last packet successfully received from the server was 316 milliseconds ago.  The last packet sent successfully to the server was 315 milliseconds ago.

[2014-06-30 22:17:04,616]  ERROR - etbrains.buildServer.HEARTBEAT - Heartbeat pulse error: Unexpected exception MySQLNonTransientConnectionException: SQL error when doing: Commit

SQL exception: Communications link failure during commit(). Transaction resolution unknown.

[2014-06-30 22:17:05,618]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Connection.setAutoCommit(false)

SQL exception: Communications link failure

The last packet successfully received from the server was 31,744 milliseconds ago.  The last packet sent successfully to the server was 31,744 milliseconds ago.

[2014-06-30 22:18:09,706]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Querying for a single value

SQL query: select last_time from db_heartbeat where starting_code = ?

SQL exception: Communications link failure

The last packet successfully received from the server was 19,905 milliseconds ago.  The last packet sent successfully to the server was 18,900 milliseconds ago.

[2014-06-30 22:18:30,700]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Taking a connection from the data source

SQL exception: Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.

[2014-06-30 22:19:25,459]  ERROR -   jetbrains.buildServer.SERVER - Could not connect to MySQL server.

SQL error when doing: Executing a SQL statement

SQL query: create temporary table if not exists build_type$ ( build_type_id varchar(80) not null )

SQL exception: Communications link failure

The last packet successfully received from the server was 34,512 milliseconds ago.  The last packet sent successfully to the server was 34,511 milliseconds ago.

jetbrains.buildServer.serverSide.db.DatabaseIsNotReachableException: Could not connect to MySQL server.

SQL error when doing: Executing a SQL statement

SQL query: create temporary table if not exists build_type$ ( build_type_id varchar(80) not null )

SQL exception: Communications link failure

The last packet successfully received from the server was 34,512 milliseconds ago.  The last packet sent successfully to the server was 34,511 milliseconds ago.

 at sun.reflect.GeneratedConstructorAccessor151.newInstance(Unknown Source)

 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

 at java.lang.reflect.Constructor.newInstance(Constructor.java:526)

 at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)

 at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1127)

 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3715)

 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3604)

 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4155)

 at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)

 at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)

 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2832)

 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2781)

 at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:908)

 at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:788)

 at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)

 at jetbrains.buildServer.serverSide.db.DBFunctions$8.run(DBFunctions.java:749)

 at jetbrains.buildServer.serverSide.db.DBFunctions$8.run(DBFunctions.java:746)

 at jetbrains.buildServer.serverSide.db.DBInternalUtils.rawOperation(DBInternalUtils.java:62)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeSimpleInternal(DBFunctions.java:746)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeSimpleInternal(DBFunctions.java:731)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeParsedDdls(DBFunctions.java:696)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeDdls(DBFunctions.java:676)

 at jetbrains.buildServer.serverSide.db.TeamCityBasicDataSource$JdbcConnectionFactory.runPerSessionScriptForConnection(TeamCityBasicDataSource.java:81)

 at jetbrains.buildServer.serverSide.db.TeamCityBasicDataSource$JdbcConnectionFactory.createConnection(TeamCityBasicDataSource.java:72)

 at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)

 at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1181)

 at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)

 at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)

 at jetbrains.buildServer.serverSide.db.ReliablePoolingDataSource.getConnection(ReliablePoolingDataSource.java:51)

 at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)

 at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:224)

 at com.sun.proxy.$Proxy21.getAutoCommit(Unknown Source)

 at jetbrains.buildServer.serverSide.db.DBInternalUtils$2.run(DBInternalUtils.java:101)

 at jetbrains.buildServer.serverSide.db.DBInternalUtils$2.run(DBInternalUtils.java:98)

 at jetbrains.buildServer.serverSide.db.DBInternalUtils.rawOperation(DBInternalUtils.java:62)

 at jetbrains.buildServer.serverSide.db.DBInternalUtils.rollback(DBInternalUtils.java:98)

 at jetbrains.buildServer.serverSide.db.DBFunctions.rollback(DBFunctions.java:2124)

 at jetbrains.buildServer.serverSide.db.DBFacade.withDB(DBFacade.java:290)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery.executeUpdate(GenericQuery.java:136)

 at jetbrains.buildServer.serverSide.impl.AgentPersistenceFacade.setBindingTimestamp(AgentPersistenceFacade.java:236)

 at jetbrains.buildServer.serverSide.impl.XmlRpcBasedAgent.persistCommTimestamp(XmlRpcBasedAgent.java:66)

 at jetbrains.buildServer.serverSide.impl.XmlRpcBasedAgent.setCommunicationTimestamp(XmlRpcBasedAgent.java:76)

 at jetbrains.buildServer.serverSide.impl.XmlRpcBasedAgent$AgentTargetProxy.call(XmlRpcBasedAgent.java:314)

 at jetbrains.buildServer.serverSide.impl.XmlRpcBasedAgent.pingInternal(XmlRpcBasedAgent.java:159)

 at jetbrains.buildServer.serverSide.impl.XmlRpcBasedAgent.ping(XmlRpcBasedAgent.java:142)

 at jetbrains.buildServer.serverSide.impl.auth.SecuredBuildAgent.ping(SecuredBuildAgent.java:84)

 at jetbrains.buildServer.serverSide.impl.BuildAgentManagerImpl.pingAllAgents(BuildAgentManagerImpl.java:6)

 at jetbrains.buildServer.serverSide.impl.auth.SecuredBuildAgentManager.pingAllAgents(SecuredBuildAgentManager.java:39)

 at jetbrains.buildServer.serverSide.impl.BuildServerRunner$1.doSomething(BuildServerRunner.java:3)

 at jetbrains.buildServer.serverSide.impl.BuildServerRunner$BuildServerWorker.runAction(BuildServerRunner.java:50)

 at jetbrains.buildServer.serverSide.impl.BuildServerRunner$BuildServerWorker.run(BuildServerRunner.java:49)

 at java.lang.Thread.run(Thread.java:744)

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 34,512 milliseconds ago.  The last packet sent successfully to the server was 34,511 milliseconds ago.

 ... 52 more

Caused by: java.net.SocketException: Connection reset

 at java.net.SocketInputStream.read(SocketInputStream.java:196)

 at java.net.SocketInputStream.read(SocketInputStream.java:122)

 at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:112)

 at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:159)

 at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:187)

 at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3158)

 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3615)

 ... 46 more

[2014-06-30 22:19:30,435]   WARN - ide.impl.AgentStatusRestorer$1 - Failed to execute restore agent enabled status. Could not connect to MySQL server.

SQL error when doing: Executing a SQL statement

SQL query: create temporary table if not exists build$ ( build_id bigint not null )

SQL exception: Communications link failure

The last packet successfully received from the server was 34,512 milliseconds ago.  The last packet sent successfully to the server was 34,512 milliseconds ago.

jetbrains.buildServer.serverSide.db.DatabaseIsNotReachableException: Could not connect to MySQL server.

SQL error when doing: Executing a SQL statement

SQL query: create temporary table if not exists build$ ( build_id bigint not null )

SQL exception: Communications link failure

The last packet successfully received from the server was 34,512 milliseconds ago.  The last packet sent successfully to the server was 34,512 milliseconds ago.

 at sun.reflect.GeneratedConstructorAccessor151.newInstance(Unknown Source)

 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

 at java.lang.reflect.Constructor.newInstance(Constructor.java:526)

 at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)

 at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1127)

 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3715)

 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3604)

 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4155)

 at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)

 at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)

 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2832)

 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2781)

 at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:908)

 at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:788)

 at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)

 at jetbrains.buildServer.serverSide.db.DBFunctions$8.run(DBFunctions.java:749)

 at jetbrains.buildServer.serverSide.db.DBFunctions$8.run(DBFunctions.java:746)

 at jetbrains.buildServer.serverSide.db.DBInternalUtils.rawOperation(DBInternalUtils.java:62)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeSimpleInternal(DBFunctions.java:746)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeSimpleInternal(DBFunctions.java:731)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeParsedDdls(DBFunctions.java:696)

 at jetbrains.buildServer.serverSide.db.DBFunctions.executeDdls(DBFunctions.java:676)

 at jetbrains.buildServer.serverSide.db.TeamCityBasicDataSource$JdbcConnectionFactory.runPerSessionScriptForConnection(TeamCityBasicDataSource.java:81)

 at jetbrains.buildServer.serverSide.db.TeamCityBasicDataSource$JdbcConnectionFactory.createConnection(TeamCityBasicDataSource.java:72)

 at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)

 at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1181)

 at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)

 at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)

 at jetbrains.buildServer.serverSide.db.ReliablePoolingDataSource.getConnection(ReliablePoolingDataSource.java:51)

 at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)

 at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:224)

 at com.sun.proxy.$Proxy21.prepareStatement(Unknown Source)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery.prepareStatement(GenericQuery.java:499)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery.underPreparedStatement(GenericQuery.java:470)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery.doExecuteQuery(GenericQuery.java:401)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery.access$100(GenericQuery.java:25)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery$1.run(GenericQuery.java:105)

 at jetbrains.buildServer.serverSide.db.DBFacade.withDB(DBFacade.java:278)

 at jetbrains.buildServer.serverSide.db.queries.GenericQuery.execute(GenericQuery.java:103)

 at jetbrains.buildServer.serverSide.impl.AgentPersistenceFacade.restoreAgentsEnabledStatusesIfNeeded(AgentPersistenceFacade.java:46)

 at jetbrains.buildServer.serverSide.impl.AgentStatusRestorer$1.run(AgentStatusRestorer.java:1)

 at jetbrains.buildServer.util.ExceptionUtil$1.run(ExceptionUtil.java:40)

 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

 at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)

 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)

 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

 at java.lang.Thread.run(Thread.java:744)

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 34,512 milliseconds ago.  The last packet sent successfully to the server was 34,512 milliseconds ago.

 ... 49 more

Caused by: java.net.SocketException: Connection reset

 at java.net.SocketInputStream.read(SocketInputStream.java:196)

 at java.net.SocketInputStream.read(SocketInputStream.java:122)

 at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:112)

 at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:159)

 at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:187)

 at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3158)

 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3615)

 ... 43 more

[2014-06-30 22:19:39,164]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.

SQL error when doing: Querying for a single value

SQL query: select last_time from db_heartbeat where starting_code = ?

SQL exception: Communications link failure

The last packet successfully received from the server was 48,254 milliseconds ago.  The last packet sent successfully to the server was 47,251 milliseconds ago.

[2014-07-01 02:00:02,801]   INFO -  jetbrains.buildServer.CLEANUP - Git cleanup started

[2014-07-01 02:00:02,845]   INFO -  jetbrains.buildServer.CLEANUP - Git cleanup finished

8 comments
Comment actions Permalink

Hi,

Can you please collect few server thread dumps (e.g. 3-5 within several minutes) while the issue is reproduced, as described here.

0
Comment actions Permalink

I can't really the issue occurs at 3 AM in the morning, it seems to be when there are some maintenence commands running. When I run it now, it is after the server is restarted. Essentially when I connect in the morning the server process is not running and I need to start it again.



Attachment(s):
teamcity-threaddump-20140710-cabot.txt.zip
0
Comment actions Permalink

Sorry, I misunderstood you.
Can you please attach the whole logs folder from TeamCity server?

0
Comment actions Permalink

OK, it looks like I was checking the wrong file, the actual error is in teh winservice.log file and it shows a memory error, and then there is a hspid.log file that shows some additioanal details. I have attached all the logs and hsid files for you to review if desired. For some reason it seems that when I set it up to use MySQL it goes worse instead of better. I have increased the heap space available using the following environment variable:
TEAMCITY_SERVER_MEM_OPTS = -Xmx720m -XX:MaxPermSize=270m

What is very strange is I have tried going higher then 720m like 800m or 896m and when I start the service it simply crashes, and it says something about unable to allocate membory. I have using 32 bit JVM on a 64 bit system. Most or all memory on the system is devoted to IIS. The system has 4 GB of RAM.

This is really a small installation with 1 agent and 3 projects, I can't see how I am running out of memory so there is perhaps some configuration issue somewhere but I just don't know what to try. I am not the most Windows savvy guy, I am more of a UNIX guy, but the system I am maintaining and developing for has to run on Windows so this is what I am stuck with.

Also I am a bit concerned about having my log files up on this public service. Are these protected in anyway or can they be deleted?

Thanks

This is what I see in the teamcity-winservice.log file:
[2014-07-16 22:23:02,574] console                           [Info] [2014-07-16 22:23:02,528]  ERROR - etbrains.buildServer.HEARTBEAT - Could not connect to MySQL server.
[2014-07-16 22:23:02,574] console                           [Info] SQL error when doing: Querying for a single value
[2014-07-16 22:23:02,574] console                           [Info] SQL query: select last_time from db_heartbeat where starting_code = ?
[2014-07-16 22:23:02,574] console                           [Info] SQL exception: Communications link failure
[2014-07-16 22:23:02,574] console                           [Info]
[2014-07-16 22:23:02,574] console                           [Info] The last packet successfully received from the server was 19,939 milliseconds ago.  The last packet sent successfully to the server was 18,939 milliseconds ago.
[2014-07-17 00:58:47,891] console                           [Info]
[2014-07-17 00:58:47,891] console                           [Info] [error occurred during error reporting (null), id 0xc0000005]
[2014-07-17 00:58:47,891] console                           [Info]
[2014-07-17 00:58:47,891] console                           [Info] #
[2014-07-17 00:58:47,891] console                           [Info] # There is insufficient memory for the Java Runtime Environment to continue.
[2014-07-17 00:58:47,891] console                           [Info] # Native memory allocation (malloc) failed to allocate 740352 bytes for Chunk::new
[2014-07-17 00:58:47,891] console                           [Info] # An error report file with more information is saved as:
[2014-07-17 00:58:47,891] console                           [Info] # e:\TeamCity\bin\hs_err_pid1708.log
[2014-07-17 00:58:48,813] ProcessCommand                    [Info] Process exited with code: 1
[2014-07-17 00:58:48,907] ServiceExecuteProcessTask        [Error] Service process exited without service stop request



When I check the hs_err_pid1708.log I see the following:
#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 740352 bytes for Chunk::new
# Possible reasons:
#   The system is out of physical RAM or swap space
#   In 32 bit mode, the process size limit was hit
# Possible solutions:
#   Reduce memory load on the system
#   Increase physical memory or swap space
#   Check if swap backing store is full
#   Use 64 bit Java on a 64 bit OS
#   Decrease Java heap size (-Xmx/-Xms)
#   Decrease number of Java threads
#   Decrease Java thread stack sizes (-Xss)
#   Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
#  Out of Memory Error (allocation.cpp:323), pid=1708, tid=1912
#
# JRE version: Java(TM) SE Runtime Environment (7.0_51-b13) (build 1.7.0_51-b13)
# Java VM: Java HotSpot(TM) Server VM (24.51-b03 mixed mode windows-x86 )
# Failed to write core dump.
#


...

---------------  S Y S T E M  ---------------

OS: Windows Server 2008 , 64 bit Build 6002 Service Pack 2

CPU:total 2 (1 cores per cpu, 1 threads per core) family 6 model 37 stepping 1, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, popcnt, aes, tsc, tscinvbit

Memory: 4k page, physical 4192860k(1103504k free), swap 8641004k(5246196k free)

vm_info: Java HotSpot(TM) Server VM (24.51-b03) for windows-x86 JRE (1.7.0_51-b13), built on Dec 18 2013 19:04:14 by "java_re" with unknown MS VC++:1600

time: Thu Jul 17 00:58:47 2014
elapsed time: 55401 seconds
0
Comment actions Permalink

We've downloaded logs and investigating, thanks. For the future you can send files to teamcity-feedback@jetbrains.com.

0
Comment actions Permalink

Please try to decrease the java heap size -Xmx600m and add the following server JVM option: -XX:+HeapDumpOnOutOfMemoryError to get memory dump. If server crashes again, please attach java_xxx.hprof file from process startup directory <TeamCity home>/bin (for more details read this section).

0
Comment actions Permalink

It continues to crash with the same error, and I only get the following longs in my bin directory "hs_err_pid8040.log". I don't see any logls like what you describe below.

0
Comment actions Permalink

Matt,

The crash that you see does not come from running TeamCity server, but from Java virtual machine that hosts the server.

It does not say that application (TeamCity) has used up all heap memory (set with -Xmx). It says that JVM failed to obtain a contiguous chunk of memory from OS (to increase the heap size within limits)

If you try to further decrease -Xmx value, you will probably will get rid of "There is insufficient memory for the Java Runtime Environment to continue." message. But for the production server we recommend having -Xmx=750m at least (see this documentation for details), so it is not really an option.


So it seems, you need to optimize memory usage of your box. Maybe reduce memory limit for IIS, or move some services to another machines.

0

Please sign in to leave a comment.