Intermittent get failures V10

[IanG]

Hi,
We have just upgraded to V10.0.0 and are now getting intermitent get failures in our nightly build process:
We have a script that uses the cmd line client to retrive the latest code before building it overnight.
We have now had several instances for the get failing with errors like this:

Code: Select all

<vault>
  <error>
    <exception>System.UnauthorizedAccessException: Access to the path 'C:\Users\codebuilder\AppData\Local\Temp\vaulte382cfd3-2cff-4a7a-99a0-2603ab66d485' is denied.
   at VaultClientIntegrationLib.GetOperations.ProcessCommandGetToLocationOutsideWorkingFolder(String[] objectPaths, GetOptions getOptions, String destPath)
   at VaultCmdLineClient.VaultCmdLineClient.ProcessCommand(Args curArg)
   at VaultCmdLineClient.VaultCmdLineClient.Main(String[] args)</exception>
  </error>
  <result>
    <success>False</success>
  </result>
</vault>

It is not consistent, sometimes the same get will work successfully, we build 3 different branches every night and the get might fail for any one of them or none!
If it was consistent I would suspect a permissions issue but i cant see how it could be that if sometimes it works?
Any suggestions?
Ian.

[Beth]

If you look in the Temp folder of the path you posted, there should be a Vault error log for the command-line client. The name will start with Vault. Do you see one?

If you don't see an error log, then instructions for setting up logging are in this KB article: viewtopic.php?p=5375.

Can you tell me if the errors happen on all projects or just particular ones?

[IanG]

The command line log (VaultCLC.txt) contains lots of instances of this:

Code: Select all

21/04/2017 19:02:31 <generic>: [System.NullReferenceException: Object reference not set to an instance of an object.
   at VaultClientOperationsLib.ClientInstance.IsCheckedOutByMeOnThisMachine(VaultClientFile file, VaultClientCheckOutItem& checkOutItem, VaultClientCheckOutUser& checkOutUser)
   at VaultClientOperationsLib.ClientInstance.IsCheckedOutByMeOnThisMachine(VaultClientFile file)
   at VaultClientOperationsLib.WorkingFolder.GetStatusForSingleFile(VaultClientFile file, Boolean& isModified, Boolean& exists, String& strAbsoluteFilename)
   at VaultClientOperationsLib.WorkingFolder.GetStatus(VaultClientFile file, Boolean& isModified, Boolean& exists, String& strAbsoluteFilename)
   at VaultClientOperationsLib.WorkingFolder.GetStatus(VaultClientFile file)
   at VaultClientOperationsLib.ClientInstance.MakeChangeSetItemForKnownChange(VaultClientFile file, WorkingFolder wf, Boolean ignoreCheckedOutFiles)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_Folder(VaultClientFolder folder, Hashtable alreadySearchedFolderPaths, Boolean recursive)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Boolean notifyChangeSetItemsChanged)] Object reference not set to an instance of an object.
   at VaultClientOperationsLib.ClientInstance.IsCheckedOutByMeOnThisMachine(VaultClientFile file, VaultClientCheckOutItem& checkOutItem, VaultClientCheckOutUser& checkOutUser)
   at VaultClientOperationsLib.ClientInstance.IsCheckedOutByMeOnThisMachine(VaultClientFile file)
   at VaultClientOperationsLib.WorkingFolder.GetStatusForSingleFile(VaultClientFile file, Boolean& isModified, Boolean& exists, String& strAbsoluteFilename)
   at VaultClientOperationsLib.WorkingFolder.GetStatus(VaultClientFile file, Boolean& isModified, Boolean& exists, String& strAbsoluteFilename)
   at VaultClientOperationsLib.WorkingFolder.GetStatus(VaultClientFile file)
   at VaultClientOperationsLib.ClientInstance.MakeChangeSetItemForKnownChange(VaultClientFile file, WorkingFolder wf, Boolean ignoreCheckedOutFiles)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_Folder(VaultClientFolder folder, Hashtable alreadySearchedFolderPaths, Boolean recursive)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Boolean notifyChangeSetItemsChanged)

Stack Trace:
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Boolean notifyChangeSetItemsChanged)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Object notifyChangeSetItemsChanged)
   at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(_ThreadPoolWaitCallback tpWaitCallBack)
   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state)

However when I look in detail the last entry is from before we upgraded...
The VaultVisipClient.txt log for is massive (600 MB) and contains lots of entries like this:

Code: Select all

27/09/2017 12:50:31 <generic>:     [System.ArgumentException: Value does not fall within the expected range.
   at Microsoft.VisualStudio.OLE.Interop.IPropertyBag.Read(String pszPropName, Object& pVar, IErrorLog pErrorLog, UInt32 VARTYPE, Object pUnkObj)
   at SourceGearLLC.VaultVsipClient.VaultVsipClient.ReadSolutionProps_Implementation(IVsHierarchy pHierarchy, String pszProjectName, String pszProjectMk, String pszKey, Int32 fPreLoad, IPropertyBag pPropBag) in E:\Builds\Vault10.0.0.x_Nightly\vault\src\VaultVsipClient\VaultVsipClient.IVsPersistSolutionProps.cs:line 437] Value does not fall within the expected range.
   at Microsoft.VisualStudio.OLE.Interop.IPropertyBag.Read(String pszPropName, Object& pVar, IErrorLog pErrorLog, UInt32 VARTYPE, Object pUnkObj)
   at SourceGearLLC.VaultVsipClient.VaultVsipClient.ReadSolutionProps_Implementation(IVsHierarchy pHierarchy, String pszProjectName, String pszProjectMk, String pszKey, Int32 fPreLoad, IPropertyBag pPropBag) in E:\Builds\Vault10.0.0.x_Nightly\vault\src\VaultVsipClient\VaultVsipClient.IVsPersistSolutionProps.cs:line 437

Stack Trace:
   at SourceGearLLC.VaultVsipClient.VaultVsipClient.ReadSolutionProps_Implementation(IVsHierarchy pHierarchy, String pszProjectName, String pszProjectMk, String pszKey, Int32 fPreLoad, IPropertyBag pPropBag)
   at SourceGearLLC.VaultVsipClient.VaultVsipClient.ReadSolutionProps(IVsHierarchy pHierarchy, String pszProjectName, String pszProjectMk, String pszKey, Int32 fPreLoad, IPropertyBag pPropBag)

As to which projects, it happens sometimes to any project, so sometimes a project will work other times it will fail there does not appear to be any pattern.
Ian.

[IanG]

I have enabled logging as per the linked article, and zipped the existing log files so new clean ones will be created when the build process runs tonight.

Ian.

[Beth]

The CLC logging is from April, and the VSIP log shouldn't be related to the command-line client.

Is logging set to "all"? If so, try to run the CLC Get commands manually from a command prompt. Then I would like to see the full log file. If you attach it here, you'll be able to remove it when we're done, or you can send it to support at sourcegear.com with a link to this thread.

[IanG]

Hi Beth,
we have been running with the logging turned on for a few days now, unfortunately we have been unable to recreate the original issue, we are seeing a different issue.
Now when the process runs to retrieve the files to build the code some files fail to download and the build fails.

In one of the logfiles we repeatedly see items like this:

Code: Select all

03/10/2017 02:11:15 <generic>: [System.NullReferenceException: Object reference not set to an instance of an object.
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_Folder(VaultClientFolder folder, Hashtable alreadySearchedFolderPaths, Boolean recursive)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Boolean notifyChangeSetItemsChanged)] Object reference not set to an instance of an object.
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_Folder(VaultClientFolder folder, Hashtable alreadySearchedFolderPaths, Boolean recursive)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Boolean notifyChangeSetItemsChanged)

Stack Trace:
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Boolean notifyChangeSetItemsChanged)
   at VaultClientOperationsLib.ClientInstance.UpdateKnownChanges_All(Object notifyChangeSetItemsChanged)
   at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(_ThreadPoolWaitCallback tpWaitCallBack)
   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state)

We have had to turn logging back off in order to stand a chance of having the build work, intermittent failures are better than constant failures.
Any idea where we go from here?

[Beth]

Could you send me your Vault server log found on the Vault server at %windir%\temp\sgvault\sgvault.log, and your Vault command line client log to support at sourcegear.com with a link to this thread?

[IanG]

Hi Beth,
OK I've emailed you the requested log files.
Ian.

[Beth]

I have received the email and respond directly.

HS: 249194

[IanG]

With lots of help from Beth and after lots of tests, we have discovered that we were experiencing two different problems, the get failures during our build process were being caused by the System Watcher component of Kaspersky Endpoint Security V10.
With this enabled the get of the code was failing after approximately 50 minutes with it disabled the get succeeds in approximately 3.5 mins!
So that problem is now fixed by turning off the System Watcher componet on the build machine.
We are also experiencing an issue when a get with wildcards that throws an exception, which happens whether Kaspersky is on or off which was confusing our troubleshooting.
I thought it would be a good idea to record the outcome here in case anyone else is having similar issues.
Ian.

[Beth]

Thanks for posting this information.