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:





Please, help =)