Exchange 2010: Adding database copies to databases with a single copy results in copy status failed after seeding is completed…


In recent weeks, I’ve worked with customers that have experienced database copies that go into a failed state immediately after adding a copy.  In all cases the following circumstances were noted:

 

  • The database previously only had a single copy.
  • The single copy database had a backup performed on it <or>
  • The single copy database utilized circular logging.

 

Let us explore the first scenario – single copy databases that have had a full backup performed. 

 

Using eseutil /k ENN I examined the log files that were present in the log directory.  Here is a sample output:

Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000001.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000002.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000003.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000004.log – OK

Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000020.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000021.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000022.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000023.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000024.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000025.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000026.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000027.log – OK

Using Window Server Backup, a full backup was performed of the single copy database.  This results in log truncation of the log stream when the backup completes successfully.  This is noted by the log truncation event present in the application log.

 

Log Name:      Application
Source:        ESE
Date:          7/1/2012 11:59:18 AM
Event ID:      224
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Information Store (3080) Mailbox Database 0958497998: Deleting log files C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000001.log to C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000028.log.
 

For more information, click http://www.microsoft.com/contentredirect.asp.

 

Using eseutil /k ENN the log sequence after backup was verified.  Here is the sample output:

 

Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000029.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000002A.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000002B.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000002C.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000002D.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000002E.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000002F.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000030.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000031.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000032.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000033.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000034.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000035.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000036.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000037.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000038.log – OK

 

As confirmed by the event and verification of the log sequence log truncation occurred successfully.

 

Using the Exchange Management Shell a copy of the database was added to the other DAG member.  The Exchange Management Shell confirms that the database seeding was successful.  The following is a sample copy status:

 

[PS] C:\>Get-MailboxDatabaseCopyStatus "Mailbox Database 0958497998\MBX-2" | fl

RunspaceId                       : 14523823-d7fe-4e42-9558-9395f418e6d0
Identity                         : Mailbox Database 0958497998\MBX-2
Name                             : Mailbox Database 0958497998\MBX-2
DatabaseName                     : Mailbox Database 0958497998
Status                           : Failed
MailboxServer                    : MBX-2
ActiveDatabaseCopy               : mbx-1
ActivationSuspended              : False
ActionInitiator                  : Service
ErrorMessage                     : The required log file 32 for Mailbox Database 0958497998\MBX-2 is missing on the act
                                   ive copy. If you removed the log file, please replace it. If the log file is lost, t
                                   he database copy will need to be reseeded using Update-MailboxDatabaseCopy.

ErrorEventId                     : 2059
ExtendedErrorInfo                :
SuspendComment                   :
SinglePageRestore                : 0
ContentIndexState                : Healthy
ContentIndexErrorMessage         :
CopyQueueLength                  : 72
ReplayQueueLength                : 0
LatestAvailableLogTime           : 7/1/2012 12:09:32 PM
LastCopyNotificationedLogTime    : 7/1/2012 12:09:32 PM
LastCopiedLogTime                :
LastInspectedLogTime             :
LastReplayedLogTime              :
LastLogGenerated                 : 72
LastLogCopyNotified              : 72
LastLogCopied                    : 0
LastLogInspected                 : 0
LastLogReplayed                  : 71
LogsReplayedSinceInstanceStart   : 0
LogsCopiedSinceInstanceStart     : 0
LatestFullBackupTime             :
LatestIncrementalBackupTime      :
LatestDifferentialBackupTime     :
LatestCopyBackupTime             :
SnapshotBackup                   :
SnapshotLatestFullBackup         :
SnapshotLatestIncrementalBackup  :
SnapshotLatestDifferentialBackup :
SnapshotLatestCopyBackup         :
LogReplayQueueIncreasing         : False
LogCopyQueueIncreasing           : False
OutstandingDumpsterRequests      : {}
OutgoingConnections              :
IncomingLogCopyingNetwork        :
SeedingNetwork                   :
ActiveCopy                       : False

The application log on the server on which the copy was added also has the following event:

 

Log Name:      Application
Source:        MSExchangeRepl
Date:          7/1/2012 12:09:35 PM
Event ID:      2059
Task Category: Service
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The required log file 32 for Mailbox Database 0958497998\MBX-2 is missing on the active copy. If you removed the log file, please replace it. If the log file is lost, the database copy will need to be reseeded using Update-MailboxDatabaseCopy.

 

Note:  The log file name displayed in this event is a decimal value.  The value is converted from decimal to hexadecimal in order to identify the log file.  Log file names are in hexadecimal format.

 

If the seed is attempted again using update-mailboxdatabasecopy the same error is displayed.  In this case log file 32 (0x20) is necessary to satisfy the seeding request and the lack of the log file will prevent the seed from being successful.  Why is this log file necessary and why is it missing from the active copy?  We’ll answer that question a little later…

 

Let us explore the second scenario – single copy databases that is using circular logging.

 

In this case there is a database with a single copy.  This database has had circular logging enabled. 

 

Using eseutil /k I examined the log files that were present in the log file directory.  Here is a sample output:

 

Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000049.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000004A.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000004B.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000004C.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000004D.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000004E.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000004F.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000050.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000051.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000052.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000053.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000054.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000055.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000056.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000057.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000058.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000059.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000005A.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000005B.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000005C.log – OK

 

At this point circular logging was disabled, and the database was dismounted and then mounted.  This is a requirement for databases with a single copy before adding an additional copy.

 

Using eseutil /k I examined the log files that were present in the directory prior to adding the copy.  Here is a sample output:

 

Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000005D.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000005E.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000005F.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000060.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000061.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000062.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000063.log – OK

Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000007C.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000007D.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000007E.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000007F.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000080.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000081.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000082.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000083.log – OK
Log file: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E0000000084.log – OK

Using the Exchange Management Shell a copy of the database was added to the other DAG member.  Exchange Management Shell confirms that the database seeding was successful. The following is a sample copy status:

 

[PS] C:\>Get-MailboxDatabaseCopyStatus "Mailbox Database 0958497998\MBX-2" | fl

RunspaceId                       : 14523823-d7fe-4e42-9558-9395f418e6d0
Identity                         : Mailbox Database 0958497998\MBX-2
Name                             : Mailbox Database 0958497998\MBX-2
DatabaseName                     : Mailbox Database 0958497998
Status                           : Failed
MailboxServer                    : MBX-2
ActiveDatabaseCopy               : mbx-1
ActivationSuspended              : False
ActionInitiator                  : Service
ErrorMessage                     : The required log file 73 for Mailbox Database 0958497998\MBX-2 is missing on the act
                                   ive copy. If you removed the log file, please replace it. If the log file is lost, t
                                   he database copy will need to be reseeded using Update-MailboxDatabaseCopy.

ErrorEventId                     : 2059
ExtendedErrorInfo                :
SuspendComment                   :
SinglePageRestore                : 0
ContentIndexState                : Healthy
ContentIndexErrorMessage         :
CopyQueueLength                  : 72
ReplayQueueLength                : 0
LatestAvailableLogTime           : 7/1/2012 2:12:32 PM
LastCopyNotificationedLogTime    : 7/1/2012 2:12:32 PM
LastCopiedLogTime                :
LastInspectedLogTime             :
LastReplayedLogTime              :
LastLogGenerated                 : 132
LastLogCopyNotified              : 131
LastLogCopied                    : 0
LastLogInspected                 : 0
LastLogReplayed                  : 131
LogsReplayedSinceInstanceStart   : 0
LogsCopiedSinceInstanceStart     : 0
LatestFullBackupTime             :
LatestIncrementalBackupTime      :
LatestDifferentialBackupTime     :
LatestCopyBackupTime             :
SnapshotBackup                   :
SnapshotLatestFullBackup         :
SnapshotLatestIncrementalBackup  :
SnapshotLatestDifferentialBackup :
SnapshotLatestCopyBackup         :
LogReplayQueueIncreasing         : False
LogCopyQueueIncreasing           : False
OutstandingDumpsterRequests      : {}
OutgoingConnections              :
IncomingLogCopyingNetwork        :
SeedingNetwork                   :
ActiveCopy                       : False

The application log on the member where the copy was added also has the following event:

 

Log Name:      Application
Source:        MSExchangeRepl
Date:          7/1/2012 2:12:35 PM
Event ID:      2059
Task Category: Service
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The required log file 73 for Mailbox Database 0958497998\MBX-2 is missing on the active copy. If you removed the log file, please replace it. If the log file is lost, the database copy will need to be reseeded using Update-MailboxDatabaseCopy.

 

If the seed is attempted again using update-mailboxdatabasecopy the same error is displayed. In this case log file 73 (0x49) is necessary to satisfy the seeding request and the lack of the log file will prevent the seed from being successful.

 

Why does this issue occur?

When a database copy is created and subsequently seeded between nodes the Replication services establish a global truncation point.  The global truncation point represents the log files that are safe to truncate across all copies of a given database that exist within the DAG.  This process takes into account a feature introduced in Exchange 2010 SP1 known as checkpoint at log creation.  For an example of how checkpoint at log creation works in Exchange 2010 refer to http://blogs.technet.com/b/timmcmic/archive/2012/03/12/exchange-2010-log-truncation-and-checkpoint-at-log-creation-in-a-database-availability-group.aspx.

 

The Replication service establishes the global truncation point based on the checkpoint at log creation of the lowest order log file on the active copy.  Running eseutil /ml on the lowest order log file on the active copy shows the following header information:

 

Extensible Storage Engine Utilities for Microsoft(R) Exchange Server
Version 14.02
Copyright (C) Microsoft Corporation. All Rights Reserved.

Initiating FILE DUMP mode…

      Base name: E00
      Log file: E00000001E6.log
      lGeneration: 486 (0x1E6)
      Checkpoint: (0x360,80,0)
      creation time: 08/05/2012 06:25:24
      prev gen time: 08/05/2012 06:25:24
      Format LGVersion: (7.3704.16.2)
      Engine LGVersion: (7.3704.16.2)
      Signature: Create time:07/02/2012 08:31:36 Rand:2868451 Computer:
      Env SystemPath: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\
      Env LogFilePath: C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\
      Env Log Sec size: 4096 (matches)
      Env (CircLog,Session,Opentbl,VerPage,Cursors,LogBufs,LogFile,Buffers)
          (    off,   1227,  61350,  16384,  61350,   2048,    256,  29487)
      Using Reserved Log File: false
      Circular Logging Flag (current file): off
      Circular Logging Flag (past files): on
      Checkpoint at log creation time: (0x186,1,0)
      1 C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\Mailbox Database 0958497998.edb
                 dbtime: 964150 (0-964150)
                 objidLast: 4617
                 Signature: Create time:07/02/2012 08:31:36 Rand:2859643 Computer:
                 MaxDbSize: 0 pages
                 Last Attach: (0x16D,1,270)
                 Last Consistent: (0x16C,1,1F)

      Last Lgpos: (0x1e6,FF,0)

Number of database page references:  922

Integrity check passed for log file: E00000001E6.log

Operation completed successfully in 0.78 seconds.

 

In this case the checkpoint at log creation when the log file 0x1E6 was created was in log file 0x186.  Therefore the global truncation point is established at 0x186 (390).  The event establishing the global truncation point is present in the active copy’s High Availability \ TruncationDebug log:

 

Log Name:      Microsoft-Exchange-HighAvailability/TruncationDebug
Source:        Microsoft-Exchange-HighAvailability
Date:          8/5/2012 7:07:04 AM
Event ID:      224
Task Category: TruncationSource
Level:         Information
Keywords:     
User:          SYSTEM
Computer:      MBX-1.exchange.msft
Description:
Global truncation point for database ’46f2fd7f-4a8e-4c56-81ac-51707746dfe2′ calculated ‘390’ with the value from server ‘390’.


When the seeding of the database file is successful the Replication service on the passive copy establishes a log shipping process.  At this time the global truncation point is read to determine where log file copying must start.

 

37683 00000000 1268 Cluster.Replay LogTruncater RequestGlobalTruncationCoordination for db 46f2fd7f-4a8e-4c56-81ac-51707746dfe2 notified our lowest is 0x234, learned the global truncation is 0x186

 

The Replication service establishes that the first log file that must be copied is the checkpoint at log creation of the lowest log file found on the active copy or in simpler terms the log file identified as the global truncation point.

 

37686 01E6E81B 1268 Cluster.Replay ReplicaInstance Log copying will start from generation 390

 

The Replication service then queries the source Replication service to determine the range of log files present on the active copy.

 

37758 009BAD9B 1268 Cluster.Replay LogCopyClient LogCopyClient:QueryLogRange: 0x1e6 .. 37a

 

At this time it is determined that the necessary log files do not exist on the active copy and the copy status is set to failed even though the database seeding was successful.

 

37760 00000000 1268 Cluster.Replay ReplayApi FormatMessage( 3221489675 ) was successful. Message: The required log file 390 for Mailbox Database 0958497998\MBX-2 is missing on the active copy. If you removed the log file, please replace it. If the log file is lost, the database copy will need to be reseeded using Update-MailboxDatabaseCopy.
.

Where did this log file go?  If you review the backup events from the successful backup of the single copy database the following event is noted:

 

Log Name:      Application
Source:        ESE
Date:          8/5/2012 6:37:32 AM
Event ID:      224
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Information Store (3172) Mailbox Database 0958497998: Deleting log files C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E000000016E.log to C:\Program Files\Microsoft\Exchange Server\V14\Mailbox\Mailbox Database 0958497998\E00000001E5.log.
 

 

In this case the log file necessary for a successful seed operation was removed as a result of a successful full backup.  Remember that when a database has a single copy log truncation as a result of a full backup, incremental backup, or circular logging is under control of the Information Store service.  Whenever a database has multiple copies the Replication service handles these tasks.  In this instance the Information Store service utilizes different rules for log truncation than the Replication service does.  The Information Store service does not account for the global truncation point when performing log truncation.

 

This behavior cannot be altered.

 

How does one work around this issue?

 

Unfortunately once a database is converted from single copy to multiple copies and a seed operation has been completed the target database cannot be utilized.  The process must be started over again with a few modifications.

 

First the database copy should be added to the remote node with the seedingPostponed flag set to true.  This will update Active Directory with the additional database copy and will attempt to inform the target Replication service that a copy was added. 

 

add-mailboxdatabasecopy “DBName” –mailboxServer “TargetServer” –seedingPostponed:$TRUE

 

Second circular logging should be enabled on the database.  This does not require the database to be dismounted and mounted since the database now has multiple copies and when using continuous replication circular logging this flag can be set dynamically. 

 

set-mailboxdatabase “DBNAME” –circularLogging:$TRUE

 

It is very important at this step that sufficient time exists for the circular logging flag to replicate through Active Directory and for the target Replication service to acknowledge that circular logging is enabled.  If subsequent steps are attempted prior to all nodes acknowledging the change the missing log file failure condition will be encountered.

 

Third the database must be seeded to the passive node.

 

update-mailboxdatabasecopy “DBName\Server” –deleteExistingFiles:$TRUE

 

Lastly the health of the copy can be verified with get-mailboxdatabsecopystatus.  Here is an example of a successful seeding operation of our example database that experienced this issue and utilized this process:

 

[PS] C:\Windows\system32>Get-MailboxDatabaseCopyStatus

Name                                          Status          CopyQueue ReplayQueue LastInspectedLogTime   ContentIndex
                                                              Length    Length                             State
—-                                          ——          ——— ———– ——————–   ————
Mailbox Database 1608324257\MBX-2             Mounted         0         0                                  Healthy
Mailbox Database 0958497998\MBX-2             Healthy         0         0           8/5/2012 7:47:08 AM    Healthy

Why does this process work?

 

At the end of a seed operation where circular logging is enabled the replication service simply begins log copying at the first log file found.  It is not concerned with maintaining the same log states between nodes as it is when circular logging is not enabled.  Therefore enabling circular logging in this situation allows us to bypass this problem.

 

Once seeding is successful circular logging can be dynamically disabled using the set-mailboxdatabase command.

 

set-mailboxdatabase “DBNAME” –circularLogging:$FALSE

 

When circular logging is disabled a backup should be taken if desired.  When circular logging was utilized by this process log files were truncated off of both copies leaving previous backups taken unable to be utilized for roll forward recovery.  The next backup taken would become the recovery point for roll forward recovery should a restoration be necessary.  Until the backup is taken the database availability group should be sufficient to provide primary data protection.


Comments (45)

  1. Anonymous says:

    great trick, thanks.

  2. TIMMCMIC says:

    @RP75

    Thanks for posting an alternative. I have not tested it, but in guessing adding the database with suspension and then performing the backup allowed for the full backup header to become updated. Then subsequently reseeding would allow log copy to start based off the alternate information.

    TIMMCMIC

  3. TIMMCMIC says:

    @TardisMaximums:

    It’s really not about recommending it one way or another. If you have an information store that has zero copies, and has had a backup performed, and then you add a copy you will hit this issue. This is the only way short of resetting the log stream and adding / seeding the copy again to get around it while keeping the source store online.

    TIMMCMIC

  4. Anonymous says:

    @DCSandoz…

    As you pointed out the draw back here is the user outage.  These steps do not incur any user outage.

    Also I'd have to trace this out specifically to ensure – in theory the rules regarding how logs are copied based on CALC should still apply even if the source database was dismounted.

    TIMMCMIC

  5. TIMMCMIC says:

    @Ed…

    NP

    TIMMCMIC

  6. khemarin Set says:

    Dear TIMMCMIC,

    it’s great article 🙂

    Just my thought, Can we create the new database then moving all mailbox to the new database?

    BR,
    Khemarin

  7. Anonymous says:

    Do you have to keep circular logging enabled for the DB copy replication to continue taking place?

  8. TIMMCMIC says:

    @Me…

    If something is unclear let me know.

    TIMMCMIC

  9. Anonymous says:

    Never mind, helps to read the whole thing… #smh lol

  10. TIMMCMIC says:

    @Simple Issue

    I’d have to look at the logs to explain that. It should not have gone into a healthy state.

    TIMMCMIC

  11. TIMMCMIC says:

    @@Khemarin…
    I’m not sure what you mean by this comment.

    You can always create a new database, add the copies, and migrate the users to it.

    If you create any single copy database and perform a backup of it you will have this issue.

    TIMMCMIC

  12. TIMMCMIC says:

    @Baconator

    I am not sure what you are referring to with the dismount / remount method, I am also equally not sure what tricking is here, In this example enabling circular logging is as simple as running a command. With the exception of breaking backup / restore streams it should be rather non-frustrating, It also does not incur any downtime. Repairing the database prior to performing these operations should never be considered. Running a repair, defragment, and then subsequently repairing each mailbox within the database just to satisfy the seed would not be something I would recommend.

    TIMMCMIC

  13. Ed (DareDevil57) says:

    thanks

  14. TIMMCMIC says:

    @Simple Issue…

    The decision to change or fix code is always a balance between the cost of taking the change, the potential destabilizations that may occur, and many other factors. Although this would seem like a “simple issue” the change is potentially very complicated as it crosses two different processes. Architecturally to fix this would require modifying portions of the store code while the replicated database behavior resides within the replication service.

    With that in mind – the number of cases that present to support with this particular issue were very low. When looking at the majority of database handling in a DAG it appeared the more common method was to have the DAG fully established and have the copies fully established prior to backing them up or moving mailboxes to them. With that in mind though there should not be an issue with backing up a single copy database that is populated etc. In some cases this issue was actually encountered by customers who were intentionally removing all copies and readding them (with backups that has occurred in between). The issue becomes even less frequent as we continue to see installations moving to native data protection and forgoing all backups completely.

    The workaround highlighted here is simple and low risk with the only side effect being the break of the restore chain moving from a single database to a database with a copy. In the long run that risk is even further mitigated by the fact that you are using a database availability group and would hopefully by now have more than one copy of a database. (The break only occurs after the database copy has successfully seeded and log files start to ship – implying a healthy copy to move to in the short term).

    Given the simple work around, the low overall impact, and the high overall impact of taking a code change the decision is to not fix the issue but rather work around it.

    Thanks

    TIMMCMIC

  15. TIMMCMIC says:

    @Thomas:

    I’m glad you found it helpful.

    TIMMCMIC

  16. Anonymous says:

    @Serhad:

    Thanks!

    TIMMCMIC

  17. RP75 says:

    This article wasn’t easy to find but I’m glad I did! I enabled the suspended copy, let the full backups and log truncation run overnight then updated the mailbox database copy the next day. Saved me from having to enable circular logging.

  18. TIMMCMIC says:

    @Me..

    I have no idea how you’ve missed this wonderful post! I’m glad it was able to help…

    TIMMCMIC

  19. Anonymous says:

    Thank you very much

  20. Anonymous says:

    @Ajay:

    Depends – are you running into the situation outlined in this article? If so then yes if you disable circular logging before seeding the database the copy will still fail.

    TIMMCMIC

  21. DCSandoz says:

    I ran into this issue and figured out that I can get the copy to a healthy status by simply suspending the failed copy (if not already suspended) and dismounting the source database, and resuming the copy while the source is dismounting. Obviously, I did the dismount outside business hours, so worked beautifully.

  22. Tony says:

    TIMMCMIC, great work! This has been extremely helpful in resolving our issue when DPM backed up a active copy of a database while replication was down due to maintenance.  

    Do you know if it is possible to dynamically enable circular logging and have it clear the logs, for a database WITHOUT seeding it to a passive node?  I am trying to prevent an outtage without adding a ton of expensive storage for a temporary need.  

  23. Andrew says:

    Just wanted to say thanks for the Article, fixed my problems, instructions are spot on. Thank you!

  24. TIMMCMIC says:

    @Andrew:

    Thanks

    TIMMCMIC

  25. Baconator says:

    I wonder how safe the “dismount/resume” method is. I have a funny feeling that it doesn’t play back the latest logs when it fails due to missing earlier logs, and therefor leaves a gap. I expect that, even though enabling circular logging is rather frustrating, it is safer than “tricking” exchange into using the seeded database. Maybe if you repaired the database before “tricking” it…

  26. Having experienced this issue on our first (of many) database copies, would you recommend following this method when creating initial copies of our other info stores? I will note that your procedure did fix our problem, I’m just gun shy about kicking off some of our more mission critical stores.

  27. Simple issue says:

    It seems to me that this issue is rather simple and that most people would run in to this problem. Would it not have been good of microsoft to come up with a solution to this problem as a part of the software? So that you could just make a database copy even if you have zero copies and you have performed a backup. Wouldn’t have that been a better solution than having to break all my exchange backups?

  28. Simple issue says:

    Hi thank you for the prompt and informative response. I suspected that there would be a good justification for it.

    We ran in to this issue because we upgraded to 2010 from 2003 before adding the second 2010 server as we were waiting on a wan link, which was not installed until after the upgrade.

    Interestingly, I managed to seed db2 first time without any problems but suspect that i may have added it suspended and then the following day seeded it, at the time not knowing what i did differently that allowed it to work first time.

    I had on the weekend tried another seed of the db1 (before find this article) this db had failed to seed many times as i have been trying for a few months on this problem and not wanting to rename the logs folder as described by many blog and forums posts on the topic.

    What I did:

    1) removed the failed seed. (without deleting the actual files) this is after a successful seed of the db with a log file error as described in your blog post exactly.
    2) enabled circular logging on the db. Waited 30 mins for it replicate.
    3) ran the seed command only to be told the DB is not in a suspended state. Ran Get-MailboxDatabaseCopyStatus only to find that it is in a healthy state.
    4) disabled circular logging.

    This is essentially the same as what you said except i didn’t have to reseed.

    Thanks for the blog post and taking the time to respond.

  29. simple issue says:

    What would you suggest then? to not turn off circular logging right away?

    Should I re-renable circular logging and suspend the copy and reseed it with delete existing files? I checked the folders and the log and edb file look ok on the secondary server and the replication status says healthy.

    I am bit concerned now.

  30. Thomas says:

    Excellent Article.Thank You!

  31. hero says:

    this article help me resolve my datbae copy add problems thanks

  32. Anonymous says:

    拔罐减肥   第一:通过拔罐减肥能有效调节脂质的代 自然美化脂酵素 谢过程。肥胖症患者的体中过氧化脂质高于正常值,拔罐打通人体减肥要穴后,可以使人体中过氧化脂质含量下降,加速脂房的新 自然美化脂酵素如何辨别真假 陈代谢,从而达到减肥目的。  第二:可以纠正患者的异常食欲,通过对神经系统的调节,可以抑制胃酸分泌过多,达到不乏力、不饥饿的目的。拔罐以后,胃的排空减慢,胃不空了,自然就有饱的感觉,可以不太想吃东西了。  第三:在于有效调节内分泌紊乱。肥胖症患者的内分泌紊 自然美化脂酵素副作用 乱发生率极高

  33. Me says:

    how did I miss this post:)?
    amazing info to know, I seen this many times and used to dismount remove logs and mount.
    which isn’t even supposed to work in DAG(I removed copies before that’s probably why it worked)
    this is much simpler and supported.
    Thanks

  34. Me says:

    i also have no idea:)
    i already read it like 3 times just to understand what the "lowest log" is
    i am sure 99.99% of people handling exchange dont have a clue about this whole procedure or the fact that c.logging doesn’t require dismount mount.
    they think "backup should truncate logs" and that’s where it ends:)
    blame Symantec:)

  35. Ajay Siwach says:

    Hi Tim,
    Thanks for the great article…just curious to know that I just ran the below commands and the database copy was showing Healthy, :

    add-mailboxdatabasecopy “Mailbox Database” –mailboxServer “mb” –seedingPostponed:$TRUE

    set-mailboxdatabase “Mailbox Database” –circularLogging:$TRUE

    I did not run
    Update-MailboxDatabaseCopy -Identity "Mailbox DatabaseMB" -DeleteExistingFiles

    But, I have not yet disabled circular logging. will it have any impact if I disable circular logging without reseeding it?

    Thanks in advance
    Ajay Siwach

  36. Amol pawar says:

    Thank you very much for sharing this..

  37. A Malik says:

    Hi Tim,

    Nice article, regarding this step in your article,

    "It is very important at this step that sufficient time exists for the circular logging flag to replicate through Active Directory and for the target Replication service to acknowledge that circular logging is enabled. If subsequent steps are attempted prior
    to all nodes acknowledging the change the missing log file failure condition will be encountered."

    Will it be achieved by restarting the active directory topology service on the target server if it is in same AD site?

    And if a remote site is involved then doing a force replication through AD sites & services before restarting the topology service?

  38. TIMMCMIC says:

    @A Malik:

    The circular logging flag actually needs to be detected by the replication service. Restarting the AD topology service will have no impact here. I’m not recommending that any services be restarted – rather AD replication must be allowed and the replication
    service should refresh its configuration every 15 minutes.

    TIMMCMIC

  39. A Malik says:

    Thanks for the clarification.

  40. G-Squared says:

    @TIMMCMIC

    We have 10 databases however I am only seeing this issue on half of them, why is that? They were all backed up at the same time but some seed without a problem while others fail with this error.

  41. TIMMCMIC says:

    @G-Squared…

    This is all about the log files. If the databases were all single copy at the time they were backed up they should have all experienced the same issue.

    TIMMCMIC

  42. G-Squared says:

    @TIMMCMIC

    Thanks for the response. Since I wrote I had 5 databases seeded and functioning and 5 that will not seed. However, now all but 1 have failed. I still don’t understand why 1 continues to work and all the rest repeatedly fail, doesn’t make much sense. I guess
    my only option is to follow your instructions to correct the log issue and get them to seed but I am a bit confused about the affect this will have on my backups. Does this mean I would not be able to do a full recovery from prior to enabling circular logging?
    If so does that render all previous backups worthless or would I still be able to restore individual items from those backups?

  43. Amjad says:

    Helpful and Useful
    Thanks A lot

  44. Matt Mauchley says:

    Can a backup be run while the DB is seeding or should backups be paused until the seeding is finished and the Circular Logging Flag is turned back off?

  45. TIMMCMIC says:

    @Matt:

    Thanks for reaching out to me.

    When a database is seeding a backup cannot be performed of the database. Exchange will actually block this from happening. The seeding framework uses the ESE streaming backup API to perform the seed – so to Exchange a backup of the database is currently in
    progress.

    TIMMCMIC