1

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!

New contributor
Frederik is a new contributor to this site. Take care in asking for clarification, commenting, and answering. Check out our Code of Conduct.
  • 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....) – SQLpro Jan 14 at 11:53
0

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.

1

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

New contributor
Frederik is a new contributor to this site. Take care in asking for clarification, commenting, and answering. Check out our Code of Conduct.
  • 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. :-) – Tibor Karaszi Jan 14 at 7:55
  • 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. – John K. N. Jan 14 at 8:48
  • 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 ;-) – Frederik 2 days ago

Your Answer

Frederik is a new contributor. Be nice, and check out our Code of Conduct.

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.