File to Tape Backup Error

[Princes]

Case # 00821241

Have an issue similar to that discussed in the "File to tape from Mac OS SMB share" thread on here, however it is subtly different.

I have created a File to Tape Backup Job pointing to a Backup Copy Job repository as a source (since you cannot create a Backup to Tape job for a Copy Job), specifying a Full Backup to a Weekly Media Pool and an Incremental to a Daily Media Pool. It runs the first time it is created without problems and backs up everything as expected. However the next time it is run, I get the following error:

Code: Select all

13/03/2015 01:30:08 :: Job started at 13/03/2015 01:30:06 
13/03/2015 01:30:10 :: Building file tree 
13/03/2015 01:30:12 :: Unable to enumerate files in folder Y:\<folder name>\<repository name> 
13/03/2015 01:30:12 :: All file system objects were skipped 
13/03/2015 01:30:12 :: No new files to backup per job settings 
13/03/2015 01:30:12 :: Job finished with error at 13/03/2015 01:30:12

In fact, in testing, it seems that all File to Tape Copy Jobs that I configure in this way will always consistently fail the second time they are run. This even happens if I use other repositories or other files and folders as a target for the backup. If I clone the job and re-run it, it works fine again - though once again only for that first run. If I run it again, it will always fail the second time.

In the job log folder, the log file for the job contains the following SQL related error:

Code: Select all

13.03.2015 01:30:11] <01> Info     Bulk copy Complete, executing stored procedure
[13.03.2015 01:30:12] <01> Error    Cannot drop the table '#batch_get_last_table', because it does not exist or you do not have permission. (System.Data.SqlClient.SqlException)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning()
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String methodName, Boolean async)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
[13.03.2015 01:30:12] <01> Error       at Veeam.Backup.DBManager.CDbConnectionImpl.ExecuteNonQuery(String query, CommandType commandType, SqlParameter[] parameters)
[13.03.2015 01:30:12] <01> Error       at Veeam.Backup.DBManager.CPersistentDbConnection.ExecuteNonQuery(String query, CommandType commandType)
[13.03.2015 01:30:12] <01> Error       at Veeam.Tape.Database.CTempTable.Dispose()
[13.03.2015 01:30:12] <01> Error    Cannot resolve the collation conflict between "SQL_Latin1_General_CP1_CI_AS" and "Latin1_General_CI_AS" in the equal to operation. (System.Data.SqlClient.SqlException)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning()
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlDataReader.ConsumeMetaData()
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlDataReader.get_MetaData()
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
[13.03.2015 01:30:12] <01> Error       at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
[13.03.2015 01:30:12] <01> Error       at Veeam.Backup.DBManager.CDbConnectionImpl.ExecDataReader(String spName, Nullable`1 timeout, SqlParameter[] spParams)
[13.03.2015 01:30:12] <01> Error       at Veeam.Backup.DBManager.CPersistentDbConnection.ExecDataReaderWithTimeout(String spName, Nullable`1 timeout, SqlParameter[] spParams)
[13.03.2015 01:30:12] <01> Error       at Veeam.Tape.Core.CatalogueFileVersionRepository.BatchFindLastNotCorrupted(CBatchFindLastNotCorruptedFileVersionRecord[] tapeFileRecords, Guid backupId)
[13.03.2015 01:30:12] <01> Error       at Veeam.Tape.Core.CIncrementalLastWriteTimeFilter.FilterFileFsItems(Guid backupHostId, TapeFsItem2Process[] fsItems)
[13.03.2015 01:30:12] <01> Error       at Veeam.Tape.Core.CIncrementalLastWriteTimeFilter.Filter(Guid backupHostId, IEnumerable`1 fsItems)
[13.03.2015 01:30:12] <01> Error       at Veeam.Tape.Core.CTapeFileSystemEnumerator2.EnumDirectoryRecursiveOnWindows(CatalogueHost tapeHost, VolumeWithCreds volume, FileSystemItemInfo directoryInfo, BackupSelectionMasks masks, CWinFileCommander winFileCommander)
[13.03.2015 01:30:12] <01> Error       at Veeam.Tape.Core.CTapeFileSystemEnumerator2.EnumRootDirectories(VolumeWithCreds volume, BackupSelection selection)
[13.03.2015 01:30:12] <01> Info     No new files to backup per job settings

Veeam Support have identified that the SQL 2008 R2 Express instance that is currently being used by Veeam B&R for the "VeeamBackup" database, is set to "Latin1_General_CI_AS" collation as its system default. However the "VeeamBackup" database itself is set to "SQL_Latin1_General_CP1_CI_AS" as its database specific collation. They have suggested that I install another instance of SQL 2008 R2 Express on the same server using the "SQL_Latin1_General_CP1_CI_AS" the default system collation and move the database there. Whilst I am happy to try this to resolve the issue, it seems a bit 'messy' and means that I will now have to monitor and backup Veeam databases from two different instances of SQL Express (since the Veeam Enterprise Manager database is also on the same instance).

Interestingly, the Veeam Enterprise Manager used the default SQL 2008 R2 collation of "Latin1_General_CI_AS" without any issues. I have looked at converting the "VeeamBackup" database to use this system default collation, however the process is complex and not without an element of risk in introducing further issues (since I do not understand how the "VeeamBackup" database has been designed and so various assumptions concerning the conversion process would need to be made, and you know what they say about making assumptions in IT.....).

This instance of Veeam has been upgraded in place several times from an earlier version (v6 through to v8) over the years we have been using the product. Earlier versions used to install SQL 2005 Express. This was then uninstalled and upgraded when later versions of Veeam were released, to the current SQL 2008 R2 Express. I believe the most recent builds of Veeam now use SQL 2012 Express as well. What I suspect has happened is that earlier SQL Express instances were installed by Veeam with "SQL_Latin1_General_CP1_CI_AS" as the default collation. The original "VeeamBackup" database was then created on that instance when Veeam B&R was first installed and inherited that default collation. Later versions of SQL Express now use "Latin1_General_CI_AS" as default (which is now the recommended default system collation to use I believe since the Windows based ones are now seen as preferable and less trouble that the older, depreciated SQL specific collations). However, I suspect the upgrade process only moved the database (probably detached and reattached) when the latest build of SQL Express was installed, and did not state that the default system collation of the new instance should remain compatible with the legacy "VeeamBackup" database specific collation.

Is anyone experiencing the same job issues or has had any issues with collation conflicts between SQL Express instance and database?

[Dima P.]

James,
Thank you for the detailed explanation of you issue. I’ll share this post and your case with QA and DEV teams, so they could investigate the root of the issue and then find for a proper resolution, so once again thank you for sharing.

By the way since v8 you can use backup copy job as a source for backup to tape – give it a try, your problem could go away.

[Princes]

Thanks,

I'll give the Backup to Tape job a try - I was always of the belief you couldn't use a copy job repository as a source in this context, so I'll re-examine the functionality. I'll let you know the outcome.

James.

[veremin]

I was always of the belief you couldn't use a copy job repository as a source in this context

It was the case with version 7, but that has been changed in version 8 and now you can use backup copy job as a source for a backup to tape job.

[daveuu]

Hi James, thanks for post. I had the same issue when trying to add files from new VEB jobs to an file to tape job containing existing backup files, although my database and server collations were the opposite way around to yours.

[16.09.2015 08:52:18] <01> Error Cannot resolve the collation conflict between "Latin1_General_CI_AS" and "SQL_Latin1_General_CP1_CI_AS" in the equal to operation. (System.Data.SqlClient.SqlException)

Unfortunately, I don't have the Backup to tape option available in my edition. I installed a new SQL Express 2014 instance as Latin1_General_CI_AS to match my database for Veeam B&R and moved the databases. It appears to work.

Cheers
Dave

[Emortalz]

We currently have the exact same error as above, where our files to tape jobs have an error enumerating files in folders.
We hit the sql express limit of 4GB so we moved it to a full version of SQL 2012 and now we have the enumerating errors on all our file to tape jobs.

Looking at the logs we have the following:

Code: Select all

[19.10.2015 15:05:20] <01> Info     Building records
[19.10.2015 15:05:20] <01> Info     Records built, trying to find last uncorrupted file version for each
[19.10.2015 15:05:20] <01> Info     Executing bulk copy operation on table #batch_get_last_table
[19.10.2015 15:05:20] <01> Info     Bulk copy Complete, executing stored procedure
[19.10.2015 15:05:33] <01> Error    Cannot drop the table '#batch_get_last_table', because it does not exist or you do not have permission. (System.Data.SqlClient.SqlException)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String methodName, Boolean async, Int32 timeout, Boolean asyncWrite)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
[19.10.2015 15:05:33] <01> Error       at Veeam.Backup.DBManager.CDbConnectionImpl.ExecuteNonQuery(String query, CommandType commandType, SqlParameter[] parameters)
[19.10.2015 15:05:33] <01> Error       at Veeam.Backup.DBManager.CPersistentDbConnection.ExecuteNonQuery(String query, CommandType commandType)
[19.10.2015 15:05:33] <01> Error       at Veeam.Tape.Database.CTempTable.Dispose()
[b][19.10.2015 15:05:33] <01> Error    Cannot resolve the collation conflict between "SQL_Latin1_General_CP1_CI_AS" and "Latin1_General_CI_AS" in the equal to operation. (System.Data.SqlClient.SqlException)[/b]
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlDataReader.get_MetaData()
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean asyncWrite)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
[19.10.2015 15:05:33] <01> Error       at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
[19.10.2015 15:05:33] <01> Error       at Veeam.Backup.DBManager.CDbConnectionImpl.ExecDataReader(String spName, Nullable`1 timeout, SqlParameter[] spParams)
[19.10.2015 15:05:33] <01> Error       at Veeam.Backup.DBManager.CPersistentDbConnection.ExecDataReaderWithTimeout(String spName, Nullable`1 timeout, SqlParameter[] spParams)
[19.10.2015 15:05:33] <01> Error       at Veeam.Tape.Core.CatalogueFileVersionRepository.BatchFindLastNotCorrupted(CBatchFindLastNotCorruptedFileVersionRecord[] tapeFileRecords, Guid backupId)
[19.10.2015 15:05:33] <01> Error       at Veeam.Tape.Core.CIncrementalLastWriteTimeFilter.FilterFileFsItems(Guid backupHostId, TapeFsItem2Process[] fsItems)
[19.10.2015 15:05:33] <01> Error       at Veeam.Tape.Core.CIncrementalLastWriteTimeFilter.Filter(Guid backupHostId, IEnumerable`1 fsItems)
[19.10.2015 15:05:33] <01> Error       at Veeam.Tape.Core.CTapeFileSystemEnumerator2.EnumDirectoryRecursiveOnWindows(CatalogueHost tapeHost, VolumeWithCreds volume, FileSystemItemInfo directoryInfo, BackupSelectionMasks masks, CWinFileCommander winFileCommander)
[19.10.2015 15:05:33] <01> Error       at Veeam.Tape.Core.CTapeFileSystemEnumerator2.EnumRootDirectories(VolumeWithCreds volume, BackupSelection selection)

This version of veeam was also upgraded several times since version 6 or even earlier.

Is there a fix for this? As we cant do incremental jobs to tape, only active fulls.

[mattdwyerva]

Just adding my case to this list of failures.
Case # 01208285

One curious note below is "Not a valid Win32 filetime", although that message is after the failure to enumerate. Perhaps the failure to enumerate resulted in software routine being handed a null filetime. 2008R2 server. Local drive. Files were copied using robocopy to this location.

Log:

Code: Select all

[03.12.2015 11:11:10] <01> Info     [BAK] [FC] Enumerating items in directory 'G:\BackupOldLBVA', searchMask '*.*', recursive 'True'
[03.12.2015 11:11:22] <01> Error    [BAK] Failed to enumerate files in directory G:\BackupOldLBVA\ (System.Exception)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CProxyFileCommander.EnumFiles(String dirPath, String searchMask, Boolean recursive, Boolean needDirSize, CancellationToken cancellationToken)
[03.12.2015 11:11:22] <01> Error       at Veeam.Tape.Core.CTapeFileSystemEnumerator2.EnumDirectoryRecursiveOnWindows(CatalogueHost tapeHost, VolumeWithCreds volume, FileSystemItemInfo directoryInfo, BackupSelectionMasks masks, CWinFileCommander winFileCommander)
[03.12.2015 11:11:22] <01> Error       at Veeam.Tape.Core.CTapeFileSystemEnumerator2.EnumRootDirectories(VolumeWithCreds volume, BackupSelection selection)
[03.12.2015 11:11:22] <01> Error    Failed to get next files. Current position '0'. (Veeam.Backup.Common.CRegeneratedTraceException)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.Common.CExceptionUtil.RegenTraceExc(Exception originalExc, String formatString, Object[] args)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CEnumFilesRecursive.Next()
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CProxyFileCommander.EnumFiles(String dirPath, String searchMask, Boolean recursive, Boolean needDirSize, CancellationToken cancellationToken)
[03.12.2015 11:11:22] <01> Error    Failed to get files info from host. SearchId: '1' MaxItemsNum: '1024'. (Veeam.Backup.Common.CRegeneratedTraceException)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.Common.CExceptionUtil.RegenTraceExc(Exception originalExc, String formatString, Object[] args)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CEnumFilesRecursive.FetchFromServer()
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CEnumFilesRecursive.Next()
[03.12.2015 11:11:22] <01> Error    Not a valid Win32 FileTime.
[03.12.2015 11:11:22] <01> Error    Parameter name: fileTime (System.ArgumentOutOfRangeException)
[03.12.2015 11:11:22] <01> Error       at System.DateTime.FromFileTimeUtc(Int64 fileTime)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CDeployerFsItemInfo.UnSerialize(XmlNode node)
[03.12.2015 11:11:22] <01> Error       at Veeam.Backup.ProxyProvider.CEnumFilesRecursive.FetchFromServer()
[03.12.2015 11:11:22] <01> Info     No new files to backup per job settings
[03.12.2015 11:11:22] <01> Info     [Session] AuxData '<TapeAuxData><TapeLibrary Name="QUANTUM ULTRIUM 5" /><SessionStarterInfo Version="1" UserName="SYSTEM" UserDomainName="NT AUTHORITY" RunManually="True" /></TapeAuxData>'
[03.12.2015 11:11:22] <01> Info     [JobSession] New OriginalSessionId is 'e37d0428-fd32-46fd-a155-2c79e986ffd8'
[03.12.2015 11:11:22] <01> Info     Job has been stopped successfully. Name: [Archives2Tape], JobId: [63ddcfc0-10db-41bc-a09f-6882e6575b41]

[mattdwyerva]

Well, it works fine if the local disk source is an old 1TB WD Passport usb drive connected to the VBR server. It can't enumerate the 30 TB raid array however.

Could it be a question of disk types, or cluster size, or 2TB limit??

[veremin]

How the said device is connected to the tape server? And how it's added to the source of file to tape job?

[mattdwyerva]

The raid array is attached with a Dell PERC H700. The WD MyPassport 0740 is external attached with USB. The Quantum LTO-5 tape drive is attached to a separate Adaptec scsi card. All are "physically" connected to the VBR server. Support reports that the number of files on the raid array being copied is too high (900K). Since failure is instant, I am skeptical.

I also wondered if I could install LTFS and try doing the copy using ROBOCOPY instead of VBR, or if installing LTFS will interfere with VBR's normal tape functions. RoboCopy has a nice log file, but no restore functions of course, so limited. I have never tried LTFS, but I could try it and see.

[mattdwyerva]

Support helped me, so I will try to paraphrase what I think I learned... (1) my source has millions of files on it, that number of files is overwhelming (crashing) the VBR FileCopy SQL queries, (2) the number of files implies many small files and will be very slow to copy to tape if we ever get SQL to calm down, (3) copying files from physical server to tape is not a virtual backup problem, so use Endpoint Protection (VEB) to create a VBK file instead and then move the VBK to tape.

Of course, I am already using VEB to give me a vbk related to basic drives (C/D) on this server now and do not want to add archives onto that, but I could use windows backup server process instead of VEB for the basic drives. I wish VEB allowed multiple jobs .

Meanwhile, I did manage to start a job using FIle Copy to Tape for a partial directory that contained 720 GB and about 1.5 million (?) files from the old slower USB drive and NOT from the newer, speedy Raid-5 array (job failed to enumerate from the array). I find this interesting (altho trying something once is not statistically significant) - maybe the speed of the usb drive reduced the pace of sql inserts? After about 13 hours, it is 85% done, at 13 MB/s. Given that the same system moves a 750 GB syn full VBK to tape every day in 2 hours and 9 minutes, this is at least 6 times slower than usual. As support said, it will be very slow if I ever get it to work because of the nature of small file copies. I only need to do this tape job once a month or so, as this is backing up archives only, so I am not as constrained by low speeds as if this were production. Still, I have plans to archive additional files, so ... this could be a problem soon. I will test LTFS.

[Dima P.]

my source has millions of files on it

True story – the design was to reach maximum performance while backing up large files. I wish the we had the upcoming version available now – we made lots of improvements and I hope you can test it once it goes public.

I wish VEB allowed multiple jobs

I do have your request in mind