Wednesday, April 6, 2011

Quiz: Which log backups are required to restore a database?

Lets say you have a subfolder structure containing the following database backup files:


...\backup\generation10
ddd12.db
ddd12.log
...\backup\generation10\logs
110405AA.log
110405AB.log
110405AC.log

The ddd12.db and ddd12.log backup files were created by a single full backup run of dbbackup:

"%SQLANY12%\bin32\dbbackup.exe"^
-c "ENG=ddd12;DBN=ddd12;UID=dba;PWD=sql"^
-x^
backup\generation10

The yymmddXX.log files were created by three subsequent runs of an incremental log backup process:

"%SQLANY12%\bin32\dbbackup.exe"^
-c "ENG=ddd12;DBN=ddd12;UID=dba;PWD=sql"^
-n^
-t^
-x^
backup\generation10\logs

Is ddd12.log necessary?


Question: When it comes time to restore ddd12.db backup file and apply the subsequent *.log backup files, is it necessary to apply ddd12.log before applying the yymmddXX.log files?

Or can ddd12.log be skipped and just the yymmddXX.log files applied?

The following simple experiment is inconclusive. According to Demonstrating Full and Incremental Backups the following restore process works OK even though it skips ddd12.log:

"%SQLANY12%\bin32\dbsrv12.exe"^
-o backup\generation10\dbbackup_log.txt^
-oe dbsrv12_log_fatal_ddd12.txt^
-os 10M^
ddd12.db^
-ad backup\generation10\logs

I. 04/05 06:37:02. SQL Anywhere Network Server Version 12.0.1.3298 I. 04/05 06:37:02. Developer edition, not licensed for deployment.
I. 04/05 06:37:02. I. 04/05 06:37:02. Copyright © 2001-2011, iAnywhere Solutions, Inc.
I. 04/05 06:37:02. Portions copyright © 1988-2011, Sybase, Inc. All rights reserved.
I. 04/05 06:37:02. Use of this software is governed by the Sybase License Agreement.
I. 04/05 06:37:02. Refer to http://www.sybase.com/softwarelicenses.
I. 04/05 06:37:02. I. 04/05 06:37:02. Connection limit (licensed seats): 3
I. 04/05 06:37:02. Processors detected: 1 (containing 8 logical processors)
I. 04/05 06:37:02. Maximum number of physical processors the server will use: 1
I. 04/05 06:37:02. This server is licensed to:
I. 04/05 06:37:02. Developer Edition
I. 04/05 06:37:02. Restricted Use
I. 04/05 06:37:02. Running Windows 7 Build 7600 on X86_64
I. 04/05 06:37:02. Server built for X86 processor architecture
I. 04/05 06:37:02. 3216K of memory used for caching
I. 04/05 06:37:02. Minimum cache size: 2956K, maximum cache size: 3474688K
I. 04/05 06:37:02. Using a maximum page size of 4096 bytes
I. 04/05 06:37:02. Multiprogramming level: minimum:8, current:20, maximum:80
I. 04/05 06:37:02. Automatic tuning of multiprogramming level is enabled
I. 04/05 06:37:02. Starting database "ddd12" (C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:02. Database recovery in progress
I. 04/05 06:37:02. Last checkpoint at Tue Apr 05 2011 06:36
I. 04/05 06:37:02. Checkpoint log...
I. 04/05 06:37:02. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\logs\110405AA.log...
I. 04/05 06:37:02. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:03. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:03. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:03. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:03. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\logs\110405AB.log...
I. 04/05 06:37:03. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:04. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:04. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:04. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:04. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\logs\110405AC.log...
I. 04/05 06:37:04. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:05. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:05. Checkpointing...
I. 04/05 06:37:05. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:05. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:37
I. 04/05 06:37:05. Recovery complete
I. 04/05 06:37:05. Database server shutdown automatically after log applied
I. 04/05 06:37:05. Database server stopped at Tue Apr 05 2011 06:37

However, the same restore process also works OK when it is modified to apply ddd12.log before the yymmddXX.log files:

"%SQLANY12%\bin32\dbsrv12.exe"^
-o backup\generation10\dbbackup_log.txt^
-oe dbsrv12_log_fatal_ddd12.txt^
-os 10M^
ddd12.db^
-ad backup\generation10

"%SQLANY12%\bin32\dbsrv12.exe"^
-o backup\generation10\dbbackup_log.txt^
-oe dbsrv12_log_fatal_ddd12.txt^
-os 10M^
ddd12.db^
-ad backup\generation10\logs

I. 04/05 06:31:30. SQL Anywhere Network Server Version 12.0.1.3298 I. 04/05 06:31:30. Developer edition, not licensed for deployment.
I. 04/05 06:31:30. I. 04/05 06:31:30. Copyright © 2001-2011, iAnywhere Solutions, Inc.
I. 04/05 06:31:30. Portions copyright © 1988-2011, Sybase, Inc. All rights reserved.
I. 04/05 06:31:30. Use of this software is governed by the Sybase License Agreement.
I. 04/05 06:31:30. Refer to http://www.sybase.com/softwarelicenses.
I. 04/05 06:31:30. I. 04/05 06:31:30. Connection limit (licensed seats): 3
I. 04/05 06:31:30. Processors detected: 1 (containing 8 logical processors)
I. 04/05 06:31:30. Maximum number of physical processors the server will use: 1
I. 04/05 06:31:30. This server is licensed to:
I. 04/05 06:31:30. Developer Edition
I. 04/05 06:31:30. Restricted Use
I. 04/05 06:31:30. Running Windows 7 Build 7600 on X86_64
I. 04/05 06:31:30. Server built for X86 processor architecture
I. 04/05 06:31:30. 3216K of memory used for caching
I. 04/05 06:31:30. Minimum cache size: 2956K, maximum cache size: 3474688K
I. 04/05 06:31:30. Using a maximum page size of 4096 bytes
I. 04/05 06:31:30. Multiprogramming level: minimum:8, current:20, maximum:80
I. 04/05 06:31:30. Automatic tuning of multiprogramming level is enabled
I. 04/05 06:31:30. Starting database "ddd12" (C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:30. Database recovery in progress
I. 04/05 06:31:30. Last checkpoint at Tue Apr 05 2011 06:31
I. 04/05 06:31:30. Checkpoint log...
I. 04/05 06:31:40. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\ddd12.log...
I. 04/05 06:31:40. Checkpointing...
I. 04/05 06:31:40. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:41. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:41. Recovery complete
I. 04/05 06:31:41. Database server shutdown automatically after log applied
I. 04/05 06:31:41. Database server stopped at Tue Apr 05 2011 06:31
I. 04/05 06:31:42. SQL Anywhere Network Server Version 12.0.1.3298 I. 04/05 06:31:42. Developer edition, not licensed for deployment.
I. 04/05 06:31:42. I. 04/05 06:31:42. Copyright © 2001-2011, iAnywhere Solutions, Inc.
I. 04/05 06:31:42. Portions copyright © 1988-2011, Sybase, Inc. All rights reserved.
I. 04/05 06:31:42. Use of this software is governed by the Sybase License Agreement.
I. 04/05 06:31:42. Refer to http://www.sybase.com/softwarelicenses.
I. 04/05 06:31:42. I. 04/05 06:31:42. Connection limit (licensed seats): 3
I. 04/05 06:31:42. Processors detected: 1 (containing 8 logical processors)
I. 04/05 06:31:42. Maximum number of physical processors the server will use: 1
I. 04/05 06:31:42. This server is licensed to:
I. 04/05 06:31:42. Developer Edition
I. 04/05 06:31:42. Restricted Use
I. 04/05 06:31:42. Running Windows 7 Build 7600 on X86_64
I. 04/05 06:31:42. Server built for X86 processor architecture
I. 04/05 06:31:42. 3216K of memory used for caching
I. 04/05 06:31:42. Minimum cache size: 2956K, maximum cache size: 3474688K
I. 04/05 06:31:42. Using a maximum page size of 4096 bytes
I. 04/05 06:31:42. Multiprogramming level: minimum:8, current:20, maximum:80
I. 04/05 06:31:42. Automatic tuning of multiprogramming level is enabled
I. 04/05 06:31:42. Starting database "ddd12" (C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:42. Database recovery in progress
I. 04/05 06:31:42. Last checkpoint at Tue Apr 05 2011 06:31
I. 04/05 06:31:42. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\logs\110405AA.log...
I. 04/05 06:31:42. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:42. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:42. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:43. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:43. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\logs\110405AB.log...
I. 04/05 06:31:43. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:43. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:44. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:44. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:44. Transaction log: C:\projects\$SA_templates\run\dbbackup\demo_restore_incremental_backup12\backup\generation10\logs\110405AC.log...
I. 04/05 06:31:44. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:44. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:44. Checkpointing...
I. 04/05 06:31:44. Starting checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:45. Finished checkpoint of "ddd12" (ddd12.db) at Tue Apr 05 2011 06:31
I. 04/05 06:31:45. Recovery complete
I. 04/05 06:31:45. Database server shutdown automatically after log applied
I. 04/05 06:31:45. Database server stopped at Tue Apr 05 2011 06:31

Huh?


So, what's the answer? Why do both restores work?

And which method should be used?

2 comments:

Thomas Dümesnil said...

I don't know the details behind the scenes but it can happen that unfinished transactions are recorded in the full backup log file ddd12.log.

In the incremental log files the transaction is continued and perhaps later on committed.

This happened to me when during the backup process many transactions were running.

After the backup I was not able to add incremental log files to the full backup db without adding first the full log file.

The Database brought a failure when I tried to add the incremental directly.

Normally if the Database is more or less in idle mode you can directly add the incremental logs. But if you want to be on the safe side add the main log always first.

This is what I figured out. HTH
Thomas

Anonymous said...

AFAIK, the official answer is to ALWAYS use the log from the full database backup as a starting point.

As Thomas has pointed out, it may contain transactions that were in progress (or even had not started) when the backup started. As such, their effect may not be part of the database backup, simply as the according pages may be backuped up before the transaction has altered them.

As you are doing the full database backup with -x, I would suspect that such transactions won't be contained in the newly created log (which is the first incremental one), and in such cases a restore will fail.

So I would conclude that your test happen to do not have such transactions, and therefore the recovery without the original log happens to succeed.

In general, particularly with a busy server, ongoing transactions might occur, and therefore the original log MUST be used as the first applied log when using dbbackup -x. Otherwise the recovery just might not work, and then the backup is pointless.

When using dbbackup without -x, it might not be that necessary, but even then I would suggest to apply that log initially, and then apply the last log. The engine options -ad or ar might help further.

Volker