CruiceControl .NET fails to get modifications

If you are having a problem using Vault, post a message here.

Moderator: SourceGear

Post Reply
espenalb
Posts: 11
Joined: Wed Aug 31, 2005 2:02 am

CruiceControl .NET fails to get modifications

Post by espenalb » Thu Nov 16, 2006 8:11 am

We are using CCNet 1.1.0.2527 and vault client 3.5.1.4786.

We are having problems with the CCNet integration because modifications are not returned the second time around. Here are some details from our ccnet.log:

2006-11-15 17:01:12,417 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:01:12 PM
2006-11-15 17:01:25,385 [FarmManagement:INFO] No modifications detected.
2006-11-15 17:02:25,432 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:02:25 PM
2006-11-15 17:02:39,557 [FarmManagement:INFO] Retrieving detailed change list for $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:02:25 PM
2006-11-15 17:02:55,667 [FarmManagement:INFO] 13 modifications detected.
2006-11-15 17:02:55,682 [FarmManagement:INFO] The most recent modification at 11/15/2006 5:02:12 PM is within in the modification delay. Waiting for 286.6 seconds until 11/15/2006 5:07:12 PM before checking again.
2006-11-15 17:05:53,417 [Mercatus.Common:INFO] Checking for modifications to $/Mercatus/Common in Vault Repository "Default Repository" between 11/15/2006 11:27:40 AM and 11/15/2006 5:05:53 PM
2006-11-15 17:06:07,839 [Mercatus.Common:INFO] Checking for modifications to $/3rdParty in Vault Repository "Default Repository" between 11/15/2006 11:27:40 AM and 11/15/2006 5:05:53 PM
2006-11-15 17:06:22,620 [Mercatus.Common:INFO] No modifications detected.
2006-11-15 17:07:42,260 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:07:42 PM
2006-11-15 17:08:00,323 [FarmManagement:INFO] Retrieving detailed change list for $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:07:42 PM
2006-11-15 17:08:18,339 [FarmManagement:INFO] 15 modifications detected.
2006-11-15 17:08:18,339 [FarmManagement:INFO] The most recent modification at 11/15/2006 5:07:25 PM is within in the modification delay. Waiting for 282.7 seconds until 11/15/2006 5:12:25 PM before checking again.
2006-11-15 17:11:22,651 [Mercatus.Common:INFO] Checking for modifications to $/Mercatus/Common in Vault Repository "Default Repository" between 11/15/2006 11:27:40 AM and 11/15/2006 5:11:22 PM
2006-11-15 17:11:38,635 [Mercatus.Common:INFO] Checking for modifications to $/3rdParty in Vault Repository "Default Repository" between 11/15/2006 11:27:40 AM and 11/15/2006 5:11:22 PM
2006-11-15 17:11:52,995 [Mercatus.Common:INFO] No modifications detected.
2006-11-15 17:13:01,089 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:13:01 PM
2006-11-15 17:13:15,760 [FarmManagement:INFO] No modifications detected.
2006-11-15 17:14:15,807 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:14:15 PM
2006-11-15 17:14:30,448 [FarmManagement:INFO] No modifications detected.
2006-11-15 17:15:30,495 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/15/2006 4:20:02 PM and 11/15/2006 5:15:30 PM
2006-11-15 17:15:44,792 [FarmManagement:INFO] No modifications detected.

As you can see - no build was triggered. We do not know if this is a bug in CCNet or the vault. Any feedback would be great...

ian_sg
Posts: 787
Joined: Wed May 04, 2005 10:55 am
Location: SourceGear
Contact:

Post by ian_sg » Thu Nov 16, 2006 9:40 am

My first guess is that there's an issue with the modificationDelaySeconds setting.

If I remember correctly, that setting is intended for source control providers that don't allow atomic commits; it requires a certain amount of "quiet" in the repository before starting a build. It's possible there's a CCNET bug there, in its interaction with Vault. We've been committing Vault-related changes to that project, so we can look into it, but I can't promise a time frame now.

In the mean time, as a workaround, try removing the modification delay completely, if possible. Vault does support atomic commits, so strictly speaking it shouldn't be necessary.

It's also important that your CCNET machine and the Vault SQL Server machine have synchronized clocks, particularly if your polling interval is very short. People sometimes see changes fail to trigger a build for this reason. But I'd try removing the modification delay setting first, if you can.
Ian Olsen
SourceGear

espenalb
Posts: 11
Joined: Wed Aug 31, 2005 2:02 am

Still fails with modificationDelay=0

Post by espenalb » Thu Nov 23, 2006 6:05 am

CCNet logs this warning:
2006-11-23 12:57:52,790 [FarmManagement:WARN] Item history returned no changes. Version history is supposed to determine if changes exist. This is usually caused by clock skew between the CC.NET server and the Vault server.

But our clocks are synchronized.

This is the "complete" log from FinalBuilder:

2006-11-23 12:57:12,958 [FarmManagement:INFO] Checking for modifications to $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/23/2006 12:48:29 PM and 11/23/2006 12:56:08 PM
2006-11-23 12:57:12,958 [FarmManagement:DEBUG] Executing process C:\Program Files\SourceGear\Vault Client\vault.exe versionhistory $/Applications/FarmManagement -beginversion 10328 -rowlimit 1 -host vault -user **** -password **** -repository "Default Repository" in c:\FinalBuilder\CruiceControl\FarmManagement\WorkingDirectory
2006-11-23 12:57:12,958 [FarmManagement:DEBUG] Attempting to start process [C:\Program Files\SourceGear\Vault Client\vault.exe] in working directory [c:\FinalBuilder\CruiceControl\FarmManagement\WorkingDirectory] with arguments [versionhistory $/Applications/FarmManagement -beginversion 10328 -rowlimit 1 -host vault -user **** -password **** -repository "Default Repository"]
2006-11-23 12:57:31,430 [3984:DEBUG] <vault>
2006-11-23 12:57:31,430 [3984:DEBUG] <history>
2006-11-23 12:57:31,430 [3984:DEBUG] <item version="10328" date="11/23/2006 12:56:13 PM" user="Espen" comment="Disabled the IIS Reset action" txid="67563" />
2006-11-23 12:57:31,430 [3984:DEBUG] </history>
2006-11-23 12:57:31,430 [3984:DEBUG] <result success="yes" />
2006-11-23 12:57:31,430 [3984:DEBUG] </vault>
2006-11-23 12:57:31,461 [FarmManagement:DEBUG] Most recent folder version: 10328
2006-11-23 12:57:31,461 [FarmManagement:DEBUG] Most recent TxID: 67563
2006-11-23 12:57:31,461 [FarmManagement:DEBUG] The folder has changed.
2006-11-23 12:57:31,461 [FarmManagement:INFO] Retrieving detailed change list for $/Applications/FarmManagement in Vault Repository "Default Repository" between 11/23/2006 12:48:29 PM and 11/23/2006 12:56:08 PM
2006-11-23 12:57:31,461 [FarmManagement:DEBUG] Vault History command: FileName: [C:\Program Files\SourceGear\Vault Client\vault.exe] -- Arguments: [history $/Applications/FarmManagement -excludeactions label,obliterate -rowlimit 0 -begindate 2006-11-23T12:48:29 -enddate 2006-11-23T12:56:08 -host vault -user **** -password **** -repository "Default Repository"] -- WorkingDirectory: [c:\FinalBuilder\CruiceControl\FarmManagement\WorkingDirectory] -- StandardInputContent: [] -- Timeout: [120000]
2006-11-23 12:57:31,461 [FarmManagement:DEBUG] Executing process C:\Program Files\SourceGear\Vault Client\vault.exe history $/Applications/FarmManagement -excludeactions label,obliterate -rowlimit 0 -begindate 2006-11-23T12:48:29 -enddate 2006-11-23T12:56:08 -host vault -user **** -password **** -repository "Default Repository" in c:\FinalBuilder\CruiceControl\FarmManagement\WorkingDirectory
2006-11-23 12:57:31,461 [FarmManagement:DEBUG] Attempting to start process [C:\Program Files\SourceGear\Vault Client\vault.exe] in working directory [c:\FinalBuilder\CruiceControl\FarmManagement\WorkingDirectory] with arguments [history $/Applications/FarmManagement -excludeactions label,obliterate -rowlimit 0 -begindate 2006-11-23T12:48:29 -enddate 2006-11-23T12:56:08 -host vault -user **** -password **** -repository "Default Repository"]
2006-11-23 12:57:52,774 [2976:DEBUG] <vault>
2006-11-23 12:57:52,774 [2976:DEBUG] <history />
2006-11-23 12:57:52,774 [2976:DEBUG] <result success="yes" />
2006-11-23 12:57:52,774 [2976:DEBUG] </vault>
2006-11-23 12:57:52,790 [FarmManagement:WARN] Item history returned no changes. Version history is supposed to determine if changes exist. This is usually caused by clock skew between the CC.NET server and the Vault server.
2006-11-23 12:57:52,790 [FarmManagement:INFO] No modifications detected.

ian_sg
Posts: 787
Joined: Wed May 04, 2005 10:55 am
Location: SourceGear
Contact:

Post by ian_sg » Mon Nov 27, 2006 8:59 am

The error message is a little bit misleading because it's the SQL Server machine and the CC.NET machine whose clocks need to be synchronized.
Ian Olsen
SourceGear

activa
Posts: 16
Joined: Fri Feb 09, 2007 4:53 am

Post by activa » Fri Feb 09, 2007 4:56 am

ian_sg wrote:The error message is a little bit misleading because it's the SQL Server machine and the CC.NET machine whose clocks need to be synchronized.
What's the status of this issue? I also have this problem, and it's a real showstopper...

This is the CCNet log:

Code: Select all

2007-02-09 11:31:36,727 [Lunch.be:INFO] Checking for modifications to $ in Vault Repository "LunchWeb" between 9/02/2007 11:09:22 and 9/02/2007 11:31:36
2007-02-09 11:31:36,727 [Lunch.be:DEBUG] Starting process [C:\Program Files\SourceGear\Vault Client\vault.exe] in working directory [C:\CCDev\Lunch.be] with arguments [versionhistory $ -beginversion 734 -rowlimit 1 -host 192.168.1.10 -user xxx -password xxx -repository LunchWeb]
2007-02-09 11:31:43,987 [Lunch.be:DEBUG] <vault>
2007-02-09 11:31:43,997 [Lunch.be:DEBUG] <history>
2007-02-09 11:31:43,997 [Lunch.be:DEBUG]  <item version="734" date="9/02/2007 12:31:40" user="philippe" txid="2440" />
2007-02-09 11:31:43,997 [Lunch.be:DEBUG] </history>
2007-02-09 11:31:43,997 [Lunch.be:DEBUG] <result success="yes" />
2007-02-09 11:31:43,997 [Lunch.be:DEBUG] </vault>
2007-02-09 11:31:44,007 [Lunch.be:DEBUG] Most recent folder version: 734
2007-02-09 11:31:44,007 [Lunch.be:DEBUG] Most recent TxID: 2440
2007-02-09 11:31:44,007 [Lunch.be:DEBUG] The folder has changed.
2007-02-09 11:31:44,007 [Lunch.be:INFO] Retrieving detailed change list for $ in Vault Repository "LunchWeb" between 9/02/2007 11:09:22 and 9/02/2007 11:31:36
2007-02-09 11:31:44,007 [Lunch.be:DEBUG] Vault History command: FileName: [C:\Program Files\SourceGear\Vault Client\vault.exe] -- Arguments: [history $ -excludeactions label,obliterate -rowlimit 0 -begindate 2007-02-09T11:09:22 -enddate 2007-02-09T11:31:36 -host 192.168.1.10 -user xxx -password xxx -repository LunchWeb] -- WorkingDirectory: [C:\CCDev\Lunch.be] -- StandardInputContent: [] -- Timeout: [120000]
2007-02-09 11:31:44,007 [Lunch.be:DEBUG] Starting process [C:\Program Files\SourceGear\Vault Client\vault.exe] in working directory [C:\CCDev\Lunch.be] with arguments [history $ -excludeactions label,obliterate -rowlimit 0 -begindate 2007-02-09T11:09:22 -enddate 2007-02-09T11:31:36 -host 192.168.1.10 -user xxx -password xxx -repository LunchWeb]
2007-02-09 11:31:53,261 [Lunch.be:DEBUG] <vault>
2007-02-09 11:31:53,271 [Lunch.be:DEBUG] <history />
2007-02-09 11:31:53,271 [Lunch.be:DEBUG] <result success="yes" />
2007-02-09 11:31:53,271 [Lunch.be:DEBUG] </vault>
2007-02-09 11:31:53,291 [Lunch.be:WARN] Item history returned no changes.  Version history is supposed to determine if changes exist.  This is usually caused by clock skew between the CC.NET server and the Vault server.
2007-02-09 11:31:53,291 [Lunch.be:INFO] No modifications detected.
[/code][/quote]

espenalb
Posts: 11
Joined: Wed Aug 31, 2005 2:02 am

Post by espenalb » Fri Feb 09, 2007 7:12 am

If you remove the modificationDelay section from ccnet.config, you can proceed. Of course, this means the developers need to check in _all_ their files at once, but that is good practice anyway...

In my opinion, this feature should be fixed, but for us at least, it is not a showstopper.

activa
Posts: 16
Joined: Fri Feb 09, 2007 4:53 am

Post by activa » Fri Feb 09, 2007 8:02 am

espenalb wrote:If you remove the modificationDelay section from ccnet.config, you can proceed. Of course, this means the developers need to check in _all_ their files at once, but that is good practice anyway...

In my opinion, this feature should be fixed, but for us at least, it is not a showstopper.
I don't have the modificationDelay section in ccnet.config

activa
Posts: 16
Joined: Fri Feb 09, 2007 4:53 am

Post by activa » Fri Feb 09, 2007 8:05 am

espenalb wrote:If you remove the modificationDelay section from ccnet.config, you can proceed. Of course, this means the developers need to check in _all_ their files at once, but that is good practice anyway...

In my opinion, this feature should be fixed, but for us at least, it is not a showstopper.
Regarding the "showstopper": if this problem cannot be resolved, CruiseControl.NET is completely useless, because it won't detect changes to the repository.

ian_sg
Posts: 787
Joined: Wed May 04, 2005 10:55 am
Location: SourceGear
Contact:

Post by ian_sg » Fri Feb 09, 2007 9:09 am

Can you verify that the CC.NET server and the SQL Server's clocks are precisely synchronized? I haven't seen this issue caused by anything but that. Windows has the ability to synchronize it's clock with an external ntp server, which would be the easiest way to to accomplish this. Some people have time synchronization with their a domain controlled set up.
Ian Olsen
SourceGear

activa
Posts: 16
Joined: Fri Feb 09, 2007 4:53 am

Post by activa » Fri Feb 09, 2007 9:12 am

ian_sg wrote:Can you verify that the CC.NET server and the SQL Server's clocks are precisely synchronized? I haven't seen this issue caused by anything but that. Windows has the ability to synchronize it's clock with an external ntp server, which would be the easiest way to to accomplish this. Some people have time synchronization with their a domain controlled set up.
CC.NET, Vault and SQL Server are running on the same physical server...

activa
Posts: 16
Joined: Fri Feb 09, 2007 4:53 am

Post by activa » Fri Feb 09, 2007 9:18 am

FYI, this is the project definition in ccnet.config:

Code: Select all

<cruisecontrol>
	<project>
		<name>Lunch.be</name>
		<labeller type="dateLabeller" />
	    <sourcecontrol type="vault" username="xxx" password="xxx" host="192.168.1.10" repository="LunchWeb" folder="$" autoGetSource="false" workingDirectory="C:\CCDev\Lunch.be" cleanCopy="false" useWorkingDirectory="false" applyLabel="true" />
		<tasks>...</tasks>
		<triggers>
			<intervalTrigger name="continuous" seconds="300" />
		</triggers>
	</project>
...
I have tried every combination of the attribute values for autoGetSource and applyLabel.

ian_sg
Posts: 787
Joined: Wed May 04, 2005 10:55 am
Location: SourceGear
Contact:

Post by ian_sg » Fri Feb 09, 2007 9:37 am

Strange. Does this happen for every single change, or only occasionally?

When it does happen, as in the log above, what are the times shown in item history vs. the time range CCNet is looking for?

Edit to perhaps clarify: Can you retrieve a list of changes you expect CCNet to find, and compare the time on them to the time the log says it's looking for, and report back the results?
Ian Olsen
SourceGear

activa
Posts: 16
Joined: Fri Feb 09, 2007 4:53 am

Post by activa » Fri Feb 09, 2007 9:45 am

CC.NET was running under the local system account, while SQL Server was running as Administrator. I changed the CC.NET service so it will run under the Administrator account, and guess what... It works now. :)

Good to know...

I guess this solves the problem (for now)

tstafney
Posts: 5
Joined: Mon Jul 24, 2006 11:44 am
Contact:

Post by tstafney » Wed May 09, 2007 9:56 pm

If anyone is interested, I believe I found the cause of this problem. I think it is a timezone issue. I noticed that my Vault History was displaying the dates in GMT while everything else in Vault seems to display a timezone adjusted date. This seems like a bug in the history results doesn't it?

Hey activa, running services as Administrator is sorta frowned upon :wink:

Post Reply