Problem with log backups
Sławomir 
Posts: 3
Hello,
I'm using Red Gate SQL Backup to perform many tasks, among them are log backups for some databases. Today I found something rather strange.
Log backup failed because there was not enough space on the destination drive - OK :-), such situtaion should never happend (that is - to some extent - my fault), but the problem is not in the fact that the backup failed - but in that the next log backup performed when there was a lot of space, which completed successfuly, contains LSNs newer than the last LSN in the previous successful log backup - so there is a gap, and as a result log backup sequence is broken.
According to MS and in case of the normal SQL command BACKUP LOG...:
The log is backed up from the last successfully executed log backup to the current end of the log.
Can anyone explain that behaviour?
I'm more than happy with Red Gate SQL Backup, and the process that failed today worked without an issue for over a year (in this case as a part of the custom log shipping scenario - that's why the gap in the sequence is so important), but I want to be sure, what I may or may not expect in the case when the log backup will fail in the future for any reason.
I'm posting this message to the forum about Red Gate SQL Backup 5 (because in this case it was version 5.x) , but maybe that behaviour changed in the version 6.x?
Best regards and thanks for any suggestion/responses
I'm using Red Gate SQL Backup to perform many tasks, among them are log backups for some databases. Today I found something rather strange.
Log backup failed because there was not enough space on the destination drive - OK :-), such situtaion should never happend (that is - to some extent - my fault), but the problem is not in the fact that the backup failed - but in that the next log backup performed when there was a lot of space, which completed successfuly, contains LSNs newer than the last LSN in the previous successful log backup - so there is a gap, and as a result log backup sequence is broken.
According to MS and in case of the normal SQL command BACKUP LOG...:
The log is backed up from the last successfully executed log backup to the current end of the log.
Can anyone explain that behaviour?
I'm more than happy with Red Gate SQL Backup, and the process that failed today worked without an issue for over a year (in this case as a part of the custom log shipping scenario - that's why the gap in the sequence is so important), but I want to be sure, what I may or may not expect in the case when the log backup will fail in the future for any reason.
I'm posting this message to the forum about Red Gate SQL Backup 5 (because in this case it was version 5.x) , but maybe that behaviour changed in the version 6.x?
Best regards and thanks for any suggestion/responses
Comments
Thanks.
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8
1) Last successful:
SQL Backup log file 5.3.0.178
-SQL "BACKUP LOG [DATABASE_NAME] TO DISK = 'DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_064001.trn.sqb' WITH CHECKSUM , COMPRESSION = 3 , STOP_ON_ERROR , DESCRIPTION =
'DATABASE_NAME - DATABASE_NAME - log backup - 2010-10-27 06:40' , INIT , KEYSIZE = 256 , NAME = 'DATABASE_NAME - DATABASE_NAME - BACKUP MEDIA' , PASSWORD = 'XXXXXXXXXXXX' , SINGLERESULTSET ,
THREADPRIORITY = 3 "
PROCESSES COMPLETED SUCCESSFULLY
2010-10-27 06:40:01: Backing up DATABASE_NAME (transaction log) to:
2010-10-27 06:40:01: DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_064001.trn.sqb
2010-10-27 06:40:01: BACKUP LOG [DATABASE_NAME] TO VIRTUAL_DEVICE = 'SQLBACKUP_3CD67858-352D-4C77-B362-FBBF40154B23' WITH BUFFERCOUNT = 6, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME =
N'DATABASE_NAME - DATABASE_NAME - BACKUP MEDIA', DESCRIPTION = N'DATABASE_NAME - DATABASE_NAME - log backup - 2010-10-27 06:40', CHECKSUM
2010-10-27 06:40:06: Backup data size : ? MB
2010-10-27 06:40:06: Compressed data size: ? MB
2010-10-27 06:40:06: Compression rate : 75,52%
Processed ? pages for database 'DATABASE_NAME', file 'DATABASE_NAME_Log' on file 1.
BACKUP LOG successfully processed ? pages in ? seconds (17.943 MB/sec).
2010-10-27 06:40:06: SQL Backup process ended.
2) Next first failed (due to the lack of the free space on the drive)
SQL Backup log file 5.3.0.178
-SQL "BACKUP LOG [DATABASE_NAME] TO DISK = 'DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_065000.trn.sqb' WITH CHECKSUM , COMPRESSION = 3 , STOP_ON_ERROR , DESCRIPTION = 'DATABASE_NAME - DATABASE_NAME - log backup - 2010-10-27 06:50' , INIT , KEYSIZE = 256 , NAME = 'DATABASE_NAME - DATABASE_NAME - BACKUP MEDIA' , PASSWORD = 'XXXXXXXXXXXX' , SINGLERESULTSET , THREADPRIORITY = 3 "
ERRORS AND WARNINGS
2010-10-27 06:50:00: Backing up DATABASE_NAME (transaction log) to:
2010-10-27 06:50:00: DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_065000.trn.sqb
2010-10-27 06:50:01: BACKUP LOG [DATABASE_NAME] TO VIRTUAL_DEVICE = 'SQLBACKUP_AF2539C6-2BD5-45D8-9C7D-9372B63431E6' WITH BUFFERCOUNT = 6, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'DATABASE_NAME - DATABASE_NAME - BACKUP MEDIA', DESCRIPTION = N'DATABASE_NAME - DATABASE_NAME - log backup - 2010-10-27 06:50', CHECKSUM
2010-10-27 06:50:02: Thread 0 error:
Error 620: Error writing to backup file(s).
2010-10-27 06:50:02: Warning 210: Thread 0 warning:
Warning 210: Error writing to backup file: DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_065000.trn.sqb
Warning: System error 112 (There is not enough space on the disk)
2010-10-27 06:50:02:
Processed ? pages for database 'DATABASE_NAME', file 'DATABASE_NAME_Log' on file 1.
BACKUP LOG successfully processed ? pages in ? seconds (13.396 MB/sec).
I believe that it is the root cause of the problem, log backup was unable to write the data to the file, but reported (to the SQL Server) that the operation completed successfuly - so that's the reason - my guess - for the broken sequence.
3) The next one (and the rest until I fixed the problem with the free space) also failed, but with different message (this time there is not 'completed successfuly':
SQL Backup log file 5.3.0.178
-SQL "BACKUP LOG [DATABASE_NAME] TO DISK = 'DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_070000.trn.sqb' WITH CHECKSUM , COMPRESSION = 3 , STOP_ON_ERROR , DESCRIPTION = 'DATABASE_NAME - DATABASE_NAME - log backup - 2010-10-27 07:00' , INIT , KEYSIZE = 256 , NAME = 'DATABASE_NAME - DATABASE_NAME - BACKUP MEDIA' , PASSWORD = 'XXXXXXXXXXXX' , SINGLERESULTSET , THREADPRIORITY = 3 "
ERRORS AND WARNINGS
2010-10-27 07:00:00: Backing up DATABASE_NAME (transaction log) to:
2010-10-27 07:00:00: DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_070000.trn.sqb
2010-10-27 07:00:03: BACKUP LOG [DATABASE_NAME] TO VIRTUAL_DEVICE = 'SQLBACKUP_5C4CF6D9-3466-4E7D-BB7D-12EE64E4AF36' WITH BUFFERCOUNT = 6, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576, NAME = N'DATABASE_NAME - DATABASE_NAME - BACKUP MEDIA', DESCRIPTION = N'DATABASE_NAME - DATABASE_NAME - log backup - 2010-10-27 07:00', CHECKSUM
2010-10-27 07:00:06: Thread 0 error:
Error 620: Error writing to backup file(s).
Process terminated unexpectedly. Error code: -2139684860
2010-10-27 07:00:06: Warning 210: Thread 0 warning:
Warning 210: Error writing to backup file: DRIVE_LETTER:\DIRECTORY_NAME\DATABASE_NAME_DATABASE_NAME_20101027_070000.trn.sqb
Warning: System error 112 (There is not enough space on the disk)
2010-10-27 07:00:06:
SQL error 3013: SQL error 3013: BACKUP LOG is terminating abnormally.
SQL error 3271: SQL error 3271: A nonrecoverable I/O error occurred on file "SQLBACKUP_5C4CF6D9-3466-4E7D-BB7D-12EE64E4AF36:" 995(error not found).
SQL error 3202: SQL error 3202: Write on "SQLBACKUP_5C4CF6D9-3466-4E7D-BB7D-12EE64E4AF36" failed: 1117(error not found)
Thanks for the response
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 8