Cannot restore database with transaction log

Question

I make every day at 0300 AM a Full Backup (NOT a COPY-ONLY) of a database (11 GB) and every minute (from 03:05AM till 02:55AM) a TRANSACTION LOG Backup. When I tried to Restore to a point in Time eg 03:07AM there is an error that the backupsets are not inline.

When I took a look at the backupset table in msdb database I see all the backups (FULL en LOGS), but the first_lsn of the First TRNLOG after a FULL Backup is not the same as the last_lsn of the FULL backup, but it is the same the last_lsn of Prev TRNLOG (which is before the FULL backup).

So it is not possible to restore the FULL backup and eg the First TRNLOG backup.

What is going wrong in my backup process?

See image below

Answer 1

To restore to 03:07 AM you would require the following backup files:

• SW_SAM_GEMAAL_backup_2017_09_21_030159_6588486 (FULL)
• SW_SAM_GEMAAL_backup_2017_09_21_030501_0515333 (TLOG)
• SW_SAM_GEMAAL_backup_2017_09_21_030601_6958001 (TLOG)
• SW_SAM_GEMAAL_backup_2017_09_21_030701_....... (TLOG)
• SW_SAM_GEMAAL_backup_2017_09_21_030801_....... (TLOG; possibly)

In your screenshot you are only listing the files up until the SW_SAM_GEMAAL_backup_2017_09_21_030601_6958001 TLOG backup. However, this file does not contain any modifications past 03:06:01 AM and this is possibly why you are unable to restore to the point-in-time at 03:07:00 AM.

The FULL backup is always consistent as is stated by the official Microsoft (Docs) documentation (emphasis mine):

DATABASE

Specifies a complete database backup. If a list of files and filegroups is specified, only those files and filegroups are backed up. During a full or differential database backup, SQL Server backs up enough of the transaction log to produce a consistent database when the backup is restored.

When you restore a backup created by BACKUP DATABASE (a data backup), the entire backup is restored. Only a log backup can be restored to a specific time or transaction within the backup.

Reference: BACKUP (Transact-SQL)

Depending on your error message, you might find that because you ommitted one TLOG backup file, that the restore is failing.

Reproducing Issue

Inserting data / creating backups

I reproduced your situation on my local SQL Server with the following steps and was able to restore to a point-in-time with a transaction still open during the FULL and TLOG backups:

-- 11:23 BEGIN TRANSACTION WITH INSERT
BEGIN TRAN TESTBACKUP
INSERT INTO dbo.Good_Morning
(
    Test
)
VALUES
(
    'A Text '
)
-- 11:24 TLOG Backup
-- 11:25 FULL Backup
-- 11:26 NEXT INSERT
INSERT INTO dbo.Good_Morning
(
    Test
)
VALUES
(
    'A Text 2'
)
-- 11:27 TLOG BACKUP
-- 11:28 COMMIT
COMMIT TRAN TESTBACKUP
-- 11:29 TLOG BACKUP

Backup History

My backup history looked like this:

database_name backup_start_date       backup_finish_date      backup_type physical_device_name                                                          first_lsn         last_lsn          checkpoint_lsn    database_backup_lsn
AdminDB2      2017-09-21 11:24:08.000 2017-09-21 11:24:08.000 Log         C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_112408.trn   35000001910900001 35000001911200001 35000001908000042   35000001908000042
AdminDB2      2017-09-21 11:25:15.000 2017-09-21 11:25:15.000 Full        C:\SQL\Backup\NB31710\AdminDB2\FULL\NB31710_AdminDB2_FULL_20170921_112515.bak 35000001911100002 35000001913500001 35000001911700042   35000001908000042
AdminDB2      2017-09-21 11:27:03.000 2017-09-21 11:27:03.000 Log         C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_112703.trn   35000001911200001 35000001914300001 35000001911700042   35000001911700042
AdminDB2      2017-09-21 11:29:06.000 2017-09-21 11:29:06.000 Log         C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_112906.trn   35000001914300001 35000001914600001 35000001911700042   35000001911700042
AdminDB2      2017-09-21 11:31:59.000 2017-09-21 11:31:59.000 Log         C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_113159.trn   35000001914600001 35000001914900001 35000001911700042   35000001911700042
AdminDB2      2017-09-21 12:15:00.000 2017-09-21 12:15:00.000 Log         C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_121500.trn   35000001914900001 35000001915200001 35000001911700042   35000001911700042

Restoring Database

I then restored my database to 11:28:00 AM with the following statements:

RESTORE DATABASE [AdminDB2] FROM  DISK = 'C:\SQL\Backup\NB31710\AdminDB2\FULL\NB31710_AdminDB2_FULL_20170921_112515.bak' 
WITH FILE = 1, NORECOVERY, NOUNLOAD, STATS = 5  

RESTORE LOG [AdminDB2] FROM  DISK = 'C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_112703.trn' 
WITH FILE = 1, NORECOVERY, NOUNLOAD, STATS = 5  

RESTORE LOG [AdminDB2] FROM  DISK = 'C:\SQL\Backup\NB31710\AdminDB2\LOG\NB31710_AdminDB2_LOG_20170921_112906.trn' 
WITH FILE = 1, NOUNLOAD, STATS = 5, STOPAT = N'2017-09-21T11:28:00'

Solution

Add your last TLOG backup of your database to the restore statement and you should be able to restore to your point-in-time at 03:07:00 AM.

Answer 2

That happens when you have an open transaction during the database full backup.

Whenever you make any DML data pages are hardened to disk, containing the earliest LSN that was part of that transaction.These are called dirty pages (since transaction is not committed), which helps SQL recover after an unexpected shutdown/restart, to restore itself to the point before non committed transaction.

While you was doing a full backup you, it ignored the LSN of the transaction that was ongoing, and after it has been committed, you next transaction log backup read the latest committed transaction (which was the one that was active while your full backup was being processed).

I managed to demonstrate the same situation on my computer with a simple test: leaving a transaction active, while taking a full backup:

You should try to get a track of long running trans. especially during that time, so you could prevent it from happening again. Check whether you have some kind of bulk inserts, long running jobs that include some DMLs, or simply set the alert.