Deadlock problems with Vault 3.5 and CruiseControl.NET

everettmuniz · Post by **everettmuniz** » Thu Apr 26, 2007 7:52 am

Vault Version: 3.5.1.4786
Server OS: Windows 2003
SQL Version: 2000
IIS Version: 6

We're running CruiseControl.NET with about 10 build projects. We have a team of 3 developers.

Prior to our upgrade to 3.5, builds were failing pretty frequently due to a Vault error when the build kicked off. We tracked this down to a deadlock error much like the one shown below. After the upgrade to 3.5 there was about 3 weeks where we were deadlock free. More recently the "deadlock" errors are back in force.

The following is taken directly from our server log for yesterday...

System.Data.SqlClient.SqlException: Transaction (Process ID 53) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
at VaultServiceSQL.VaultSqlSystem.LoginUser(VaultSqlConn conn, String strLogin, String strDbHashPwd, Guid& gSession) at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
at VaultServiceSQL.VaultSqlSystem.LoginUser(VaultSqlConn conn, String strLogin, String strDbHashPwd, Guid& gSession)

I'm assuming this occurs in the midst of login b/c it is consistently followed by...

Login failed: FailDBUpdate

...and, of course, the stack trace seems to strongly suggest the same thing.

Any help on this is MUCH appreciated.

Post by **jclausius** » Thu Apr 26, 2007 8:37 am

This was resolved in Vault 3.5.2. See Vault 3.5.2 Release Notes for more information.

everettmuniz · Post by **everettmuniz** » Mon May 07, 2007 2:53 pm

I've upgraded to Vault 3.5.2 and the errors in the log have indeed gone away but the errors in CCNET have not.

The relevant portion of the exception seems to be...

Source control operation failed: . Process command: vault.exe history $/Projects/GBS.CourtSuite/Trunk/ -excludeactions label -rowlimit 0 -begindate 2007-05-07T16:35:37 -enddate 2007-05-07T16:42:19 -host #censored# -user #censored# -password #censored# -repository #censored#

I'm not sure if this is important but the Vault server, CCNET and the Vault database all run on the same system.

If I manually force the build it seems to be fine but having to manually force the build sort of defeats the purpose

.

Post by **jclausius** » Tue May 08, 2007 7:34 am

When you force the build are you doing it while logged into the machine hosting CC.NET and Vault?

everettmuniz · Post by **everettmuniz** » Tue May 08, 2007 8:08 am

I've used the 'Force Build' option from the CCNET web interface while logged into the machine hosting CCNET and Vault. However, I've also done it from my PC via the web interface and the winforms interface (monitoring app that comes with CCNET).

Post by **jclausius** » Tue May 08, 2007 8:18 am

If someone was logged in on the CC.NET and Vault Server, I'm wondering if the problem lies in some kind of Windows Security or permissions problems.

What Windows Account would CC.NET run under? Under what process would the Vault command line client be launched? Does the Vault CLC have permissions to all the folders it will be using under that Windows Account to find its local cache information and other supporting files?

everettmuniz · Post by **everettmuniz** » Tue May 08, 2007 9:36 am

I hear your point but the permissions angle doesn't seem to fit the gradually degenerative nature of the problem.

When I first installed 3.5.2 everything was fine for about a week as it was when I installed the last update and then after about a week or so the issue began to occur. It started with the 'exception' status on just a few CCNET projects durring the course of the day and now over the course of a day they'll all enter the 'exception' status with the message I posted yesterday being the visible message in CCNET.

It seems like if it were permissions the CCNET/Vault integration wouldn't work at all.

Is there any additional logging I can turn on?

everettmuniz · Post by **everettmuniz** » Tue May 08, 2007 10:03 am

I was just poking around on the build server and was reminded of the CCNET server log. Among other things, the CCNET server log records the results of calls to vault.exe and I found a number of instances of the following...

<vault>
<error>
The connection to the server failed: server cannot be contacted or uses a protocol that is not supported by this client. System.Web.Services.Protocols.SoapException: Server was unable to process request. ---> System.InvalidCastException: Specified cast is not valid.
at VaultServiceSQL.VaultSqlSystem.GetLoginInfo(VaultSqlConn conn, String strLogin, String strHostname, String strSessionID, VaultUser vu, String& strDbHashPwd, Int32& nAttempts)
at VaultServiceAPILib.VaultServiceAPI.AuthenticateAndLogin(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, VaultUser vu, Guid& gSessionGUID, Int32& nValidUserAttempts)
at VaultServiceAPILib.VaultServiceAPI.Login(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, String& strToken, VaultUser& vu, Int32& nValidUserAttempts)
at VaultServiceAPILib.VaultServiceAPISystem.DoLogin(Boolean bAdminLogin, HttpApplicationState has, HttpSessionState hss, String strHostname, Boolean bUseFullFiles, String strLogin, String strPassword, String strRMKey, String& strAuthToken)
at VaultService.VaultService.Login(String strHostname, Boolean bUseFullFiles, String username, String strEncryptedPassword, String strRMKey, String& strAuthToken)
--- End of inner exception stack trace ---
</error>
<exception>
System.Exception: The connection to the server failed: server cannot be contacted or uses a protocol that is not supported by this client. System.Web.Services.Protocols.SoapException: Server was unable to process request. ---> System.InvalidCastException: Specified cast is not valid.
at VaultServiceSQL.VaultSqlSystem.GetLoginInfo(VaultSqlConn conn, String strLogin, String strHostname, String strSessionID, VaultUser vu, String& strDbHashPwd, Int32& nAttempts)
at VaultServiceAPILib.VaultServiceAPI.AuthenticateAndLogin(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, VaultUser vu, Guid& gSessionGUID, Int32& nValidUserAttempts)
at VaultServiceAPILib.VaultServiceAPI.Login(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, String& strToken, VaultUser& vu, Int32& nValidUserAttempts)
at VaultServiceAPILib.VaultServiceAPISystem.DoLogin(Boolean bAdminLogin, HttpApplicationState has, HttpSessionState hss, String strHostname, Boolean bUseFullFiles, String strLogin, String strPassword, String strRMKey, String& strAuthToken)
at VaultService.VaultService.Login(String strHostname, Boolean bUseFullFiles, String username, String strEncryptedPassword, String strRMKey, String& strAuthToken)
--- End of inner exception stack trace ---
at VaultCmdLineClient.VaultCmdLineClient.Login(Boolean bAllowAuto, Boolean bSaveSession)
at VaultCmdLineClient.VaultCmdLineClient.ProcessCommandHistory(String strReposPath)
at VaultCmdLineClient.VaultCmdLineClient.ProcessCommand(Args curArg)
at VaultCmdLineClient.VaultCmdLineClient.Main(String[] args)
</exception>
<result success="no" />
</vault>

Post by **jclausius** » Tue May 08, 2007 10:27 am

Look at the properties for vault.exe. Is it 3.5.2.5087? Is there another vault.exe on the path? How about configuring CC.NET to use the absolute path to vault.exe.

everettmuniz · Post by **everettmuniz** » Tue May 08, 2007 10:40 am

As for the multiple instances of vault issue, I did a

Code: Select all

dir /s vault.exe

from the command line while in the root directory (i.e. '\') of the only drive on the box and got...

Code: Select all

 Volume in drive C has no label.
 Volume Serial Number is 3471-512E

 Directory of C:\Program Files\SourceGear\Vault Client

04/21/2007  05:15 AM           143,360 vault.exe
               1 File(s)        143,360 bytes

     Total Files Listed:
               1 File(s)        143,360 bytes
               0 Dir(s)   7,448,570,880 bytes free

The version on C:\Program Files\SourceGear\Vault Client\vault.exe is 3.5.2.5087.

The location of vault.exe is not supplied in the CCNET config (it's assumed to be on the path as you surmised) so I'll try adding the full path to vault.exe in the CCNET config to rule out the possability that there is an out-of-date instance of vault.exe on the path that isn't being identified when I execute the 'dir /s'.

everettmuniz · Post by **everettmuniz** » Tue May 08, 2007 11:10 am

Ok, made the change to CCNET config but it doesn't appear to have effected the error. This is a section of the CCNET log from after the change. I've included a bit more to illustrate that the path change truly did take effect.

5/8/2007 12:46:58 PM: [GBS.CourtSuite-CS:Error]: Exception: Source control operation failed: . Process command: C:\Program Files\SourceGear\Vault Client\vault.exe history $/Projects/GBS.CourtSuite/Trunk/ -excludeactions label -rowlimit 0 -begindate 2007-05-07T20:21:19 -enddate 2007-05-08T12:46:20 -host #censored# -user #censored# -password #censored# -repository #censored#
----------
ThoughtWorks.CruiseControl.Core.CruiseControlException: Source control operation failed: . Process command: C:\Program Files\SourceGear\Vault Client\vault.exe history $/Projects/GBS.CourtSuite/Trunk/ -excludeactions label -rowlimit 0 -begindate 2007-05-07T20:21:19 -enddate 2007-05-08T12:46:20 -host #censored# -user #censored# -password #censored# -repository #censored#
at ...
----------

5/8/2007 12:46:58 PM: [GBS.CourtSuite-CS:Info]: Integration complete: 5/8/2007 12:46:58 PM
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: <vault>
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: <error>
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: The connection to the server failed: server cannot be contacted or uses a protocol that is not supported by this client. System.Web.Services.Protocols.SoapException: Server was unable to process request. ---> System.InvalidCastException: Specified cast is not valid.
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceSQL.VaultSqlSystem.GetLoginInfo(VaultSqlConn conn, String strLogin, String strHostname, String strSessionID, VaultUser vu, String& strDbHashPwd, Int32& nAttempts)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceAPILib.VaultServiceAPI.AuthenticateAndLogin(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, VaultUser vu, Guid& gSessionGUID, Int32& nValidUserAttempts)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceAPILib.VaultServiceAPI.Login(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, String& strToken, VaultUser& vu, Int32& nValidUserAttempts)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceAPILib.VaultServiceAPISystem.DoLogin(Boolean bAdminLogin, HttpApplicationState has, HttpSessionState hss, String strHostname, Boolean bUseFullFiles, String strLogin, String strPassword, String strRMKey, String& strAuthToken)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultService.VaultService.Login(String strHostname, Boolean bUseFullFiles, String username, String strEncryptedPassword, String strRMKey, String& strAuthToken)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: --- End of inner exception stack trace ---
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: </error>
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: <exception>
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: System.Exception: The connection to the server failed: server cannot be contacted or uses a protocol that is not supported by this client. System.Web.Services.Protocols.SoapException: Server was unable to process request. ---> System.InvalidCastException: Specified cast is not valid.
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceSQL.VaultSqlSystem.GetLoginInfo(VaultSqlConn conn, String strLogin, String strHostname, String strSessionID, VaultUser vu, String& strDbHashPwd, Int32& nAttempts)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceAPILib.VaultServiceAPI.AuthenticateAndLogin(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, VaultUser vu, Guid& gSessionGUID, Int32& nValidUserAttempts)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceAPILib.VaultServiceAPI.Login(VaultSqlConn conn, String strLogin, String strDecryptedPassword, String strHostname, String strSessionID, String& strToken, VaultUser& vu, Int32& nValidUserAttempts)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultServiceAPILib.VaultServiceAPISystem.DoLogin(Boolean bAdminLogin, HttpApplicationState has, HttpSessionState hss, String strHostname, Boolean bUseFullFiles, String strLogin, String strPassword, String strRMKey, String& strAuthToken)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultService.VaultService.Login(String strHostname, Boolean bUseFullFiles, String username, String strEncryptedPassword, String strRMKey, String& strAuthToken)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: --- End of inner exception stack trace ---
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultCmdLineClient.VaultCmdLineClient.Login(Boolean bAllowAuto, Boolean bSaveSession)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultCmdLineClient.VaultCmdLineClient.ProcessCommandHistory(String strReposPath)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultCmdLineClient.VaultCmdLineClient.ProcessCommand(Args curArg)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: at VaultCmdLineClient.VaultCmdLineClient.Main(String[] args)
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: </exception>
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: <result success="no" />
5/8/2007 12:47:00 PM: [CruiseControl Server:Debug]: </vault>

Post by **jclausius** » Tue May 08, 2007 11:18 am

OK. If we have the correct version, then the client cannot contact the server.

When you run the history command from a command prompt when logged on to that same machine, everything works, is that correct?

If so, then let's try something else. Instead of a hostname, use "-host localhost". Let's see if that has any effect.

everettmuniz · Post by **everettmuniz** » Tue May 08, 2007 12:11 pm

The closest I can get to '-host localhost' is to use the IP of the web site. This system also has a few low traffic development web sites on it so the adapter has an IP address setup for each site. Then in IIS we associate the IP with the specified site.

So, I've switched to use the IP and the issue continues to occur.

Post by **jclausius** » Tue May 08, 2007 12:37 pm

jclausius wrote:When you run the history command from a command prompt when logged on to that same machine, everything works, is that correct?

What we need to do is isolate the problem. Once we have the problem isolated, then it is just a matter of finding the resolution.

I'm trying to figure out if the problem is the launched vault.exe process is not finding the server. Could you set up a test server on a different machine and give it a try with that server's hostname?