Slow Transaction log backup performance
kmadsen@hbham.com
Posts: 23
I am seeing on one server very slow performance for transaction log backups via the extended stored proc. Looking at the generated log file alone the performance looks good one instance the log shows a start time of 8:40:14 and a finish time of 8:40:17 (3 seconds lapsed time), but the file times on the log file and the backup file are 8 minutes different and they are both located on the same drive in the same folder. Logfile Timestamp = 8:46 and the backup file = 8:38am. Now this is backing up to a remote share (100MB Lan) so I would not expect the times in the log file to match exactly the file times, it looks like an 8 minute period between the create f the backup file and the create of the log file. Note: The backup file size is only 11KB. Also looking that the job that runs the transaction log backups it runs as if it was taking 8+ minutes per database while the backup files total only 4MB.
Any ideas?
Any ideas?
Comments
Do you experience this delay only for transaction log backups, and only if using the extended stored proc.? Does using the GUI or command line interface give the same problem?
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
I've sent the link directly to your email address. Sorry for the delay.
The link that I had sent is always the newest version. Older versions are available from a *different* URL. When a new version comes out, we simply append a bit on the end with the old version number.
All that you need to do is run the new install and it should detect the old version and upgrade it. You probably also want to run the 'install stored procedure' utility when it comes up, otherwise, you'll still have the older stored procedure installed on the SQL Server.
Contents of the log file
6/6/2005 5:20:43 PM: SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
6/6/2005 5:20:43 PM:
6/6/2005 5:20:43 PM: Backing up Admin (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050606_172007.TRN ...
6/6/2005 5:20:43 PM:
6/6/2005 5:20:43 PM: BACKUP LOG [Admin] TO DISK = '\\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050606_172007.TRN' WITH NAME = '', DESCRIPTION = '', ERASEFILES = 3, LOGTO = '\\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050606_172007.Log', COMPRESSION = 1
6/6/2005 5:20:43 PM:
6/6/2005 5:20:43 PM:
6/6/2005 5:20:44 PM: Backup data size : 896.000 KB
6/6/2005 5:20:44 PM: Compressed data size: 11.500 KB
6/6/2005 5:20:44 PM: Compression rate : 98.72%
6/6/2005 5:20:50 PM: Process completed successfully.
6/6/2005 5:20:50 PM:
Processed 1 pages for database 'Admin', file 'Admin_Log' on file 1.
BACKUP LOG successfully processed 1 pages in 0.082 seconds (0.099 MB/sec).
(1 row affected)
which shows a time stamp of 5:23pm and the backup file shows a time of 5:19. Note: This is obviously backing up to a network share and the file times are not in sync with the SQL server's time.
I think your right about this being related to backing up over the network. I have not been able to confirm this yet but i would assume that once the last part of the data file is written some verification, not file verification, is occurring and then the file is time stamped.
I would not recommend backing up directly to a network device, unless you have to. My preferred method would be to backup locally and then use the "copyto" option to get the file to the remote drive. Local files can be kept to a minimum by using the "erasefiles" and "erasefiles_atstart" options, and the remote files can be dealt with locally by using robocopy and delete.
This method should also increase the backup time (no network bottle neck), and increase the writing across the network (no backup bottleneck).
Regards
Dan
Red Gate Software Ltd
FYI - Server is a quad 1.4Ghz with an average CPU utilization while backups are occuring of 15-30%.
Sorry I misunderstand. I thought you were saying that the backup takes about 3 seconds to complete, but the timestamp on the remote is different because the remote computer clock is not synced with SQL Server?
Please try my suggested method, but i will attempt to replicate you situation here.
Regards
Dan
Red Gate Software Ltd
1. EXEC master..sqlbackup '-SQL "BACKUP DATABASE CME_TRAIN_GLL TO DISK = ''C:\BACKUPS\DB\<AUTO>'' WITH ERASEFILES=2,COMPRESSION=1, VERIFY" -E"'
the output from this command says: BACKUP DATABASE successfully processed 21009 pages in 2.490 seconds (69.115 MB/sec). But in QA it actually took 10 seconds to execute.
2. backup database CME_TRAIN_GLL to DISK='c:\BACKUPS\DB\CME_TRAIN_GLL_FULL_20050609.BAK' with init
The output from this command says BACKUP DATABASE successfully processed 21009 pages in 5.664 seconds. (30.384 MB/sec) QA says it actually took 6 seconds to execute which is about right.
The SQL Backup version is smaller but it doesn't seem to execute in less time despite what it says.
However, SQL Backup also writes some header data to the file after it has been generated, and some delays are introduced to ensure that the backup file has been fully flushed to disk before the header data is written. To write part of the header, it also needs to login to SQL Server to retrieve the data.
Also, using the ERASEFILES option requires SQL Backup to iterate through all files in the folder, check if it's a SQL Backup file, read it's header, and decide if the file should be deleted. If you have a lot of files in the folder, this might take some time.
To gain a better insight of what's happening when, you could start Profiler and measure each stage of the backup process. You should see an entry for 'BACKUP
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
What is the next step for correcting this?
1. creation of the backup file
2. connecting to SQL Server to retrieve the header data, update the backup history tables and writing the file header
3. deletion of the old backup files
4. writing of the log file
1 and 2 can be measured by looking at profiler, and the writing of the file header is recorded by the date modified attribute of the backup file.
4 can be measured by taking the difference between the date created attribute of the log file and the actual time the entire backup process completes.
3 can only be assumed by taking the difference between 2 and 4, or by creating the backup file to an empty network folder (remember to copy it later to the standard location if you need it), and measuring the time this takes to the time it takes when created in the standard backup folder which contains other backup files.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
For small backups, the time taken by SQL Backup is indeed larger than that taken by native backups due to process overheads (between 2 to 6 seconds). The actual time spent on the backup is as reported. The rest of the time is spent updating the header and backup history, allowing for some intentional delays to ensure the backup file is fully written to disk.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
Event Class Application Name Text Data SPID Start Time
Audit Logout SQLAgent - Job Manager 68 6/15/05 3:20 PM
Audit Login OSQL-32 #NAME?
SQL:BatchStarting OSQL-32 set quoted_identifier off 68 6/15/05 3:20 PM
SQL:BatchStarting OSQL-32 BACKUP LOG [Admin] TO VIRTUAL_DEVICE = 'SQLBACKUP_49282749' WITH BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = '', DESCRIPTION = '', FORMAT
Audit Logout OSQL-32 68 6/15/05 3:20 PM
Audit Login OSQL-32 #NAME?
SQL:BatchStarting OSQL-32 set quoted_identifier off 83 6/15/05 3:20 PM
SQL:BatchStarting OSQL-32 SELECT TOP 1 a.first_lsn, a.last_lsn, a.checkpoint_lsn, a.database_backup_lsn FROM msdb..backupset a INNER JOIN msdb..backupmediafamily b ON a.media_set_id = b.media_set_id WHERE b.physical_device_name = 'SQLBACKUP_49282749' ORDER BY a.media_set_id DESC
Audit Logout OSQL-32 83 6/15/05 3:20 PM
Audit Login OSQL-32 #NAME?
SQL:BatchStarting OSQL-32 set quoted_identifier off 79 6/15/05 3:20 PM
SQL:BatchStarting OSQL-32 UPDATE msdb..backupmediafamily SET physical_device_name = '\\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050615_152007.TRN' WHERE physical_device_name = 'SQLBACKUP_49282749' AND device_type = 7
SQL:BatchStarting OSQL-32 set quoted_identifier off 82 6/15/05 3:25 PM
SQL:BatchStarting OSQL-32 BACKUP LOG [CMS2000] TO VIRTUAL_DEVICE = 'SQLBACKUP_166256317' WITH BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = '', DESCRIPTION = '', FORMAT
Audit Logout OSQL-32 82 6/15/05 3:25 PM
Audit Login OSQL-32 #NAME?
SQL:BatchStarting OSQL-32 set quoted_identifier off 60 6/15/05 3:26 PM
SQL:BatchStarting OSQL-32 SELECT TOP 1 a.first_lsn, a.last_lsn, a.checkpoint_lsn, a.database_backup_lsn FROM msdb..backupset a INNER JOIN msdb..backupmediafamily b ON a.media_set_id = b.media_set_id WHERE b.physical_device_name = 'SQLBACKUP_166256317' ORDER BY a.media_set_id DESC
Audit Logout OSQL-32 60 6/15/05 3:26 PM
Audit Login OSQL-32 #NAME?
SQL:BatchStarting OSQL-32 set quoted_identifier off 78 6/15/05 3:26 PM
SQL:BatchStarting OSQL-32 UPDATE msdb..backupmediafamily SET physical_device_name = '\\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050615_152433.TRN' WHERE physical_device_name = 'SQLBACKUP_166256317' AND device_type = 7
Audit Logout OSQL-32 78 6/15/05 3:26 PM
Second the file date/time of the backup files and the logs
Admin DB - TRN File = 3:20pm Log file = 3:24pm
CMS2000 db - TRN File = 3:26pm log file = 3:28pm
Third Log files
Admin.log
6/15/2005 3:20:19 PM: SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
6/15/2005 3:20:19 PM:
6/15/2005 3:20:19 PM: Backing up Admin (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050615_152007.TRN ...
6/15/2005 3:20:19 PM:
6/15/2005 3:20:19 PM: BACKUP LOG [Admin] TO DISK = '\\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050615_152007.TRN' WITH NAME = '', DESCRIPTION = '', ERASEFILES = 3, LOGTO = '\\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050615_152007.Log', COMPRESSION = 1
6/15/2005 3:20:19 PM:
6/15/2005 3:20:19 PM:
6/15/2005 3:20:19 PM: Backup data size : 832.000 KB
6/15/2005 3:20:19 PM: Compressed data size: 12.000 KB
6/15/2005 3:20:19 PM: Compression rate : 98.56%
6/15/2005 3:20:25 PM: Process completed successfully.
6/15/2005 3:20:25 PM:
Processed 1 pages for database 'Admin', file 'Admin_Log' on file 1.
BACKUP LOG successfully processed 1 pages in 0.099 seconds (0.082 MB/sec).
(1 row affected)
CMS2000 Log
6/15/2005 3:25:07 PM: SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
6/15/2005 3:25:07 PM:
6/15/2005 3:25:07 PM: Backing up CMS2000 (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050615_152433.TRN ...
6/15/2005 3:25:07 PM:
6/15/2005 3:25:07 PM: BACKUP LOG [CMS2000] TO DISK = '\\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050615_152433.TRN' WITH NAME = '', DESCRIPTION = '', ERASEFILES = 3, LOGTO = '\\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050615_152433.Log', COMPRESSION = 1
6/15/2005 3:25:07 PM:
6/15/2005 3:25:07 PM:
6/15/2005 3:25:11 PM: Backup data size : 38.000 MB
6/15/2005 3:25:11 PM: Compressed data size: 8.317 MB
6/15/2005 3:25:11 PM: Compression rate : 78.11%
6/15/2005 3:26:13 PM: Process completed successfully.
6/15/2005 3:26:13 PM:
6/15/2005 3:26:37 PM: Deleting old backup file: \\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050612_112224.TRN
Processed 4722 pages for database 'CMS2000', file 'CMS2000_Log' on file 1.
BACKUP LOG successfully processed 4722 pages in 3.583 seconds (10.795 MB/sec).
(1 row affected)
When you stated:
Admin DB - TRN File = 3:20pm Log file = 3:24pm
CMS2000 db - TRN File = 3:26pm log file = 3:28pm
I take it these are the timestamps as recorded on the remote machine? If so, it's indeed a strange situation. Could you pls run the same command without the LOGTO option, so no remote logs are created? Does the backup complete faster?
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
1 row effected
9 rows affected
12829 rows affected (This number keeps increasing)
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Backing up test001 (transaction log) to c:\temp\test001.sqb ...
Backup data size : 512.000 KB
Compressed data size: 2.500 KB
Compression rate : 99.51%
Process completed successfully.
BACKUP LOG successfully processed 20 pages ....
(1 row affected)
(8 row(s) affected)
The (1 row affected) message comes from the SQL Server backup engine, while the (8 row(s) affected) message appears because there were 8 lines of output.
You mean to say that you have a 3rd line that displays an even larger number of rows affected? Are there any output between the '9 rows affected' and the '12829 rows affected' lines? Strange, because the profiler output you provided does not seem to suggest another query was ran after the history tables were updated.
Could you post the command that you ran from within QA? Thanks.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
exec spLogDBBackup '\\hbhscorp4\sqlbak\sqlcmsbk\',3,'CatalogTraining','distribution'
Definition of spLogDBBackup
CREATE procedure spLogDBBackup
@BackupPath sysname,
@RetentionDays tinyint,
@Skip1 sysname = NULL,
@Skip2 sysname = NULL,
@Skip3 sysname = NULL,
@Skip4 sysname = NULL,
@Skip5 sysname = NULL,
@Skip6 sysname = NULL,
@Skip7 sysname = NULL,
@Skip8 sysname = NULL,
@Skip9 sysname = NULL,
@Skip10 sysname = NULL
as
--Intialize the database to be skipped list
create table #SkipDBs (DBName sysname null)
insert into #SkipDBs select @Skip1
insert into #SkipDBs select @Skip2
insert into #SkipDBs select @Skip3
insert into #SkipDBs select @Skip4
insert into #SkipDBs select @Skip5
insert into #SkipDBs select @Skip6
insert into #SkipDBs select @Skip7
insert into #SkipDBs select @Skip8
insert into #SkipDBs select @Skip9
insert into #SkipDBs select @Skip10
--Create the cursor to loop through the databases respecting the skip list
declare @DBName sysname
declare DB_Cursor Cursor for
select name from master.dbo.sysdatabases
where name not in (select DBName from #SkipDBs where DBName is not null)
and name not in ('TempDB','Master','Model','msdb')
open DB_Cursor
fetch next from DB_Cursor into @DBName
@fetch_status = 0
begin
-- print @DBName
-- select getdate()
exec spDBBackupLog @DBName, @BackupPath, @RetentionDays
-- select getdate()
fetch next from DB_Cursor into @DBName
end
close DB_Cursor
deallocate DB_Cursor
GO
Definition of spDBBackupLog
CREATE procedure spDBBackupLog
@DB_Name sysname,
@BackupPath sysname,
@RetentionDays tinyint
as
declare @BKFileName nvarchar(284)
declare @LogFileName nvarchar(284)
declare @CMDString nvarchar(255)
declare @BackupString nvarchar(4000)
declare @Cur_Date datetime
select @Cur_date = getdate()
--Verify the Database Name is valid
if not exists (select name from master.dbo.sysdatabases where name=@DB_Name)
begin
print 'The database name '+@DB_Name+' is not found in Master.dbo.Sysdatabases'
print 'Usage: exec spDBBackupFull ''DatabaseName'', ''PathToBackup'', NumberOfBackupFilesToRetain'
return 1
end
--Verify the Backup Path is valid
select @CMDString='dir '+@BackupPath
create table #DirOutput (Line nvarchar(255))
insert into #DirOutput
exec master.dbo.xp_cmdshell @CMDString
if exists (select line from #DirOutput where line='File Not Found')
begin
print 'The Backup Path '+@BackupPath+' Does not exist'
print 'Usage: exec spDBBackupFull ''DatabaseName'', ''PathToBackup'', NumberOfBackupFilesToRetain'
return 1
end
--Normalize the backup path with an ending if (select right(@BackupPath,1))<>'\'
select @BackupPath=@BackupPath+'\'
--Build the Backup Filename including the path
select @BKFileName=@BackupPath+@DB_Name+'_TLog_'
+(select right('0000'+cast(datepart(yyyy,@Cur_Date) as nvarchar(4)),4))
+(select right('00'+cast(datepart(mm,@Cur_Date) as nvarchar(2)),2))
+(select right('00'+cast(datepart(dd,@Cur_Date) as nvarchar(2))+'_',3))
+(select right('00'+cast(datepart(hh,@Cur_Date) as nvarchar(2)),2))
+(select right('00'+cast(datepart(mi,@Cur_Date) as nvarchar(2)),2))
+(select right('00'+cast(datepart(ss,@Cur_Date) as nvarchar(2)),2))
+'.TRN'
--Build the Log Filename including the path
select @LogFileName=@BackupPath+@DB_Name+'_TLog_'
+(select right('0000'+cast(datepart(yyyy,@Cur_Date) as nvarchar(4)),4))
+(select right('00'+cast(datepart(mm,@Cur_Date) as nvarchar(2)),2))
+(select right('00'+cast(datepart(dd,@Cur_Date) as nvarchar(2))+'_',3))
+(select right('00'+cast(datepart(hh,@Cur_Date) as nvarchar(2)),2))
+(select right('00'+cast(datepart(mi,@Cur_Date) as nvarchar(2)),2))
+(select right('00'+cast(datepart(ss,@Cur_Date) as nvarchar(2)),2))
+'.Log'
--Build the Backup Command String
select @BackupString=
'exec master.dbo.sqlbackup ''-SQL "BACKUP LOG '+@DB_Name+
' TO DISK = ['+@BKFileName+
-- '] WITH LOGTO = , ERASEFILES = '+cast(@RetentionDays as nvarchar(4))+'"'''
'] with ERASEFILES = '+cast(@RetentionDays as nvarchar(4))+'"'''
-- print @BackupString
exec sp_executesql @BackupString
GO
QA Output (Note: The two select getdate() lines were uncommented for this run)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
(1 row(s) affected)
2005-06-16 11:35:03.883
(1 row(s) affected)
(12846 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG Admin TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050616_113503.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up Admin (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\Admin_TLog_20050616_113503.TRN ...
Backup data size : 832.000 KB
Compressed data size: 15.500 KB
Compression rate : 98.14%
Process completed successfully.
Processed 3 pages for database 'Admin', file 'Admin_Log' on file 1.
BACKUP LOG successfully processed 3 pages in 0.058 seconds (0.344 MB/sec).
(1 row affected)
(10 row(s) affected)
2005-06-16 11:38:35.630
(1 row(s) affected)
2005-06-16 11:38:35.630
(1 row(s) affected)
(12848 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG CMS2000 TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050616_113835.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up CMS2000 (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\CMS2000_TLog_20050616_113835.TRN ...
Backup data size : 4.250 MB
Compressed data size: 709.000 KB
Compression rate : 83.71%
Process completed successfully.
Processed 420 pages for database 'CMS2000', file 'CMS2000_Log' on file 1.
BACKUP LOG successfully processed 420 pages in 0.198 seconds (17.348 MB/sec).
(1 row affected)
(10 row(s) affected)
2005-06-16 11:41:37.317
(1 row(s) affected)
2005-06-16 11:41:37.317
(1 row(s) affected)
(12850 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG CMSHeavenly TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\CMSHeavenly_TLog_20050616_114137.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up CMSHeavenly (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\CMSHeavenly_TLog_20050616_114137.TRN ...
Backup data size : 704.000 KB
Compressed data size: 23.500 KB
Compression rate : 96.66%
Process completed successfully.
Processed 9 pages for database 'CMSHeavenly', file 'CMS2000_Log' on file 1.
BACKUP LOG successfully processed 9 pages in 0.089 seconds (0.765 MB/sec).
(1 row affected)
(10 row(s) affected)
2005-06-16 11:44:34.393
(1 row(s) affected)
2005-06-16 11:44:34.393
(1 row(s) affected)
(12852 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG eConnect TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\eConnect_TLog_20050616_114434.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up eConnect (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\eConnect_TLog_20050616_114434.TRN ...
Backup data size : 896.000 KB
Compressed data size: 66.500 KB
Compression rate : 92.58%
Process completed successfully.
Processed 28 pages for database 'eConnect', file 'eConnect_Log' on file 1.
BACKUP LOG successfully processed 28 pages in 0.089 seconds (2.531 MB/sec).
(1 row affected)
(10 row(s) affected)
2005-06-16 11:47:26.050
(1 row(s) affected)
2005-06-16 11:47:26.050
(1 row(s) affected)
(12853 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG eConnectOregon TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\eConnectOregon_TLog_20050616_114726.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up eConnectOregon (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\eConnectOregon_TLog_20050616_114726.TRN ...
Backup data size : 576.000 KB
Compressed data size: 4.500 KB
Compression rate : 99.22%
Process completed successfully.
BACKUP LOG successfully processed 0 pages in 0.005 seconds (0.000 MB/sec).
(1 row affected)
(9 row(s) affected)
2005-06-16 11:49:52.453
(1 row(s) affected)
2005-06-16 11:49:52.453
(1 row(s) affected)
(12854 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG HOS TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\HOS_TLog_20050616_114952.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up HOS (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\HOS_TLog_20050616_114952.TRN ...
Backup data size : 512.000 KB
Compressed data size: 2.000 KB
Compression rate : 99.61%
Process completed successfully.
BACKUP LOG successfully processed 0 pages in 0.046 seconds (0.000 MB/sec).
(1 row affected)
(9 row(s) affected)
2005-06-16 11:52:20.220
(1 row(s) affected)
2005-06-16 11:52:20.220
(1 row(s) affected)
(12855 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG Northwind TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\Northwind_TLog_20050616_115220.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up Northwind (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\Northwind_TLog_20050616_115220.TRN ...
Backup data size : 576.000 KB
Compressed data size: 4.000 KB
Compression rate : 99.31%
Process completed successfully.
BACKUP LOG successfully processed 0 pages in 0.009 seconds (0.000 MB/sec).
(1 row affected)
(9 row(s) affected)
2005-06-16 11:55:04.437
(1 row(s) affected)
2005-06-16 11:55:04.437
(1 row(s) affected)
(12856 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG POrderApp TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\POrderApp_TLog_20050616_115504.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up POrderApp (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\POrderApp_TLog_20050616_115504.TRN ...
Backup data size : 704.000 KB
Compressed data size: 39.500 KB
Compression rate : 94.39%
Process completed successfully.
Processed 15 pages for database 'POrderApp', file 'POrderApp_Log' on file 1.
BACKUP LOG successfully processed 15 pages in 0.086 seconds (1.422 MB/sec).
(1 row affected)
(10 row(s) affected)
2005-06-16 11:58:07.593
(1 row(s) affected)
2005-06-16 11:58:07.593
(1 row(s) affected)
(12857 row(s) affected)
exec master.dbo.sqlbackup '-SQL "BACKUP LOG pubs TO DISK = [\\hbhscorp4\sqlbak\sqlcmsbk\pubs_TLog_20050616_115807.TRN] with ERASEFILES = 3"'
Output from SQL Backup (3.2.0)
SQL Backup 3.2.0, (c) Red Gate Software Ltd 2004 - 2005
Serial number: 010-005-019079-86FA
Backing up pubs (transaction log) to \\hbhscorp4\sqlbak\sqlcmsbk\pubs_TLog_20050616_115807.TRN ...
Backup data size : 512.000 KB
Compressed data size: 3.000 KB
Compression rate : 99.41%
Process completed successfully.
BACKUP LOG successfully processed 0 pages in 0.014 seconds (0.000 MB/sec).
(1 row affected)
(9 row(s) affected)
2005-06-16 12:01:12.310
(1 row(s) affected)
select @CMDString='dir '+@BackupPath
create table #DirOutput (Line nvarchar(255))
insert into #DirOutput
exec master.dbo.xp_cmdshell @CMDString
That means you have 12000+ files all in the same folder, which SQL Backup will need to check which to delete, everytime the backup is performed.
Could you try running the stored procedure but backing up the files to an empty folder (remember to copy it back to the \\hbhscorp4\sqlbak\sqlcmsbk folder)? Does the backup complete faster?
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
Deleting old SQB log files in the standard log folder is a feature planned for a future release. Hopefully, we can fit in the option to delete old SQB log files in user defined log folders too.
Thanks for your effort and patience.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8