Problems with VCS connection and Unable to collect changes

Please try to start server with additional property: -Dteamcity.execution.timeout set to a number of seconds to wait till perforce command is finished. By default it is set to 90 seconds.

Thanks Pavel,

I'll give that a try, and let you know how that goes.

Update:  Under Services, I stopped the TC server I added "-Dteamcity.execution.timeout 600" assuming it's 10 minutes, under the Start parameters.  After I started the TC server, all the the "Timeout exceptions" disappeared however, it's been "Checking for changes" for over 2 hours, and I'm pretty sure the "Unable to collect Changes" exception will occur after a couple more hours.

I'm going to change the timeout duration to 1800, and see if that makes a difference.

You should use the following argument: -Dteamcity.execution.timeout=600 (note the = sign)

Thanks Pavel, I'm going to retry it with the "=" sign with 10 minutes again, and let you know how that goes...

By the way, is there a reason why by default it's 90 seconds?  Is there a performace issue if I make it too long?

Update: It's still taking a long time to Check for Changes... any other thoughts?

Update: Left it running yesterday, it went for over 12 hours and was still checking for chages, so I'm pretty sure it's hung so I stopped it ...

then I got this exception on all my build configs. that used the same VCS:

jetbrains.buildServer.vcs.VcsException: java.lang.InterruptedException
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:178)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:209)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.getCurrentVersion(PerforceConnection.java:262)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceSupport.getCurrentVersion(PerforceSupport.java:366)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.getCurrentVersion(VcsChangesLoader.java:184)
at jetbrains.buildServer.vcs.impl.VcsManagerImpl.getVersionsForAllRoots(VcsManagerImpl.java:149)
at jetbrains.buildServer.vcs.impl.VcsManagerImpl.loadChanges(VcsManagerImpl.java:587)
at jetbrains.buildServer.serverSide.impl.auth.SecuredVcsManager.loadChanges(SecuredVcsManager.java:85)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$3.call(VcsChangesCollectorImpl.java)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$3.call(VcsChangesCollectorImpl.java:2)
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: java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1103)
at jetbrains.buildServer.CommandLineExecutor.waitForProcess(CommandLineExecutor.java:149)
at jetbrains.buildServer.CommandLineExecutor.waitForProcess(CommandLineExecutor.java:132)
at jetbrains.buildServer.buildTriggers.vcs.perforce.P4CommandLineConnection.runP4Command(P4CommandLineConnection.java:47)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:163)
... 14 more
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1103)
at jetbrains.buildServer.CommandLineExecutor.waitForProcess(CommandLineExecutor.java:149)
at jetbrains.buildServer.CommandLineExecutor.waitForProcess(CommandLineExecutor.java:132)
at jetbrains.buildServer.buildTriggers.vcs.perforce.P4CommandLineConnection.runP4Command(P4CommandLineConnection.java:47)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:163)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.runCommand(PerforceConnection.java:209)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceConnection.getCurrentVersion(PerforceConnection.java:262)
at jetbrains.buildServer.buildTriggers.vcs.perforce.PerforceSupport.getCurrentVersion(PerforceSupport.java:366)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.getCurrentVersion(VcsChangesLoader.java:184)
at jetbrains.buildServer.vcs.impl.VcsManagerImpl.getVersionsForAllRoots(VcsManagerImpl.java:149)
at jetbrains.buildServer.vcs.impl.VcsManagerImpl.loadChanges(VcsManagerImpl.java:587)
at jetbrains.buildServer.serverSide.impl.auth.SecuredVcsManager.loadChanges(SecuredVcsManager.java:85)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$3.call(VcsChangesCollectorImpl.java)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$3.call(VcsChangesCollectorImpl.java:2)
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)

TeamCity just launches Perforce command and waits for it execution. If command takes too much time to complete, a timeout may occur. Please try to do the following: enable debug logging (http://www.jetbrains.net/confluence/display/TCD4/Reporting+Issues#ReportingIssues-LoggingEvents) try to reproduce this problem again and submit issue to our tracker (http://jetbrains.net/tracker) with teamcity logs attached.

Thank you, I'll give that a try.

Hello Pavel,

I am using TC 4.5.1 with a Perforce Depot.  All of a sudden, a red warning has appeared next to my build configurations on the main page stating that there are "Problems with VCS Connection".

Under the details, it says "Failed for the root 'root name' #32: Java Heap Space

jetbrains.buildServer.vcs.VcsException: java.lang.OutOfMemoryError: Java heap space
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.loadChanges(VcsChangesLoader.java:26)
at jetbrains.buildServer.vcs.impl.VcsManagerImpl.loadChanges(VcsManagerImpl.java:150)
at jetbrains.buildServer.serverSide.impl.auth.SecuredVcsManager.loadChanges(SecuredVcsManager.java:71)
at jetbrains.buildServer.serverSide.impl.VcsModificationChecker$1.run(VcsModificationChecker.java:18)
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: java.lang.OutOfMemoryError: Java heap space
java.lang.OutOfMemoryError: Java heap space

This happened after the server had been running for about 5 days.  Any ideas how I could solve this problem?  Perhaps increase the size of the java heap in the service parameters when the TC Master is being started?

I don't know if it is related to the OP's timeout issue, but I figured the the thread was similar enough for me to post the problem here rather than create a new thread

Thanks in advance for your help

Hello Hamad,

  Please try increasing Xmx setting for TeamCity's java process as described here . Set it to something like Xmx768m (the default is 512m)

  Hope this helps,
  KIR

Hi!
We use Teamcity 4.5.4 (build 9071), and also have a problem with svn and get an "Unable to collect changes" error, but log differs.
Could you please help?

Here is log:
[14:15:47]: Checking for changes
[14:15:47]:
java.util.concurrent.ExecutionException: jetbrains.buildServer.vcs.VcsException: Problem collecting changes for 'GFTSRV Reporting :: GFTSRV Reporting' : Error collecting changes for VCS root 'svn: https://svngft.in.devexperts.com/GFTREP/trunk' #19
org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[28718, ilina, [GFTSRV-14405] Teamcity and Cruisecontrol support, 1257158739891, 19, 1, 54207_2009/11/02 13:45:40 +0300, 54207, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHANGE_DATE, VCS_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate entry '28718' for key 1; nested exception is com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '28718' for key 1
java.util.concurrent.ExecutionException: jetbrains.buildServer.vcs.VcsException: Problem collecting changes for 'GFTSRV Reporting :: GFTSRV Reporting' : Error collecting changes for VCS root 'svn: https://svngft.in.devexperts.com/GFTREP/trunk' #19
org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[28718, ilina, [GFTSRV-14405] Teamcity and Cruisecontrol support, 1257158739891, 19, 1, 54207_2009/11/02 13:45:40 +0300, 54207, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHANGE_DATE, VCS_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate entry '28718' for key 1; nested exception is com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '28718' for key 1
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:205)
at java.util.concurrent.FutureTask.get(FutureTask.java:80)
at jetbrains.buildServer.serverSide.impl.CancelableTaskHolder.waitForTaskToComplete(CancelableTaskHolder.java:33)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl.doCollectChanges(TopBuildDependencyGraphImpl.java:14)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl.access$000(TopBuildDependencyGraphImpl.java:34)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl$3.run(TopBuildDependencyGraphImpl.java:2)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl$3.run(TopBuildDependencyGraphImpl.java)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl$4.run(TopBuildDependencyGraphImpl.java:1)
at jetbrains.buildServer.serverSide.impl.auth.SecurityContextImpl.runAs(SecurityContextImpl.java:4)
at jetbrains.buildServer.serverSide.impl.auth.SecurityContextImpl.runAsSystem(SecurityContextImpl.java:23)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl.runAsSystem(TopBuildDependencyGraphImpl.java:61)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl.collectChangesForGraph(TopBuildDependencyGraphImpl.java:31)
at jetbrains.buildServer.serverSide.impl.dependency.TopBuildDependencyGraphImpl.collectChangesForGraph(TopBuildDependencyGraphImpl.java:60)
at jetbrains.buildServer.serverSide.impl.BuildChangesCollector.collectChangesForBuild(BuildChangesCollector.java:15)
at jetbrains.buildServer.serverSide.impl.BuildStarter$1.run(BuildStarter.java:1)
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: jetbrains.buildServer.vcs.VcsException: Problem collecting changes for 'GFTSRV Reporting :: GFTSRV Reporting' : Error collecting changes for VCS root 'svn: https://svngft.in.devexperts.com/GFTREP/trunk' #19
org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[28718, ilina, [GFTSRV-14405] Teamcity and Cruisecontrol support, 1257158739891, 19, 1, 54207_2009/11/02 13:45:40 +0300, 54207, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHANGE_DATE, VCS_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate entry '28718' for key 1; nested exception is com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '28718' for key 1
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$ChangesCollectorResultImpl.rethrowIfOurBuildType(VcsChangesCollectorImpl.java:51)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$ChangesCollectorResultImpl.checkNoProblemsInMyBuildTypes(VcsChangesCollectorImpl.java:82)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$ChangesCollectorResultImpl.checkingForChangesFinished(VcsChangesCollectorImpl.java:13)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$1.call(VcsChangesCollectorImpl.java:29)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$1.call(VcsChangesCollectorImpl.java:20)
... 5 more
Caused by: jetbrains.buildServer.vcs.VcsException: Error collecting changes for VCS root 'svn: https://svngft.in.devexperts.com/GFTREP/trunk' #19
org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[28718, ilina, [GFTSRV-14405] Teamcity and Cruisecontrol support, 1257158739891, 19, 1, 54207_2009/11/02 13:45:40 +0300, 54207, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHANGE_DATE, VCS_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate entry '28718' for key 1; nested exception is com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '28718' for key 1
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.loadChangesForRoot(VcsChangesLoader.java:43)
at jetbrains.buildServer.vcs.impl.VcsManagerImpl.loadChanges(VcsManagerImpl.java:252)
at jetbrains.buildServer.serverSide.impl.auth.SecuredVcsManager.loadChanges(SecuredVcsManager.java:29)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$3.call(VcsChangesCollectorImpl.java:2)
at jetbrains.buildServer.vcs.impl.VcsChangesCollectorImpl$3.call(VcsChangesCollectorImpl.java)
... 5 more
Caused by: org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[28718, ilina, [GFTSRV-14405] Teamcity and Cruisecontrol support, 1257158739891, 19, 1, 54207_2009/11/02 13:45:40 +0300, 54207, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHANGE_DATE, VCS_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate entry '28718' for key 1; nested exception is com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '28718' for key 1
at jetbrains.buildServer.serverSide.impl.query.GenericQuery.doExecuteQuery(GenericQuery.java:76)
at jetbrains.buildServer.serverSide.impl.query.GenericQuery.access$100(GenericQuery.java:123)
at jetbrains.buildServer.serverSide.impl.query.GenericQuery$1.run(GenericQuery.java:1)
at jetbrains.buildServer.serverSide.impl.DBFacade$3.doInConnection(DBFacade.java:1)
at jetbrains.buildServer.serverSide.impl.DBFacade$4.doInConnection(DBFacade.java:2)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:341)
at jetbrains.buildServer.serverSide.impl.DBFacade._runSql(DBFacade.java:27)
at jetbrains.buildServer.serverSide.impl.DBFacade.runSql(DBFacade.java:203)
at jetbrains.buildServer.serverSide.impl.query.GenericQuery.execute(GenericQuery.java:45)
at jetbrains.buildServer.serverSide.impl.query.InsertVcsModficationQuery$1.doInTransaction(InsertVcsModficationQuery.java:10)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:128)
at jetbrains.buildServer.serverSide.impl.query.InsertVcsModficationQuery.insert(InsertVcsModficationQuery.java:6)
at jetbrains.buildServer.vcs.impl.DBVcsModificationHistory.persistModification(DBVcsModificationHistory.java:215)
at jetbrains.buildServer.serverSide.impl.auth.SecuredVcsModificationHistory.persistModification(SecuredVcsModificationHistory.java:20)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.persistModification(VcsChangesLoader.java:114)
at jetbrains.buildServer.buildTriggers.vcs.VcsChangesLoader.loadChangesForRoot(VcsChangesLoader.java:172)
... 9 more
Caused by: com.mysql.jdbc.exceptions.MySQLIntegrityConstraintViolationException: Duplicate entry '28718' for key 1
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:931)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2941)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1623)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1715)
at com.mysql.jdbc.Connection.execSQL(Connection.java:3249)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1268)
at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:839)
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
at jetbrains.buildServer.serverSide.impl.query.GenericQuery.doExecuteQuery(GenericQuery.java:94)
... 24 more
[14:15:47]: Build finished

Most likely you have two instances of TeamCity using the same MySQL database.

"Two instances" - you mean two agents? Is it impossible to use the same database with more than one instance?

No I mean you have two TeamCity servers up and running on the same MySQL database.

But we have only one Teamcity server... Are there any other reasons of this error?

Please check again. You have one Tomcat server but more than one TeamCity web application. There are no other reasons of this error. Please check how TeamCity web application is deployed to your Tomcat. What is the content of webapps directory in Tomcat?

Pavel,

This problem was finded exactly after first installation of our corporate server. It is impossible that we have two tomcat application with one tomcat instance.

We are planning to move to new version and I want to try to resolve this problem with mysql access. I'll do clear installation and then install upgrade the existing teamcity installation.

Alexey

Well, it is impossible to obtain this exception without more than one instance of TeamCity
Could you please explain how TeamCity is installed? Did you use .exe or .war? In case of war, please check you do not have a situation when there is a 'teamcity.war' in webapps directory and unpacked war in the directory with name different from 'teamcity'. Also please take a look or attach here teamcity-server.log from your server.

Pavel,

Could you please correct our virtual host configuration. You was right we have two instances.


<Host name="teamcity.company.com">
    <Context path="" docBase="${catalina.home}/virtual/teamcity" debug="5"/>
      </Host>

Thanks a lot.

Alexey

Let's process it in the one thread, please reply to my last question here: http://www.jetbrains.net/devnet/message/5249844#5249844