9.1.3.90 - Network retention applied to Local retention

PDinCA

ONE of the 11 User databases has started to keep local backup files beyond the 8 days stipulated - more in line with the network retention of 31 days (as in, 25 days and counting). No job changes have occurred (I'm the only DBA). This applies to Full and Diff backups but not TLog backups.
This isn't coincident with the upgrade from 9.0.3 on August 14th - I have files going back to July 25th (it is August 22nd now).
The job execution log shows the network file being deleted, but not the local file.
Ideas, please?

Dan B

Hi PDinCA,

Are you able to provide a copy of the log output from the last job that ran that didn't delete the database files?

Are all 11 databases backed up as part of one job?

PDinCA

You'll see that ERASEFILES = 8 and ERASEFILES_REMOTE = 31. but there is no sign of any "Deleting old backup file: \\je-sofs1\SQLBackup\client_32\DIFF_JE217_client_32_20170824_030000.sqb" in the log.

Of all the databases under SQL Backup's auspices on this server, this is the only one behaving in this way.

Every backup type for every database is in a single-purpose job per DB, e.g., FULL - client_32, DIFF - client_32 and TRAN - client_32 are each separate SQL Agent jobs.

Most databases copy over the network, too, like this one.

We took this DB offline on August 24th, so the jobs are no longer running, but we have the history.

The SECOND Log File is for another DIFF, taken today, on the same SQB version (7.1.3) and its only difference is that the local and remote retentions are the same, and the log INCLUDES the two Delete entries, 1 for local and 1 for remote.

SQL Backup log file 9.1.3.142

-SQL "BACKUP DATABASE [client_32] TO DISK = '\\je-sofs1\SQLBackup\<database>\<AUTO>.sqb' WITH ERASEFILES = 8, ERASEFILES_REMOTE = 31, FILEOPTIONS = 4, CHECKSUM, DISKRETRYINTERVAL = 30, DISKRETRYCOUNT = 10, COMPRESSION = 4, COPYTO = '\\Apollo\ApolloSQLBackup\client_32', INIT, THREADCOUNT = 6, VERIFY, DIFFERENTIAL "

-----------------------  PROCESSES COMPLETED SUCCESSFULLY   --------------------

8/24/2017 3:00:00 AM: Backing up client_32 (differential database) to: 
8/24/2017 3:00:00 AM:   \\je-sofs1\SQLBackup\client_32\DIFF_JE217_client_32_20170824_030000.sqb

8/24/2017 3:00:01 AM: BACKUP DATABASE [client_32]  TO VIRTUAL_DEVICE = 'SQLBACKUP_183D2E26-AAE3-45E9-8504-CE51FF953ADD', VIRTUAL_DEVICE = 'SQLBACKUP_183D2E26-AAE3-45E9-8504-CE51FF953ADD01', VIRTUAL_DEVICE = 'SQLBACKUP_183D2E26-AAE3-45E9-8504-CE51FF953ADD02', VIRTUAL_DEVICE = 'SQLBACKUP_183D2E26-AAE3-45E9-8504-CE51FF953ADD03', VIRTUAL_DEVICE = 'SQLBACKUP_183D2E26-AAE3-45E9-8504-CE51FF953ADD04', VIRTUAL_DEVICE = 'SQLBACKUP_183D2E26-AAE3-45E9-8504-CE51FF953ADD05' WITH BUFFERCOUNT = 30, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (client_32), 8/24/2017 3:00:00 AM', DESCRIPTION = N'Backup on 8/24/2017 3:00:00 AM  Server: JE217  Database: client_32', FORMAT, CHECKSUM, DIFFERENTIAL

8/24/2017 3:00:14 AM: Backup data size    : 476.188 MB
8/24/2017 3:00:14 AM: Compressed data size: 40.732 MB
8/24/2017 3:00:14 AM: Compression rate    : 91.45%

8/24/2017 3:00:14 AM: Processed 58248 pages for database 'client_32', file 'AIO_NEw' on file 1.
8/24/2017 3:00:14 AM: Processed 2 pages for database 'client_32', file 'AIO_NEw_log' on file 1.
8/24/2017 3:00:14 AM: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 58250 pages in 8.587 seconds (52.996 MB/sec).
8/24/2017 3:00:16 AM: 
8/24/2017 3:00:16 AM: Verifying files:
8/24/2017 3:00:16 AM:   \\je-sofs1\SQLBackup\client_32\DIFF_JE217_client_32_20170824_030000.sqb
8/24/2017 3:00:16 AM: 
8/24/2017 3:00:16 AM: The backup set on file 1 is valid.
8/24/2017 3:00:17 AM: Copied \\je-sofs1\SQLBackup\client_32\DIFF_JE217_client_32_20170824_030000.sqb to \\Apollo\ApolloSQLBackup\client_32\DIFF_JE217_client_32_20170824_030000.sqb.
8/24/2017 3:00:17 AM: SQL Backup process ended.

8/24/2017 3:00:17 AM: Deleted msdb entries older than 8/10/2017 3:00:17 AM
8/24/2017 3:00:18 AM: Deleted local history entries older than 8/10/2017 3:00:17 AM

Log file 2 - local = 8, remote = 8 - deletions recorded:

SQL Backup log file 9.1.3.142

-SQL "BACKUP DATABASE [client_Perf] TO DISK = '\\je-sofs1\SQLBackup\<database>\<AUTO>.sqb' WITH ERASEFILES = 8, ERASEFILES_REMOTE = 8, FILEOPTIONS = 4, CHECKSUM, DISKRETRYINTERVAL = 30, DISKRETRYCOUNT = 10, COMPRESSION = 4, COPYTO = '\\Apollo\ApolloSQLBackup\client_Perf', INIT, THREADCOUNT = 6, VERIFY, DIFFERENTIAL "

-----------------------  PROCESSES COMPLETED SUCCESSFULLY   --------------------

8/31/2017 1:30:00 AM: Backing up client_Perf (differential database) to: 
8/31/2017 1:30:00 AM:   \\je-sofs1\SQLBackup\client_Perf\DIFF_JE217_client_Perf_20170831_013000.sqb

8/31/2017 1:30:00 AM: BACKUP DATABASE [client_Perf]  TO VIRTUAL_DEVICE = 'SQLBACKUP_E9A2F532-9FA7-4CB3-9C07-FA05FE9FE446', VIRTUAL_DEVICE = 'SQLBACKUP_E9A2F532-9FA7-4CB3-9C07-FA05FE9FE44601', VIRTUAL_DEVICE = 'SQLBACKUP_E9A2F532-9FA7-4CB3-9C07-FA05FE9FE44602', VIRTUAL_DEVICE = 'SQLBACKUP_E9A2F532-9FA7-4CB3-9C07-FA05FE9FE44603', VIRTUAL_DEVICE = 'SQLBACKUP_E9A2F532-9FA7-4CB3-9C07-FA05FE9FE44604', VIRTUAL_DEVICE = 'SQLBACKUP_E9A2F532-9FA7-4CB3-9C07-FA05FE9FE44605' WITH BUFFERCOUNT = 30, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'Database (client_Perf), 8/31/2017 1:30:00 AM', DESCRIPTION = N'Backup on 8/31/2017 1:30:00 AM  Server: JE217  Database: client_Perf', FORMAT, CHECKSUM, DIFFERENTIAL

8/31/2017 5:18:51 AM: Backup data size    : 213.126 GB
8/31/2017 5:18:51 AM: Compressed data size: 126.662 GB
8/31/2017 5:18:51 AM: Compression rate    : 40.57%

8/31/2017 5:18:51 AM: Processed 27929400 pages for database 'client_Perf', file 'AIO_NEw' on file 1.
8/31/2017 5:18:51 AM: Processed 95 pages for database 'client_Perf', file 'AIO_NEw_log' on file 1.
8/31/2017 5:18:51 AM: BACKUP DATABASE WITH DIFFERENTIAL successfully processed 27929495 pages in 13727.948 seconds (15.894 MB/sec).
8/31/2017 5:54:18 AM: 
8/31/2017 5:54:18 AM: Verifying files:
8/31/2017 5:54:18 AM:   \\je-sofs1\SQLBackup\client_Perf\DIFF_JE217_client_Perf_20170831_013000.sqb
8/31/2017 5:54:18 AM: 
8/31/2017 5:54:18 AM: The backup set on file 1 is valid.
8/31/2017 5:54:19 AM: Deleting old backup file: \\je-sofs1\SQLBackup\client_Perf\DIFF_JE217_client_Perf_20170823_013000.sqb
8/31/2017 5:54:19 AM: Deleting old backup file: \\Apollo\ApolloSQLBackup\client_Perf\DIFF_JE217_client_Perf_20170823_013000.sqb
8/31/2017 7:07:35 AM: Copied \\je-sofs1\SQLBackup\client_Perf\DIFF_JE217_client_Perf_20170831_013000.sqb to \\Apollo\ApolloSQLBackup\client_Perf\DIFF_JE217_client_Perf_20170831_013000.sqb.
8/31/2017 7:07:35 AM: SQL Backup process ended.

8/31/2017 7:07:35 AM: Deleted msdb entries older than 8/17/2017 7:07:35 AM
8/31/2017 7:07:35 AM: Deleted local history entries older than 8/17/2017 7:07:35 AM

PDinCA

Perhaps I should add that filling the Activity Log for these (now) 8 online databases has taken longer than putting post above together - i.e., in excess of FIFTEEN MINUTES, which renders the lower pane useless. I closed-out of SQB... SQB is on the local SQL Server, not over the wire to, say, my laptop, so I would expect local speed, which isn't realized.

Dan B

Hi PDinCA,

Are you able to place SQL Backup into debug mode and forward on your debug log please? The instructions for turning on debug mode are below:

For a stand-alone machine:
Stop the SQL Backup Agent Service.
Using the Registry Editor (regedit) locate the following registry key:
For a default SQL Instance - HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\SQLBackupAgent\ImagePath
For a named SQL Instance - HKEYLOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\SQLBackupAgent<SQL Instance_Name>\ImagePath

The ImagePath key has a data value that is the path to the service executable. Modify the ImagePath key and add -sqbdebug flag to the end of path to the SQL Backup Agent executable.

For a default SQL Instance the ImagePath may like similar to this example,
"C:\Program Files\Red Gate\SQL Backup(local)\SQBCoreService.exe"

Modify to add -sqbdebug parameter, so the path becomes,
"C:\Program Files\Red Gate\SQL Backup(local)\SQBCoreService.exe" -sqbdebug

For a named SQL Instance the ImagePath may like similar to this example,
C:\Program Files\Red Gate\SQL Backup<SQL Instance Name>\SQBCoreService.exe -i <SQL Instance Name>
Modify to add -sqbdebug parameter, so the path becomes,
"C:\Program Files\Red Gate\SQL Backup\ <SQL Instance Name>\SQBCoreService.exe -i <SQL Instance Name>" -sqbdebug

Restart the SQL Backup Agent Service.

A log text file called SQBCoreService_log.txt will be created in the Program Files folder, C:\Program Files\Red Gate\SQL Backup(local)\ or C:\Program Files\Red Gate\SQL Backup\ <SQL Instance Name>.
A second log file called SQBCoreServiceCopyManager_log.txt will also be created

Do not open the SQL Backup GUI unless it is really necessary, as this will only add unrequired entries to the log file.

Let the debug mode run for the problem period.

For a Cluster, the steps above still apply, but disable the SQL Backup Cluster Resource in the Cluster Administrator before stopping the SQL Backup Agent Service for the active node of the cluster. Once you have generated the requested file etc, remember to bring backup on line the SQL Backup Cluster resource. This prevents the cluster from failing over when you stop the SQL Backup Agent Service in Step 1 of the above process.

PDinCA

Debug files sent by PM.

Upon completion, I still have files locally going back to August 7th - 30 days ago.

Dan B

Hi PDinCA,

So it looks like The primary backup folder is

'\\je-sofs1\SQLBackup\<database>\<AUTO>.sqb'

and the copy to folder is

'\\Apollo\ApolloSQLBackup\shopko_32''

And you are using both ERASEFILES and ERASEFILES_REMOTE. However, the value for ERASEFILES_REMOTE is used when both the primary and copy to folders are remote folders. To differentiate between the two, use ERASEFILES_PRIMARY and ERASEFILES_SECONDARY instead e.g.

EXEC master..sqlbackup '-SQL "BACKUP DATABASE [shopko_32] TO DISK = [\\je-sofs1\SQLBackup\<database>\<AUTO>.sqb] WITH ERASEFILES_PRIMARY = 8, ERASEFILES_SECONDARY = 31, FILEOPTIONS = 4, CHECKSUM, DISKRETRYINTERVAL = 30, DISKRETRYCOUNT = 10, COMPRESSION = 4, COPYTO = [\\Apollo\ApolloSQLBackup\shopko_32], INIT, THREADCOUNT = 6, VERIFY, DIFFERENTIAL"'

PDinCA

We use a "Storage Spaces" storage appliance. So, because the appliance mount points aren't mapped to drive letters at the server level, we have to use a UNC path, which appears to SQB as a remote location, but is actually local to the SQL Server.

Where in SQB is the ability to change that command parameter to use the _PRIMARY extension?

Perhaps SQB should use ERASEFILES and ERASEFILES_PRIMARY synonymously if we have no UI means of differentiating, and especially for those using a storage appliance, which are becoming more deployed, (even at Microsoft - they use the same appliance, I'm told).

I don't think I'll be visiting all the backup jobs just to change that parameter, BTW. I have no guarantee that if I later use the SQB UI to edit any job, the overrides I painstakingly went through won't be nuked... When recently fully loaded, that server had a dozen or more DBs, each with three scheduled jobs, all using ERASEFILES and most using ERASEFILES_REMOTE.

Requesting an enhancement to SQB to automatically handle, or give the User the option of using, the _PRIMARY command-version as needed. Hand-editing is not a viable workaround.

Dan B

Hi PDinCA,

I have added your request to an existing Bug Report SB-4556. I will update this forum post when I get some further information on this.