MS SQL Server: Log Backup LSN Mismatch

Question

We had to restore a database yesterday using a full backup and a number of log backups. This caused problems because the log chain was broken. All full and log backups were written. No backup job was failing, the corresponding log history looks like:

Backup Type	Name	Start	End	First LSN	Last LSN	Checkpoint	Size
Database Full	db_name	12.01.2021 20:30:02	12.01.2021 20:30:04	171000001698500037	171000001700400001	171000001698500037	277955584
Transaction Log	db_name	12.01.2021 20:48:00	12.01.2021 20:48:00	171000001696100001	171000001701900001	171000001698500037	80896
Transaction Log	db_name	12.01.2021 21:12:00	12.01.2021 21:12:00	171000001701900001	171000001715000001	171000001702100002	146432
Transaction Log	db_name	12.01.2021 21:36:00	12.01.2021 21:36:00	171000001715000001	171000001740600001	171000001715200002	146432
Transaction Log	db_name	12.01.2021 22:00:01	12.01.2021 22:00:01	171000001740600001	171000001748500001	171000001740800002	80896
Transaction Log	db_name	12.01.2021 22:24:00	12.01.2021 22:24:00	171000001748500001	171000001751100001	171000001748700002	80896
Transaction Log	db_name	12.01.2021 22:48:00	12.01.2021 22:48:00	171000001751100001	171000001753400001	171000001751300002	80896
Transaction Log	db_name	12.01.2021 23:12:00	12.01.2021 23:12:00	171000001753400001	171000001755700001	171000001753600002	80896
Transaction Log	db_name	13.01.2021 00:00:00	13.01.2021 00:00:00	171000001756300001	171000001756700001	171000001756500002	80896
Transaction Log	db_name	13.01.2021 00:24:00	13.01.2021 00:24:00	171000001756700001	171000001757100001	171000001756900002	80896
Transaction Log	db_name	13.01.2021 00:48:00	13.01.2021 00:48:00	171000001757100001	171000001757500001	171000001757300002	80896
Transaction Log	db_name	13.01.2021 01:12:00	13.01.2021 01:12:00	171000001757500001	171000001757900001	171000001757700002	80896
Transaction Log	db_name	13.01.2021 01:36:01	13.01.2021 01:36:01	171000001757900001	171000001758300001	171000001758100002	80896
Transaction Log	db_name	13.01.2021 02:00:00	13.01.2021 02:00:00	171000001758300001	171000001758700001	171000001758500002	80896
Transaction Log	db_name	13.01.2021 02:24:00	13.01.2021 02:24:00	171000001758700001	171000001799800001	171000001758900002	277504
Transaction Log	db_name	13.01.2021 02:48:01	13.01.2021 02:48:01	171000001799800001	171000001810300001	171000001807500037	80896
Transaction Log	db_name	13.01.2021 03:12:00	13.01.2021 03:12:01	171000001810300001	171000001947400001	171000001810500002	736256
Transaction Log	db_name	13.01.2021 03:36:00	13.01.2021 03:36:00	171000001947400001	171000001958500001	171000001947600002	80896
Transaction Log	db_name	13.01.2021 04:00:00	13.01.2021 04:00:00	171000001958500001	171000001960300001	171000001959000002	80896
Transaction Log	db_name	13.01.2021 04:24:00	13.01.2021 04:24:00	171000001960300001	171000001961400001	171000001960500002	80896
Transaction Log	db_name	13.01.2021 04:48:01	13.01.2021 04:48:01	171000001962000001	171000001963800001	171000001962200002	80896
Transaction Log	db_name	13.01.2021 05:12:00	13.01.2021 05:12:00	171000001963800001	171000001964200001	171000001964000002	80896
Transaction Log	db_name	13.01.2021 05:36:00	13.01.2021 05:36:00	171000001964200001	171000001964600001	171000001964400002	80896

As you can see, the chain is broken at 13.01.2021 04:48:01. What could be the reason? A VM reset? A problem with Veeam (Backup Software)? An inconsistency with the backup plan? I rather see the problem outside of SQL Server because we've checked the full and log backup today morning and the chain is again complete and a test restore was working fine. Test restores in the past always worked.

As said before. The backup jobs terminated all successfully.

I appreciate your input. Thanks!

• SQLpro: Perhaps a BACKUP LOG ... TO NULL has been done ? At what time did the VEAM backup is executed ? (I never tolerate VEAM backup for my own customers because its interfere with my own backup plans....)

Answer 1

Something weird is going on here. I first suspected that the database was put into simple recovery mode and back to full. But SQL server won't allow you to take a log backup after such operation. I.e., the log backup with firstLSN 171000001962000001 should have failed unless there was a full backup before.

The only two things I can think of is that you are leaving out the full backup that above log backup should be based on (i.e., my above scenario) in the presentation of backup history. Or that the backup history was manipulated to either delete the row for that full backup, or a log backup was indeed taken and that row from backuphistory was deleted.

Unless you are on a super-old SQL server, of course (2005). Those had weird options for the BACKUP LOG command.

Answer 2

Thank you very much! You got me to the right track! The information in my table above was taken from the backup files.

Following SQL statement

SELECT 
 name, description, user_name, backup_start_date, backup_finish_date, type, first_lsn, last_lsn, checkpoint_lsn, database_backup_lsn
FROM
 msdb.dbo.backupset 
WHERE
 msdb.dbo.backupset.database_name IN (SELECT [name] FROM master.dbo.sysdatabases)
 AND msdb.dbo.backupset.database_name LIKE 'db_name'
 AND msdb.dbo.backupset.backup_start_date BETWEEN '2021-01-13 20:00:00.000' AND '2021-01-14 20:00:00.000'
ORDER BY backup_start_date

shows that the backup solution takes a unnecessary full backup (what is not the problem).

The problem is a log backup taken by a other user. Thats the file I don't have. Wired... but we are able to solve it with the information.

name	description	user_name	backup_start_date	backup_finish_date	type	first_lsn	last_lsn	checkpoint_lsn	database_backup_lsn
NULL	NULL	sql-server	2021年01月12日 20:30:02.000	2021年01月12日 20:30:04.000	D	171000001698500037	171000001700400001	171000001698500037	170000001098100037
NULL	NULL	sql-server	2021年01月12日 20:48:00.000	2021年01月12日 20:48:00.000	L	171000001696100001	171000001701900001	171000001698500037	171000001698500037
NULL	NULL	sql-server	2021年01月12日 21:12:00.000	2021年01月12日 21:12:00.000	L	171000001701900001	171000001715000001	171000001702100002	171000001698500037
NULL	NULL	sql-server	2021年01月12日 21:36:00.000	2021年01月12日 21:36:00.000	L	171000001715000001	171000001740600001	171000001715200002	171000001698500037
NULL	NULL	sql-server	2021年01月12日 22:00:01.000	2021年01月12日 22:00:01.000	L	171000001740600001	171000001748500001	171000001740800002	171000001698500037
NULL	NULL	sql-server	2021年01月12日 22:24:00.000	2021年01月12日 22:24:00.000	L	171000001748500001	171000001751100001	171000001748700002	171000001698500037
NULL	NULL	sql-server	2021年01月12日 22:48:00.000	2021年01月12日 22:48:00.000	L	171000001751100001	171000001753400001	171000001751300002	171000001698500037
NULL	NULL	sql-server	2021年01月12日 23:12:00.000	2021年01月12日 23:12:00.000	L	171000001753400001	171000001755700001	171000001753600002	171000001698500037
NULL	NULL	sql-server	2021年01月12日 23:36:00.000	2021年01月12日 23:36:00.000	L	171000001755700001	171000001756300001	171000001756100002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 00:00:00.000	2021年01月13日 00:00:00.000	L	171000001756300001	171000001756700001	171000001756500002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 00:24:00.000	2021年01月13日 00:24:00.000	L	171000001756700001	171000001757100001	171000001756900002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 00:48:00.000	2021年01月13日 00:48:00.000	L	171000001757100001	171000001757500001	171000001757300002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 01:12:00.000	2021年01月13日 01:12:00.000	L	171000001757500001	171000001757900001	171000001757700002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 01:36:01.000	2021年01月13日 01:36:01.000	L	171000001757900001	171000001758300001	171000001758100002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 02:00:00.000	2021年01月13日 02:00:00.000	L	171000001758300001	171000001758700001	171000001758500002	171000001698500037
NULL	NULL	sql-server	2021年01月13日 02:24:00.000	2021年01月13日 02:24:00.000	L	171000001758700001	171000001799800001	171000001758900002	171000001698500037
Veeam Backup & Replication	Image-level backup	NT AUTHORITY\SYSTEM	2021年01月13日 02:33:24.000	2021年01月13日 02:33:37.000	D	171000001807500037	171000001809300001	171000001807500037	171000001698500037
NULL	NULL	sql-server	2021年01月13日 02:48:01.000	2021年01月13日 02:48:01.000	L	171000001799800001	171000001810300001	171000001807500037	171000001807500037
NULL	NULL	sql-server	2021年01月13日 03:12:00.000	2021年01月13日 03:12:01.000	L	171000001810300001	171000001947400001	171000001810500002	171000001807500037
NULL	NULL	sql-server	2021年01月13日 03:36:00.000	2021年01月13日 03:36:00.000	L	171000001947400001	171000001958500001	171000001947600002	171000001807500037
NULL	NULL	sql-server	2021年01月13日 04:00:00.000	2021年01月13日 04:00:00.000	L	171000001958500001	171000001960300001	171000001959000002	171000001807500037
NULL	NULL	sql-server	2021年01月13日 04:24:00.000	2021年01月13日 04:24:00.000	L	171000001960300001	171000001961400001	171000001960500002	171000001807500037
NULL	NULL	admin	2021年01月13日 04:35:46.000	2021年01月13日 04:35:46.000	L	171000001961400001	171000001962000001	171000001961600002	171000001807500037
NULL	NULL	sql-server	2021年01月13日 04:48:01.000	2021年01月13日 04:48:01.000	L	171000001962000001	171000001963800001	171000001962200002	171000001807500037
NULL	NULL	sql-server	2021年01月13日 05:12:00.000	2021年01月13日 05:12:00.000	L	171000001963800001	171000001964200001	171000001964000002	171000001807500037

Thank you very much. You helped me to nail down the issue.

Best Frederik

• Tibor Karaszi: The fact that Veeam does a full backup isn't the problem (as you noted). This is the VSS snapshot that Veem produces of your machine, it is seen by SQL Server as a full backup, thanks to the integration with the SQL Server VSS Writer service. The problem is that other log backup, which you need to hunt down if you want to restore and also hunt down why this happened and make sure it doesn't happen again. :-)
• John K. N.: If you take my script from this answer and look at the msdb.dbo.backupmediafamily.physical_device_name column, then you know where the file was stored that the admin user created. Put in the correct database name in the WHERE clause.
• user3845316: Thanks. We did that and found out there was a "shrink database log file" job activated in Veeam which did break the log setup on our side ;-)