Exchange Transaction Logging in Exchange Server 2003
Microsoft® Exchange Server transaction logging is a robust disaster recovery mechanism that is designed to reliably restore an Exchange database to a consistent state after any sudden stop of the database. The logging mechanism is also used when restoring online backups.
Before changes are actually made to an Exchange database file, Exchange writes the changes to a transaction log file. After a change has been safely logged, it can then be written to the database file.
It is common for changes to become available to end users just after the changes have been secured to the transaction log, but before they have been written to the database file. Exchange employs a sophisticated internal memory management system that is tuned for high performance. Physically writing out changes to the database file is a low-priority task during normal operation. Exchange can efficiently manage caching of more than a gigabyte of database pages. This cache includes pages read from the database to fulfill client requests, as well as changed pages that will eventually be written back to the database file.
If a database suddenly stops, cached changes are not lost just because the memory cache was destroyed. On restart of the database, Exchange scans the log files, and reconstructs and applies any changes not yet written to the database file. This process is called replaying log files. The database is structured so that Exchange can determine whether any operation in any log file has already been applied to the database, needs to be applied to the database, or does not belong to the database.
Rather than write all log information to a single large file, Exchange uses a series of log files, each exactly five megabytes in size. When a log file is full, Exchange closes it and renames it with a sequence number. The first log filled ends with the name Enn00001.log. The nn refers to a two-digit number known as the base name or log prefix.
An Exchange server can have up to four storage groups, and the log files for each storage group are distinguished by file names with numbered prefixes (for example, E00, E01, E02, or E03). The log file currently open for a storage group is simply named Enn.log—it does not have a sequence number until it has been filled and closed.
The checkpoint file (Enn.chk) tracks how far Exchange has progressed in writing logged information to the database files. Typically, on a busy database, the checkpoint lags three or four log files behind the currently open log. There is a checkpoint file for each log stream, and a separate log stream for each storage group. Within a single storage group, all the databases share a single log stream. Thus, a single log file often contains operations for multiple databases.
Log files are numbered hexadecimally, so the log file after E0000009.log is E000000A.log, not E000010.log. You can convert log file sequence numbers to their decimal values using the Windows Calc.exe application in Scientific mode. To do this, run Calc, and then on the View menu, click Scientific.
You can also see the decimal sequence number for a given log file by examining its header with Eseutil.exe. The first 4-KB page of each log file contains header information that describes and identifies the log file and the databases it belongs to. The command Eseutil /ml [log filename] displays a header like the following:
Base name: e00
Log file: e00.log
lGeneration: 11 (0xB)
creation time: 12/30/2002 05:07:12
prev gen time: 12/27/2002 13:38:14
Format LGVersion: (7.3704.5)
Engine LGVersion: (7.3704.5)
Signature: Create time:12/27/2002 12:39:26 Rand:334208663 Computer:
Env SystemPath: D:\exchsrvr\mdbdata\
Env LogFilePath: D:\exchsrvr\mdbdata\
Env Log Sec size: 512
( off, 202, 10100, 1365, 10100, 384, 10240, 65421)
Using Reserved Log File: false
Circular Logging Flag (current file): off
Circular Logging Flag (past files): off
dbtime: 44889 (0-44889)
Signature: Create time:12/27/2002 12:40:16 Rand:334252058 Computer:
MaxDbSize: 0 pages
Last Attach: (0xA,199,FB)
Last Consistent: (0xA,198,8A)
dbtime: 29645 (0-29645)
Signature: Create time:12/27/2002 12:43:23 Rand:334432355 Computer:
MaxDbSize: 0 pages
Last Attach: (0xA,199,1AE)
Last Consistent: (0xA,198,8A)
Last Lgpos: (0xb,9BF,10A)
Database files have a similar header, and so does the checkpoint file. You can examine each type of header with a different Eseutil.exe command switch:
/ml displays log file headers.
/mh displays database and streaming database file headers.
/mk displays checkpoint file headers.
If you use the wrong switch for displaying a header, for example, using /ml with a database header instead of /mh, an error results or the header information that is displayed may be garbled or incorrect.
You cannot view the header of a database while it is mounted. You also cannot view the header of the current log file (Enn.log) while any database in the storage group is mounted. Exchange holds the current log file open as long as even one database is using it. You can, however, view the checkpoint file header while databases are mounted. Exchange updates the checkpoint file every thirty seconds, and its header is viewable except during the moment when an update is occurring.
As an Exchange administrator, it is an extremely valuable skill to understand Exchange file headers. If you understand the file headers, you can determine which database and log files belong together and which files are needed for successful recovery.
In this log file header example, note the first four lines:
Base name: e00
Log file: e00.log
lGeneration: 11 (0xB)
These lines show that this log file is the current log file because the Log file name does not yet have a sequence number. The lGeneration line tells you that when the log is filled and closed, its sequence number will be B, corresponding to the decimal value 11. The Base name is E00, and therefore the final log file name will be E000000B.log.
The Checkpoint value shown above is not actually read from the log file header, but it is displayed as if it were. Eseutil.exe reads the Checkpoint value directly from Enn.chk, so you do not have to enter a separate command to learn where the checkpoint is. If the checkpoint file has been destroyed, the Checkpoint value reads NOT AVAILABLE. Here, the checkpoint is in the current log file (0xB), and the numbers 7DC and 6F indicate how far into the log file the checkpoint is—which is interesting information, but you will seldom have a practical need for it.
If the checkpoint file is destroyed, Exchange can still recover and replay log files appropriately. But to do so, Exchange begins scanning log files, beginning with the oldest one available, instead of starting at the checkpoint log. Exchange skips data that has already been applied to the database and works sequentially through the logs until data that needs to be applied is encountered.
Typically, it takes but a second or two for Exchange to scan a log file that has already been applied to the database. If there are operations in a log file that need to be written to the database, it can take anywhere from 10 seconds to several minutes to apply them. On average, a log file's contents can be written to the database in 30 seconds or less.
When an Exchange database shuts down normally, all outstanding data is written to the database files. After normal shutdown, the database file set (.edb file and .stm file) is considered consistent, and Exchange detaches it from its log stream. This means that the database files are now self-contained—they are completely up-to-date. The transaction logs are not required to start the database files.
You can tell whether a database has been shut down cleanly by entering the command Eseutil /mh and examining the file headers. In Exchange 2000 Service Pack 1 and later, there is a line in the header that reads either "State: Clean Shutdown" or "State: Dirty Shutdown." Prior to this version of Exchange, the same state is reported as "State: Consistent" or "State: Inconsistent."
With all databases in a storage group disconnected and in a "Clean Shutdown" state, all log files can be safely deleted without affecting the databases. If you were then to delete all log files, Exchange would generate a new sequence of logs starting with Enn000001.log. The database files could even be moved to a different server or storage group with existing log files, and the databases would attach themselves to a different log stream.
Though you can delete the log files after all databases in a storage group have been shut down, doing so will affect your ability to restore older backups and "roll forward." The current database no longer needs the existing log files, but they may be necessary if you must restore an older database.
If a database is in a "Dirty Shutdown" state, all existing transaction logs from the checkpoint forward must be present before you can mount the database again. If these logs are unavailable, you must repair the database with Eseutil /p to make the database consistent and ready to start.
If you have to repair a database, some data may be lost. Data loss is frequently minimal; however, it may be catastrophic. After running Eseutil /p on a database, you should complete repair of the database with two further operations.
Run Eseutil/d to defragment the database. This operation discards and rebuilds all database indexes and space trees.
Run the Information Store Integrity Checker (Isinteg.exe) tool in its –fix mode. This tool scans the database for logical inconsistencies that are created by discarding outstanding transaction logs. For example, there may be references in the database that are not up-to-date with each other. Isinteg.exe attempts to correct such problems with the minimum data loss possible.
In addition to allowing Exchange to recover reliably from an unexpected database stop, transaction logging is also essential to making and restoring online backups. For more information about that process, see How Exchange Online Backups Work in Exchange Server 2003.