HELP! Error Branching in Vault

This forum is now locked, since Gold Support is no longer offered.

Moderator: SourceGear

Locked
davenovak
Posts: 222
Joined: Mon Jan 15, 2007 2:15 pm
Location: Atlanta, GA

HELP! Error Branching in Vault

Post by davenovak » Tue May 08, 2007 12:27 pm

Hi --

I'm getting a very strange error when trying to do a simple branch. After about 6 or so minutes of churning, Vault client returns "A database error has occured (FailDBReader)".

Looking at the server log, I see the following error:

Code: Select all

----5/8/2007 11:12:47 AM     buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream)
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at VaultServiceSQL.VaultSqlSCC.BranchFolder(VaultSqlConn conn, String strSessionID, Int32 nRepID, Hashtable htSharedItems, HybridDictionary htTxModifiedItems, Int64 nTxID, Int32 nTxItem, Byte nTxType, VaultDateTime vdTxBegin, String strItemPath, String strNewBranchName, String strXml, BranchingModTime bmt, VaultFolder vfRoot, String strTxComment, Int32& nCopiedSecurityFolderRights, VaultFolder& vfOut)    at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream)
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at VaultServiceSQL.VaultSqlSCC.BranchFolder(VaultSqlConn conn, String strSessionID, Int32 nRepID, Hashtable htSharedItems, HybridDictionary htTxModifiedItems, Int64 nTxID, Int32 nTxItem, Byte nTxType, VaultDateTime vdTxBegin, String strItemPath, String strNewBranchName, String strXml, BranchingModTime bmt, VaultFolder vfRoot, String strTxComment, Int32& nCopiedSecurityFolderRights, VaultFolder& vfOut)
The branch itself is about 500MB and this would be the first time this tree has been branched.

Also, I am using the latest version of Vault Client and Server -- 3.5.2.

Any ideas?


UPDATE: I am able to branch other roots in my repository, just not this root. What's the difference? Not exactly sure, though the other roots have no file or folder shares whereas the root that won't branch has both (though all shares are confined to that root)

Also, I've turned on DEBUG logging. Here's what's in the debug log:

Code: Select all

----5/8/2007 2:24:13 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Login 
----5/8/2007 2:24:13 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetUserOptions returned: Success 
----5/8/2007 2:24:13 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Success 
----5/8/2007 2:24:13 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetRepositories returned: Success 
----5/8/2007 2:24:13 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetUserList returned: Success 
----5/8/2007 2:24:22 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Getting repository Structure-> Rep ID: 4 Base: 157 Target: -1 
----5/8/2007 2:24:22 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager: Filling empty cache with current tree. 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	VaultServiceAPI::GetRepositoryTreeDelta() UserID:3 RepID:4 Base:157 Target:157  Calling VaultRepUtil.DiffRepTrees() - in-memory tree diff. 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetRepositoryStructure returned: Success 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Getting list of checkout changes. 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Beginning SQL transaction 410 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetCheckoutListChanges: Transaction Started 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager: cache matches repository revision and folder security hasn't changed.  Returning cached tree, revID 157 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	VaultServiceAPI::GetCheckoutListChanges() Status:0 UserID:3 RepID:4 FolderSecurity:False BaseList:0 Target List:30 RefreshFlag:True 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	SQL transaction 410 successfully committed. 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetCheckoutListChanges: Transaction Committed 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetCheckOutListChanges returned: Success 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetUserEmailOptions returned Success 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager: cache matches repository revision and folder security hasn't changed.  Returning cached tree, revID 157 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	ListWatchers returned Success 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	ListCloakedObjects returned: Success 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetRepositoryOptions returned: Success 
----5/8/2007 2:24:26 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetRepositories returned: Success 
----5/8/2007 2:24:51 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	BeginTx beginning transaction 
----5/8/2007 2:24:51 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager: cache matches repository revision and folder security hasn't changed.  Returning cached tree, revID 157 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	(a96cb81e-200e-49fb-9ad7-59661c851575) BeginTx returned: Success 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled		(a96cb81e-200e-49fb-9ad7-59661c851575) CopyBranch: $/<ADVERTISEMENT SPAM> 6.3.10 to $/<ADVERTISEMENT SPAM> 6.3.11 returned: Success 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Ending transaction 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Beginning SQL transaction 297 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Attempting to acquire repository lock. 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Acquired repository lock. 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager Signal - Tx Begin - CacheLockId:296 
----5/8/2007 2:24:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager: A transaction is pending, but it belongs to the current user.  Returning cached tree, revID 157 
----5/8/2007 2:30:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream)
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at VaultServiceSQL.VaultSqlSCC.BranchFolder(VaultSqlConn conn, String strSessionID, Int32 nRepID, Hashtable htSharedItems, HybridDictionary htTxModifiedItems, Int64 nTxID, Int32 nTxItem, Byte nTxType, VaultDateTime vdTxBegin, String strItemPath, String strNewBranchName, String strXml, BranchingModTime bmt, VaultFolder vfRoot, String strTxComment, Int32& nCopiedSecurityFolderRights, VaultFolder& vfOut)    at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream)
   at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at VaultServiceSQL.VaultSqlSCC.BranchFolder(VaultSqlConn conn, String strSessionID, Int32 nRepID, Hashtable htSharedItems, HybridDictionary htTxModifiedItems, Int64 nTxID, Int32 nTxItem, Byte nTxType, VaultDateTime vdTxBegin, String strItemPath, String strNewBranchName, String strXml, BranchingModTime bmt, VaultFolder vfRoot, String strTxComment, Int32& nCopiedSecurityFolderRights, VaultFolder& vfOut)
----5/8/2007 2:30:53 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	EndTx(): Failed commit changes for TxID 158 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	SQL transaction 297 successfully rolled back. 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Beginning SQL transaction 438 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	SQL transaction 438 successfully committed. 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager Signal - Tx End   - TxID:158 CacheLockId:296 RepID:4 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Beginning SQL transaction 439 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	SQL transaction 439 successfully committed. 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	(a96cb81e-200e-49fb-9ad7-59661c851575) EndTx (Revision - 0) returned: FailDBReader 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled		(a96cb81e-200e-49fb-9ad7-59661c851575) CopyBranch: $/<ADVERTISEMENT SPAM> 6.3.10 to $/<ADVERTISEMENT SPAM> 6.3.11 returned: FailDBReader 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Getting repository Structure-> Rep ID: 4 Base: 157 Target: -1 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	TreeManager: cache matches repository revision and folder security hasn't changed.  Returning cached tree, revID 157 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	VaultServiceAPI::GetRepositoryTreeDelta() UserID:3 RepID:4 Base:157 Target:157  Calling VaultRepUtil.DiffRepTrees() - in-memory tree diff. 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetRepositoryStructure returned: Success 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Getting list of checkout changes. 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Beginning SQL transaction 462 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetCheckoutListChanges: Transaction Started 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	SQL transaction 462 successfully committed. 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetCheckoutListChanges: Transaction Committed 
----5/8/2007 2:30:55 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	GetCheckOutListChanges returned: Success 
----5/8/2007 2:31:10 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Logout 
----5/8/2007 2:31:10 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	Beginning SQL transaction 482 
----5/8/2007 2:31:10 PM      buildmachine--casinobuild-dev.corp.kazootek.com(127.0.0.1)--SSL Disabled	SQL transaction 482 successfully committed. 

Beth
Posts: 8550
Joined: Wed Jun 21, 2006 8:24 pm
Location: SourceGear
Contact:

Post by Beth » Tue May 08, 2007 3:46 pm

It looks like you are getting a SQL timeout first. Go into your vault.config file and find the SQL timeout setting and add another 0 after it and see if the error goes away.

davenovak
Posts: 222
Joined: Mon Jan 15, 2007 2:15 pm
Location: Atlanta, GA

Post by davenovak » Tue May 08, 2007 3:50 pm

And where is that file? Is that a client or server setting?

Don't you find it odd that a branch would take more than 6 minutes? That's odd in my experience. I tried a test branch on a folder three times that size (in the same repository) and it branched in less than 30 seconds.

davenovak
Posts: 222
Joined: Mon Jan 15, 2007 2:15 pm
Location: Atlanta, GA

Post by davenovak » Tue May 08, 2007 4:24 pm

I found the setting on the server under C:\Inetpub\wwwroot\VaultService. I did as you suggested and the branch completed . . . in about 10 minutes.

Has something changed in Vault 3.5.2 to make branches that much slower? I've never seen a branch that this long under 3.5.1. In fairness, however, this was the first time this root was branched, and I'm guessing there may be some additional "housekeeping" with the first branch.

Any explanation for the long branch time would be appreciated.

Thanks.

jclausius
Posts: 3706
Joined: Tue Dec 16, 2003 1:17 pm
Location: SourceGear
Contact:

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

Actually no. From the Vault 3.5.2 release notes - "Improved performance for folder branch and snapshot."

In our own testing on different types of branches, the new branch code increased performance by over 300%! For example, test branches on older hardware were taking 5+ minutes in Vault 3.5.1. However, with Vault 3.5.2 the branches were benchmarked at less than 40 seconds.

The branch code does make use of some persistent and temporary tables. Is it possible your database had to "grow" to accommodate the stored data the during that branch?

How fragmented are your disk sub systems of sgvault or tempdb fragmented?

What about database maintenance on statistics and indices?

Can you try another test branch? Does it still take 10+ minutes?


At this point, we'll need more information to try to figure out what is going on.
Jeff Clausius
SourceGear

davenovak
Posts: 222
Joined: Mon Jan 15, 2007 2:15 pm
Location: Atlanta, GA

Post by davenovak » Tue May 15, 2007 11:36 am

I had our DBA look at this and he was able to fine-tune some of the database parameters to make this faster. With his new changes in place and the disk and database fully de-fragged, it still takes about 7 minutes to branch, which still seems way too long.

I should point out that this is running on a really nice piece of hardware, with RAID 5, 15K drives, 8 spindles, 800+GB free space, dual dual-core processors, 4GB RAM, and more.

Seems slow to me for an operation that does not create a new copy of the files in the source branch.

jclausius
Posts: 3706
Joined: Tue Dec 16, 2003 1:17 pm
Location: SourceGear
Contact:

Post by jclausius » Tue May 15, 2007 8:03 pm

This does seem like too long. Especially with the changes we made in Vault Server 3.5.2.

If you want, we could take a look at the database repositories w/ out your file data, and see if anything looks out of the ordinary. It's up to you.
Jeff Clausius
SourceGear

Locked