Error collecting changes for VCS root

This can happen if you have more than one TeamCity web application pointing to the same database.

I have only one teamcity web application.

Could you please provide teamcity-server.log and please list the content of the webapps directory of your Tomcat (if you are using this servlet container).

Here is a part from the log (I can't post the whole log, but these are the pertinent lines).
Note that there are multiple errors with "Cannot find build promotion with ID 11" but I don't think these are related.
We have many projects on this installation, but the others don't show this error, but they do show duplicate lines in the change log.

[2009-10-01 11:40:18,698]   WARN -      jetbrains.buildServer.VCS - Unable to collect changes for [Test dist-all]
jetbrains.buildServer.vcs.VcsException: Error collecting changes for VCS root 'svn: file:///repositories/Test/trunk' #1
org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[1087, test user, exclude  projects from test dist, 1254386383386
, 1, 1, 152_2009/10/01 11:39:44 +0300, 152, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHANGE_DATE, VC
S_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate entry '108
7' for key 1; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1087' 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.serverSide.impl.VcsModificationChecker$1.run(VcsModificationChecker.java:11)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
Caused by: org.springframework.jdbc.UncategorizedSQLException: Error executing query with params:[1087, test user, exclude  projects from test dist, 12
54386383386, 1, 1, 152_2009/10/01 11:39:44 +0300, 152, 1]; uncategorized SQLException for SQL [INSERT INTO vcs_history (MODIFICATION_ID, USER_NAME, DESCRIPTION, CHAN
GE_DATE, VCS_ROOT_ID, VCS_ROOT_VERSION, VERSION, DISPLAY_VERSION, CHANGES_COUNT) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)]; SQL state [23000]; error code [1062]; Duplicate
entry '1087' for key 1; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1087' 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.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1087' for key 1
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
        at com.mysql.jdbc.Util.getInstance(Util.java:381)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3515)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3447)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1951)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2101)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2554)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1761)
        at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1017)
        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
[2009-10-01 11:41:03,125]   WARN -   jetbrains.buildServer.SERVER - Failed to load finished build instance: Cannot find build promotion with ID 11
[2009-10-01 11:41:03,126]   WARN -   jetbrains.buildServer.SERVER - Failed to load finished build instance: Cannot find build promotion with ID 7

Here are the webapp contents

[root@teamcity teamcity]# ls webapps/
ROOT
[root@teamcity teamcity]# ls webapps/ROOT/
admin                     buildTypeStatistics.jsp         filesPopup.jsp                    nifty                     runBuildFromChange.jsp
agent                     buildTypeStatusDiv.jsp          filterByTag.jsp                   notificationRuleForm.jsp  runCustomBuild.jsp
agentDetails.jsp          buildTypeTable.jsp              footer.jsp                        notificationRuleIds.jsp   runtimeError.jsp
agentInfoDiv.jsp          buildTypeTests.jsp              img                               notificationRules.jsp     showVcsRoots.jsp
agentsInfoDiv.jsp         busy.jsp                        includeExtensionFromJspPath.jspf  notifierSettings.jsp      simpleView.jsp
agents.jsp                changeBlock.jsp                 include-internal.jsp              notImplemented.jsp        specifyAdmin.jsp
agentsList.jsp            changedFile.jsp                 include.jsp                       overview.jsp              status
agentsRunningBlock.jsp    changePopupRow.jspf             index.jsp                         pageReload.jsp            test.jsp
agentStatus.jsp           changesPopup.jsp                installLinks.jspf                 pendingChangesDiv.jsp     tests
allProjects.jsp           changesSinceLastSuccessful.jsp  jamon                             plugins                   tracker.jsp
artifactsViewer.jsp       compatibilityList.jsp           js                                profile                   unauthorizedAgentsList.jsp
BUILD_9071                createAdmin.jsp                 license                           project                   unregisteredAgentsList.jsp
buildChanges.jsp          css                             login.jsp                         projectBuildTypes.jsp     update
buildLog                  customGraphs.jsp                META-INF                          project.jsp               userChangeInfo.jsp
buildResultsSummary.jsp   diffView.jsp                    modificationListTable.jsp         projectTests.jsp          vcsProblems.jsp
buildTypeChangeLog.jsp    editBuildTypePopup.jsp          moreToStop.jsp                    queue                     vcsSettings.jsp
buildTypeHistoryList.jsp  favicon20.ico                   myChangesBuild.jsp                registerUser.jsp          viewType.jsp
buildTypeSettings.jsp     favicon3.ico                    myChanges.jsp                     rolesDescription.jsp      visibleProjectsDialog.jsp
buildTypesList.jsp        favicon4.ico                    myChangesList.jsp                 rowClassChooser.jsp       WEB-INF

Could you please connect to your mysql server and list available connections: show processlist
Please check that the number of connections corresponds to the value written in the .BuildServer/config/database.properties file (by default this is 50)

There are 6 connections currently.

| 7345 | teamcity | localhost:57149 | teamcity | Sleep   |    1 |       | NULL             |
| 7347 | teamcity | localhost:57152 | teamcity | Sleep   |    8 |       | NULL             |
| 7348 | teamcity | localhost:57157 | teamcity | Sleep   |   18 |       | NULL             |
| 7349 | teamcity | localhost:57158 | teamcity | Sleep   |    1 |       | NULL             |
| 7350 | teamcity | localhost:48615 | teamcity | Sleep   |   12 |       | NULL             |
| 7351 | teamcity | localhost:60150 | teamcity | Sleep   |   12 |       | NULL             |

The config value for max connections is 50.

Here is a query log for when an update was made (maybe this log snippet contains the queries form an earlier update also, update id 1102). It complained about the unique id 1103, which shows a couple of inserts in the log (with different comments).
Where dows teamcity get this id?

I'm having the exact same problem.  For what it's worth, I'm using TeamCity 4.5.5 (build 9103) and MySQL 5.0.51a, running on an Ubuntu 8.04 LTS server.  We're connecting to an AccuRev server that's running version 4.7.2a.

I also see six active connections from TeamCity to MySQL, and have a maxConnections of 50 in the properties file.

Under our current configuration, we have multiple Projects that each have their own VCS root, and each project has multiple build configurations (as many as about 25, in one case) that use that shared VCS root.  My current theory is that when TeamCity tries to check for updates for those build configurations, the AccuRev plugin is somehow stepping on top of itself by trying to run mutiple concurrent updates of a single VCS root... but that's just a guess.

Actually, that theory can probably be disregarded, because I saw it happen for a project that only had one build configuration...

Could you please send teamcity-server.log file to teamcity-feedback[at]jetbrains.com?

Please send teamcity-server.log file to teamcity-feedback[at]jetbrains.com

Ok, I'll do that.
The current log is over 90mb so I'll restart the server and when I get the same behaviour I'll send the log. Do you want me to increse the log-level, it seems to be WARN at the moment?
I have the old log file saved in case it is needed.

I've took a look at the file you send to the email. From the file it is clear that you have several instances of the TeamCity web application started. Try to search for the line: "Starting TeamCity server", within the time between 10:05:22 - 10:05:29 this line appears three times...

Log file has been sent.

We also recently noticed that we had accidentally created our teamcity database as a MyISAM database when we meant to use InnoDB; we tried altering the tables to use the InnoDB engine instead, but that seems to have caused some other problems.  We just started setting up this server and it isn't heavily used yet, so we're probably going to drop the database and set it up from scratch to see if our problems go away.

I see that, but I'm honestly not sure how that's possible; we deployed TeamCity into a running Tomcat server, and I only see one instance of the TeamCity application in Tomcat's manager.  Is there some config file setting I should check?

What version of Tomcat do yo use?

We're using Tomcat 6.0.20.

There were some bugs in previous Tomcat versions that could cause such problems, but I beleive in 6.0.20 they are already fixed.
How did you deploy TeamCity? Did you simply put war file into the webapps folder? If so, try to create webapps/ROOT directory and unpack war file into it. Then remove all teamcity wars from the webapps.

I think I've managed to figure out what was going wrong.  I had a virtual host defined in Tomcat's config that had the same webapps path as the default host, and Tomcat was creating instances of each application for each host.  I moved TeamCity's virtual host to a different root path, and now it seems to only be starting one instance.

Thanks for your effort on this.
For me also the problem was with multiple running instances.

I had a <Context> element in my server.xml that pointed to the teamcity-app and apparently because of that the app was deployed twice.
I needed to specify path="/teamcity" for the context because this installation can't be accessed directly from "/".

A better way to do this is to eg. rename the ROOT context -> teamcity (and I also changed the path in the teamcity app's META-INF/context.xml)

Hi!
We started discussing the same problem here
http://www.jetbrains.net/devnet/thread/281541?tstart=0

but today I found this topic and checked our teamcity.log. There really are 2 instances (I looked for 'Starting Teamcity' in log and found two such a rows).
But I can't understand how to fix it...

Could you please help? Our server.xml is attached.

What is in the webapps directory of your Tomcat? Do you have TeamCity war and unpacked war in webapps? Can you list content of the webapps directory?

BTW TeamCity 5.0 now checks whether there is another TeamCity 5.0 already running. So I hope this problem will be eliminated in the future.

So what is the content of ${catalina.home}/virtual/teamcity directory?

teamcity application, extracted from war file

Is there another TeamCity application in Tomcat/webapps directory?

There is no other tomcat application in webapps folder

Not sure what is wrong in this case. I would try the following:
- take a look at Tomcat/conf directory and check if there is a Catalina directory, if so try to investigate what contexts are there
- try to comment out <Host name="localhost"/> section

Pavel, we tried to comment out <Host name="localhost"/> section, bit it didn't help. And Catalina directory in Tomcat/conf directory is empty.

Do you have any more ideas about what is the reason that 2 instances of Teamcity works instead of 1 instance?