TeamCity7 sometimes doesn't see changes from CVS

Hello,
we have a problem with teamcity 7. Later we had TeamCity version 5 and there weren't such problems. It started when we upgrade our TeamCity.
So, the problem is that teamcity sometimes doesn't see changes from CVS (lost of changes is about 20%). Button "check for pending changes" also doesn't work.

We tried to investigate the problem and found some strange things. For example, we have VCS root id=68.

In teamcity-vcs.log we can see:

[2012-04-03 16:03:09,767]   INFO [TeamCity Agent ] -      jetbrains.buildServer.VCS - Setting build revisions on agent=robot2 {id=8, host=127.0.0.1:9090, agentTypeId=4, pool=Default}, buildPromotion=BuildPromotion{myId=24808, myPersonal=false, myBuildTypeId='bt92', myModificationId=63140, myRevisions=[BuildRevision[myVcsRootEntry=VcsRootEntry[myVcsRoot=cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68}, myCheckoutRules==>
], myRevision=RepositoryVersion[myVersion='2012/04/03 13:40:16 +0400', myDisplayVersion='03 Apr 13:40:15']]], myAssociatedBuildId=21024}, revisions={cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68}=2012/04/03 13:40:16 +0400}
[2012-04-03 16:07:13,574]   INFO [d=669} {id=669}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=669, parent id=30} from state 2012/04/03 16:00:09 +0400 to state 2012/04/03 16:06:59 +0400; 2 changes collected 2 changes reported, time spent: 14s,164ms
[2012-04-03 16:13:07,406]   INFO [TeamCity Agent ] -      jetbrains.buildServer.VCS - Setting build revisions on agent=robot2 {id=8, host=127.0.0.1:9090, agentTypeId=4, pool=Default}, buildPromotion=BuildPromotion{myId=24809, myPersonal=false, myBuildTypeId='bt92', myModificationId=63140, myRevisions=[BuildRevision[myVcsRootEntry=VcsRootEntry[myVcsRoot=cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68}, myCheckoutRules==>
], myRevision=RepositoryVersion[myVersion='2012/04/03 13:40:16 +0400', myDisplayVersion='03 Apr 13:40:15']]], myAssociatedBuildId=21025}, revisions={cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68}=null}
[2012-04-03 16:13:16,761]   INFO [d=669} {id=669}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=669, parent id=30} from state 2012/04/03 16:06:59 +0400 to state 2012/04/03 16:13:13 +0400; 1 changes collected 1 changes reported, time spent: 3s,110ms
[2012-04-03 16:17:18,252]   INFO [1942} {id=1942}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1942, parent id=97} from state 2012/04/03 16:11:39 +0400 to state 2012/04/03 16:16:03 +0400; 0 changes collected 0 changes reported, time spent: 1m:14s,557ms
[2012-04-03 16:17:18,256]   INFO [1885} {id=1885}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1885, parent id=94} from state 2012/04/03 16:11:39 +0400 to state 2012/04/03 16:15:53 +0400; 0 changes collected 0 changes reported, time spent: 1m:24s,562ms
[2012-04-03 16:17:18,259]   INFO [1393} {id=1393}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68} from state 2012/04/03 16:13:03 +0400 to state 2012/04/03 16:16:03 +0400; 0 changes collected 0 changes reported, time spent: 1m:14s,562ms
[2012-04-03 16:17:18,317]   INFO [1316} {id=1316}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1316, parent id=64} from state 2012/04/03 16:09:49 +0400 to state 2012/04/03 16:14:53 +0400; 0 changes collected 0 changes reported, time spent: 2m:24s,632ms
[2012-04-03 16:17:18,375]   INFO [1733} {id=1733}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1733, parent id=86} from state 2012/04/03 16:11:39 +0400 to state 2012/04/03 16:16:03 +0400; 0 changes collected 0 changes reported, time spent: 1m:14s,679ms
[2012-04-03 16:17:38,375]   INFO [TeamCity Agent ] -      jetbrains.buildServer.VCS - Setting build revisions on agent=robot2 {id=8, host=127.0.0.1:9090, agentTypeId=4, pool=Default}, buildPromotion=BuildPromotion{myId=24809, myPersonal=false, myBuildTypeId='bt92', myModificationId=63140, myRevisions=[BuildRevision[myVcsRootEntry=VcsRootEntry[myVcsRoot=cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68}, myCheckoutRules==>
], myRevision=RepositoryVersion[myVersion='2012/04/03 13:40:16 +0400', myDisplayVersion='03 Apr 13:40:15']]], myAssociatedBuildId=21025}, revisions={cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68}=2012/04/03 13:40:16 +0400}
[2012-04-03 16:21:20,715]   INFO [d=669} {id=669}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=669, parent id=30} from state 2012/04/03 16:13:13 +0400 to state 2012/04/03 16:19:18 +0400; 0 changes collected 0 changes reported, time spent: 2m:01s,967ms
[2012-04-03 16:22:20,658]   INFO [1393} {id=1393}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68} from state 2012/04/03 16:16:03 +0400 to state 2012/04/03 16:21:18 +0400; 0 changes collected 0 changes reported, time spent: 1m:01s,890ms
[2012-04-03 16:22:20,741]   INFO [1733} {id=1733}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1733, parent id=86} from state 2012/04/03 16:16:03 +0400 to state 2012/04/03 16:21:18 +0400; 0 changes collected 0 changes reported, time spent: 1m:01s,974ms
[2012-04-03 16:22:20,889]   INFO [1942} {id=1942}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1942, parent id=97} from state 2012/04/03 16:16:03 +0400 to state 2012/04/03 16:21:18 +0400; 0 changes collected 0 changes reported, time spent: 1m:02s,123ms
[2012-04-03 16:22:20,938]   INFO [1885} {id=1885}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1885, parent id=94} from state 2012/04/03 16:15:53 +0400 to state 2012/04/03 16:21:18 +0400; 0 changes collected 0 changes reported, time spent: 1m:02s,172ms
[2012-04-03 16:27:29,251]   INFO [d=669} {id=669}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=669, parent id=30} from state 2012/04/03 16:19:18 +0400 to state 2012/04/03 16:27:23 +0400; 1 changes collected 1 changes reported, time spent: 5s,414ms
[2012-04-03 16:34:42,418]   INFO [1904} {id=1904}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1904, parent id=95} from state 2012/04/03 15:33:58 +0400 to state 2012/04/03 16:34:33 +0400; 1 changes collected 1 changes reported, time spent: 8s,516ms
[2012-04-03 16:34:42,450]   INFO [1847} {id=1847}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1847, parent id=92} from state 2012/04/03 15:36:43 +0400 to state 2012/04/03 16:34:33 +0400; 4 changes collected 4 changes reported, time spent: 8s,548ms
[2012-04-03 16:43:39,730]   INFO [d=162} {id=162}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver {instance id=162, parent id=3} from state 2012/04/03 15:34:25 +0400 to state 2012/04/03 16:42:11 +0400; 6 changes collected 6 changes reported, time spent: 1m:28s,359ms
[2012-04-03 16:54:57,485]   INFO [TeamCity Agent ] -      jetbrains.buildServer.VCS - Setting build revisions on agent=robot2 {id=8, host=127.0.0.1:9090, agentTypeId=4, pool=Default}, buildPromotion=BuildPromotion{myId=24810, myPersonal=false, myBuildTypeId='bt85', myModificationId=63161, myRevisions=[BuildRevision[myVcsRootEntry=VcsRootEntry[myVcsRoot=cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1847, parent id=92}, myCheckoutRules==>
], myRevision=RepositoryVersion[myVersion='2012/04/03 16:13:01 +0400', myDisplayVersion='03 Apr 16:13:00']]], myAssociatedBuildId=21026}, revisions={cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1847, parent id=92}=null}
[2012-04-03 16:58:51,589]   INFO [1942} {id=1942}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1942, parent id=97} from state 2012/04/03 16:53:17 +0400 to state 2012/04/03 16:57:37 +0400; 0 changes collected 0 changes reported, time spent: 1m:14s,023ms
[2012-04-03 16:58:51,591]   INFO [1885} {id=1885}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1885, parent id=94} from state 2012/04/03 16:52:37 +0400 to state 2012/04/03 16:56:57 +0400; 0 changes collected 0 changes reported, time spent: 1m:54s,152ms
[2012-04-03 16:58:51,608]   INFO [1393} {id=1393}] -      jetbrains.buildServer.VCS - Finish collecting changes for cvs: :pserver:robot@cvsserv/Argus TechService\appserver\workspace.argus {instance id=1393, parent id=68} from state 2012/04/03 16:53:17 +0400 to state 2012/04/03 16:57:37 +0400; 0 changes collected 0 changes reported, time spent: 1m:14s,091ms

At 16:58:51 teamcity was looking for changes from 16:53:17, but during previous attempt to find changes teamcity trying to collect changes until 16:21:18. So, changes that were made from  16:21:18 till 16:53:17 were ignored by TeamCity.

Maybe we are wrong in interpreting of log files and our conclusions, but still.


Screenshots of our CVS root:
CVS_root.PNG
CVS_root2.PNG



Please, help =)

2 comments
Comment actions Permalink

The problem is most likely caused by too big quiet period. Please take a look at description of this parameter in our documentation: http://confluence.jetbrains.net/display/TCD7/CVS
Normal value for it should not exceed 10 seconds. Default value 3 seconds should be ok for most of the cases.

Also in TeamCity 7.0.2 we've fixed this issue: http://youtrack.jetbrains.com/issue/TW-20689
Please upgrade your server to the latest version and decrease quiet period.

0
Comment actions Permalink

I had similar problem with TeamCity version 7.0.1 and it was caused by two things

  1. Time between TeamCity and CVS server was not synchronized
  2. JVM had low values of xms and xmx


JF

0

Please sign in to leave a comment.