Warning 170: Log files are not in sequence

Compresses, encrypts, secures and monitors SQL Server backups.

Moderators: JonathanWatts, Chris Auckland, eddie davis, Colin Millerchip, Brian Harris, james.billings, RBA, petey

Warning 170: Log files are not in sequence

Postby jason_dev » Mon Jul 02, 2012 10:31 pm

Hi All,

We are using Red-Gate SQL Backup 7.0.5.1 to back up our production SQL server (externally hosted) as well as do backup verification restores on an internal server. From the log below, you can see that I'm having trouble restoring the transaction log backups.

I'm sure the sequence of things matter in the case, so here are the scheduled jobs:

On the production server (externally hosted):
Full backup: Once every night at 11pm. Does a remote copy to the corporate network via a VPN connection. Takes about 11 minutes to do the back up and 1 hour to transfer the full back up.
Transaction back up: Every day every 10 minutes between 2am and 10:59pm. Also does a remote copy to the corporate network.

Restore (internal server):
Restore: Every day every hour between 2am and 10:59pm.


And here is the log file of the failed job:

SQL Backup log file 7.0.5.1

-SQL \"RESTORE DATABASE [Acme_BackupVerification] FROM DISK = '\\\\laxrep003.corp.Acme.msp\\Backups\\sql001_redgate\\*.sqb' SOURCE = 'Acme' LATEST_ALL WITH RECOVERY, DISCONNECT_EXISTING, MOVE 'Acme' TO 'D:\\MSSQL\\DATA\\Acme_BackupVerification.m
df', MOVE 'Acme_Log' TO 'D:\\MSSQL\\LOG\\Acme_BackupVerification_log.ldf', REPLACE, CHECKDB = 'NO_INFOMSGS, ALL_ERRORMSGS' \"

----------------------------- ERRORS AND WARNINGS -----------------------------



7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_020000.sqb' and 'LOG_(local)_Acme_20120702_021002.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_021002.sqb' and 'LOG_(local)_Acme_20120702_022000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_022000.sqb' and 'LOG_(local)_Acme_20120702_023001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_023001.sqb' and 'LOG_(local)_Acme_20120702_024000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_024000.sqb' and 'LOG_(local)_Acme_20120702_025001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_025001.sqb' and 'LOG_(local)_Acme_20120702_030001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_030001.sqb' and 'LOG_(local)_Acme_20120702_031001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_031001.sqb' and 'LOG_(local)_Acme_20120702_032000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_032000.sqb' and 'LOG_(local)_Acme_20120702_033000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_033000.sqb' and 'LOG_(local)_Acme_20120702_034000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_034000.sqb' and 'LOG_(local)_Acme_20120702_035000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_035000.sqb' and 'LOG_(local)_Acme_20120702_040001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_040001.sqb' and 'LOG_(local)_Acme_20120702_041000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_041000.sqb' and 'LOG_(local)_Acme_20120702_042000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_042000.sqb' and 'LOG_(local)_Acme_20120702_043000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_043000.sqb' and 'LOG_(local)_Acme_20120702_044000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_044000.sqb' and 'LOG_(local)_Acme_20120702_045000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_045000.sqb' and 'LOG_(local)_Acme_20120702_050000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_050000.sqb' and 'LOG_(local)_Acme_20120702_051000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_051000.sqb' and 'LOG_(local)_Acme_20120702_052000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_052000.sqb' and 'LOG_(local)_Acme_20120702_053000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_053000.sqb' and 'LOG_(local)_Acme_20120702_054000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_054000.sqb' and 'LOG_(local)_Acme_20120702_055000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_055000.sqb' and 'LOG_(local)_Acme_20120702_060001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_060001.sqb' and 'LOG_(local)_Acme_20120702_061000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_061000.sqb' and 'LOG_(local)_Acme_20120702_062000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_062000.sqb' and 'LOG_(local)_Acme_20120702_063000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_063000.sqb' and 'LOG_(local)_Acme_20120702_064000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_064000.sqb' and 'LOG_(local)_Acme_20120702_065000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_065000.sqb' and 'LOG_(local)_Acme_20120702_070001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_070001.sqb' and 'LOG_(local)_Acme_20120702_071000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_071000.sqb' and 'LOG_(local)_Acme_20120702_072000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_072000.sqb' and 'LOG_(local)_Acme_20120702_073001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_073001.sqb' and 'LOG_(local)_Acme_20120702_074000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_074000.sqb' and 'LOG_(local)_Acme_20120702_075001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_075001.sqb' and 'LOG_(local)_Acme_20120702_080001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_080001.sqb' and 'LOG_(local)_Acme_20120702_081000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_081000.sqb' and 'LOG_(local)_Acme_20120702_082000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_082000.sqb' and 'LOG_(local)_Acme_20120702_083000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_083000.sqb' and 'LOG_(local)_Acme_20120702_084000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_084000.sqb' and 'LOG_(local)_Acme_20120702_085000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_085000.sqb' and 'LOG_(local)_Acme_20120702_090001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_090001.sqb' and 'LOG_(local)_Acme_20120702_091000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_091000.sqb' and 'LOG_(local)_Acme_20120702_092000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_092000.sqb' and 'LOG_(local)_Acme_20120702_093000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_093000.sqb' and 'LOG_(local)_Acme_20120702_094000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_094000.sqb' and 'LOG_(local)_Acme_20120702_095001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_095001.sqb' and 'LOG_(local)_Acme_20120702_100000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_100000.sqb' and 'LOG_(local)_Acme_20120702_101001.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_101001.sqb' and 'LOG_(local)_Acme_20120702_102000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_102000.sqb' and 'LOG_(local)_Acme_20120702_103000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_103000.sqb' and 'LOG_(local)_Acme_20120702_104000.sqb'
7/2/2012 11:08:45 AM: Warning 170: Log files are not in sequence: 'LOG_(local)_Acme_20120702_104000.sqb' and 'LOG_(local)_Acme_20120702_105000.sqb'
7/2/2012 11:08:45 AM: Restoring Acme_BackupVerification (transaction logs) from:
7/2/2012 11:08:45 AM: \\\\laxrep003.corp.Acme.msp\\Backups\\sql001_redgate\\LOG_(local)_Acme_20120702_020000.sqb

7/2/2012 11:08:45 AM: RESTORE LOG [Acme_BackupVerification] FROM VIRTUAL_DEVICE = 'SQLBACKUP_FA22D539-BA3A-4426-8B5C-50F5508EC00A', VIRTUAL_DEVICE = 'SQLBACKUP_FA22D539-BA3A-4426-8B5C-50F5508EC00A01', VIRTUAL_DEVICE = 'SQLBACKUP_FA22D539-BA3A-4426-8B5
C-50F5508EC00A02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 1048576 , NORECOVERY, REPLACE

7/2/2012 11:08:45 AM: Thread 0 error:
Process terminated unexpectedly. Error code: -2139684860 (An abort request is preventing anything except termination actions.)
7/2/2012 11:08:45 AM:
7/2/2012 11:08:45 AM: Thread 1 error:
Process terminated unexpectedly. Error code: -2139684860 (An abort request is preventing anything except termination actions.)
7/2/2012 11:08:45 AM:
7/2/2012 11:08:45 AM: Thread 2 error:
Process terminated unexpectedly. Error code: -2139684860 (An abort request is preventing anything except termination actions.)
7/2/2012 11:08:45 AM:
7/2/2012 11:08:45 AM: SQL error 3013: SQL error 3013: RESTORE LOG is terminating abnormally.
7/2/2012 11:08:45 AM: SQL error 4305: SQL error 4305: The log in this backup set begins at LSN 74194000009461800001, which is too recent to apply to the database. An earlier log backup that includes LSN 74185000009938600001 can be restored.



----------------------- PROCESSES COMPLETED SUCCESSFULLY --------------------

7/2/2012 11:00:06 AM: Restoring Acme_BackupVerification (database) from:
7/2/2012 11:00:06 AM: \\\\laxrep003.corp.Acme.msp\\Backups\\sql001_redgate\\FULL_(local)_Acme_20120701_230001.sqb

7/2/2012 11:00:07 AM: RESTORE DATABASE [Acme_BackupVerification] FROM VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB01', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1
E-A022-77645FE405DB02', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB03', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB04', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB05', VIRTUAL_DEVICE =
'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB06', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB07', VIRTUAL_DEVICE = 'SQLBACKUP_0B0DEBE1-AE79-4A1E-A022-77645FE405DB08' WITH BUFFERCOUNT = 27, BLOCKSIZE = 65536, MAXTRANSFERSIZE =
1048576 , NORECOVERY, MOVE 'Acme' TO 'D:\\MSSQL\\DATA\\Acme_BackupVerification.mdf', MOVE 'Acme_Log' TO 'D:\\MSSQL\\LOG\\Acme_BackupVerification_log.ldf', REPLACE

7/2/2012 11:08:44 AM: Processed 2342736 pages for database 'Acme_BackupVerification', file 'Acme' on file 1.
7/2/2012 11:08:44 AM: Processed 4865 pages for database 'Acme_BackupVerification', file 'Acme_log' on file 1.
7/2/2012 11:08:44 AM: RESTORE DATABASE successfully processed 2347601 pages in 479.770 seconds (38.227 MB/sec).
jason_dev
 
Posts: 6
Joined: Mon Jul 02, 2012 10:17 pm

Postby petey » Tue Jul 03, 2012 11:56 am

Could you please post the first 10 rows from running the following query on the production server:

Code: Select all
SELECT a.backup_start_date, a.backup_finish_date, b.physical_device_name, a.type, a.first_lsn, a.last_lsn, a.database_backup_lsn
FROM msdb..backupset a
INNER JOIN msdb..backupmediafamily b ON a.media_set_id = b.media_set_id
WHERE a.database_name = 'Acme'
  AND a.backup_start_date >= '1-Jul-2012 23:00'
ORDER BY a.backup_start_date

Thank you.
Peter Yeoh
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 7
petey
 
Posts: 2233
Joined: Sun Apr 24, 2005 12:34 pm

Postby jason_dev » Tue Jul 03, 2012 10:36 pm

I hope this is readable...

2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:00:01.000 2012-07-01 23:09:12.000 \\\\Acme\\files\\backups\\SQL001\\Acme_RedGate\\FULL_(local)_Acme_20120701_230001.sqb D 74185000002154600001 74185000009938600001 74092000014937400161
2012-07-01 23:03:03.000 2012-07-01 23:03:05.000 \\\\Acme\\files\\Backups\\sql001\\Acme\\Acme_20120701-2303-LOG.trn L 74185000002350900001 74185000005875900001 74092000014937400161
2012-07-01 23:13:04.000 2012-07-01 23:13:07.000 \\\\Acme\\files\\Backups\\sql001\\Acme\\Acme_20120701-2313-LOG.trn L 74185000005875900001 74185000014093600001 74185000003175700258
2012-07-01 23:23:00.000 2012-07-01 23:23:02.000 \\\\Acme\\files\\Backups\\sql001\\Acme\\Acme_20120701-2323-LOG.trn L 74185000014093600001 74188000001233900001 74185000003175700258
jason_dev
 
Posts: 6
Joined: Mon Jul 02, 2012 10:17 pm

Postby petey » Wed Jul 04, 2012 3:48 am

While your full backup was running, another job seemed to be running transaction log backups too, in 10 minute intervals. You can find those backup files in the '\\\\Acme\\files\\Backups\\sql001\\Acme\\' folder, with the '.trn' extension.

Thus, your transaction log restore sequence now requires both native and SQL Backup files, which explains why SQL Backup encountered sequencing issues with all the SQL Backup files.
Peter Yeoh
SQL Backup Consultant Developer
Associate, Yohz Software
Beyond compression - SQL Backup goodies under the hood, updated for version 7
petey
 
Posts: 2233
Joined: Sun Apr 24, 2005 12:34 pm

Postby jason_dev » Thu Jul 05, 2012 7:50 pm

duh!

We kept the original jobs Red Gate SQL Backup is to replace running in parallel.

Case closed. Thanks Petey.
jason_dev
 
Posts: 6
Joined: Mon Jul 02, 2012 10:17 pm


Return to SQL Backup 7

Who is online

Users browsing this forum: No registered users and 1 guest