Verifying the file share witness server / directory in use for Exchange 2010

19 Replies

If you’ve read my blog post on file share witness oddities you might be asking yourself “how can I actually verify what file share witness is in use in my environment?”

There are three different ways to verify the witness in use for Exchange 2010.

1) Exchange Management Shell

The Get-databaseavailabilitygroup –status command returns all the settings for the DAG from Active Directory. By adding the –status switch we also query additional values from the Cluster service and Replication service. These are not queried by default as they can delay the command from returning normal configuration values. Here is an example of the output:

[PS] C:>Get-DatabaseAvailabilityGroup -Identity DAG -Status | fl

RunspaceId                             : 717eb01d-a17b-4e8e-b018-acf00a0d748d
Name                                   : DAG
Servers                                : {DAG-4, DAG-3, DAG-2, DAG-1}
WitnessServer                          : mbx-1.domain.com
WitnessDirectory                       : c:DAG-FSW
AlternateWitnessServer                 : mbx-2.domain.com
AlternateWitnessDirectory              : c:DAG-FSW
NetworkCompression                     : Enabled
NetworkEncryption                      : Enabled
DatacenterActivationMode               : DagOnly
StoppedMailboxServers                  : {}
StartedMailboxServers                  : {DAG-3.domain.com, DAG-4.domain.com, DAG-2.domain.com, DAG-1.domain.com}
DatabaseAvailabilityGroupIpv4Addresses : {10.0.0.24}
DatabaseAvailabilityGroupIpAddresses   : {10.0.0.24}
AllowCrossSiteRpcClientAccess          : False
OperationalServers                     : {DAG-1, DAG-2, DAG-4, DAG-3}
PrimaryActiveManager                   : DAG-1
ServersInMaintenance                   : {}
ThirdPartyReplication                  : Disabled
ReplicationPort                        : 64327
NetworkNames                           : {DAG-4-iSCSI, DAG-MAPI, DAG-REPL-A, DAG-REPL-B}
WitnessShareInUse                      : Primary
AdminDisplayName                       :
ExchangeVersion                        : 0.10 (14.0.100.0)
DistinguishedName                      : CN=DAG,CN=Database Availability Groups,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=domain Home,CN=Microsoft Exchange`,CN=Services,CN=Configuration,DC=home,DC=domain,DC=com
Identity                               : DAG
Guid                                   : 72c87136-6721-46e6-ac43-2ad5f6bd66d2
ObjectCategory                         : domain.com/Configuration/Schema/ms-Exch-MDB-Availability-Group
ObjectClass                            : {top, msExchMDBAvailabilityGroup}
WhenChanged                            : 1/29/2012 5:34:25 PM
WhenCreated                            : 9/19/2009 6:16:52 PM
WhenChangedUTC                         : 1/29/2012 10:34:25 PM
WhenCreatedUTC                         : 9/19/2009 10:16:52 PM
OrganizationId                         :
OriginatingServer                      : DC-5.domain.com
IsValid                                : True

In this example you can see the attribute WitnessShareInUse with a value of Primary. This lets the administrator know that the current witness configured for cluster use is the primary file share witness (in this case the witness server and witness directory).

Name                      : DAG
Servers                   : {DAG-4, DAG-3, DAG-2, DAG-1}
WitnessServer             : mbx-1.domain.com
WitnessDirectory          : c:DAG-FSW
AlternateWitnessServer    : mbx-2.domain.com
AlternateWitnessDirectory : c:DAG-FSW
OperationalServers        : {DAG-1, DAG-2, DAG-4, DAG-3}
PrimaryActiveManager      : DAG-1
WitnessShareInUse         : Alternate

In this example you can see the attribute WitnessShareInUse with a value of Alternate. This is an example of where the AlternateWitnessServer and AlternateWitnessDirectory are configured for cluster use.

[PS] C:>Get-DatabaseAvailabilityGroup -Identity DAG -Status | fl name,servers,witnessserver,witnessdirectory,alternatew
itnessserver,alternatewitnessdirectory,operationalservers,primaryactivemanager,witnessshareinuse
WARNING: The witness server and directory currently in use by database availability group ‘DAG’ doesn’t match the
configured primary or alternate witness server. This may be due to Active Directory replication latency. If this
condition persists, please use the Set-DatabaseAvailabilityGroup cmdlet to correct the configuration.

In this example you can see the attribute WitnessShareInUse with a value of InvalidConfiguration. There is also a warning displayed indicating that the witness server in use does not match either the primary or alternate witness. This is an indication that the file share witness was modified outside of Exchange and the settings currently in use are not correct. Administrators can correct this by running the set-databaseavailabilitygroup command.

2) Utilize cluster commands

Windows 2008 / Windows 2008 R2

Using the command prompt execute the cluster <DAGNAME> res command. This will output all the resources within the cluster.

[PS] C:>cluster dag.domain.com res
Listing status for all available resources:

Resource             Group                Node            Status
——————– ——————– ————— ——
Cluster IP Address   Cluster Group        DAG-1           Online
Cluster Name         Cluster Group        DAG-1           Online
File Share Witness   Cluster Group        DAG-1           Online

Highlighted in red you can see the display name of the File Share Witness resource. With this information you can run the command cluster <DAGNAME> res “file share witness display name” /priv.

[PS] C:>cluster dag.domain.com res "File Share Witness" /priv

Listing private properties for ‘File Share Witness’:

T Resource             Name                           Value
— ——————– —————————— ———————–
S File Share Witness   SharePath                      \mbx-1.domain.comDAG.domain.com
D File Share Witness   ArbitrationDelay               6 (0x6)

This command lists the private properties within cluster associated with the file share witness resource. In our case we are interested in the SharePath. According to this output the current file share witness server is MBX-1.

Windows 2008 R2

Using powershell import the FailoverClusters modules.

[PS] C:>Import-Module FailoverClusters

Issue the command Get-ClusterQuorum –cluster <DAGNAME> | fl

[PS] C:>Get-ClusterQuorum -Cluster DAG.home.e-mcmichael.com | fl

Cluster : DAG
QuorumResource : File Share Witness
QuorumType : NodeAndFileShareMajority

Highlighted in red is the display name of the file share witness resource. Using the command Get-ClusterResource “Display Name” –cluster <DAGNAME> | Get-ClusterParameter

[PS] C:>Get-ClusterResource "File Share Witness" -Cluster DAG.home.e-mcmichael.com | Get-ClusterParameter

Object                        Name                          Value                         Type
——                        —-                          —–                         —-
File Share Witness            SharePath                     \mbx-1.domain.c… String
File Share Witness            ArbitrationDelay              6                             UInt32

3) Failover Cluster Manager

Using Failover Cluster Manager connect to the cluster service. You can connect to either a node or specify the DAG name as the connection point.

Click on the cluster name in the upper left hand corner of the utility.

In the center window information is displayed regarding the cluster configuration.

One piece of information is the “Quorum Configuration”. This will list the type of quorum in use and if a file share witness is configured the server and share name utilized as the witness.

In this example you can see that the cluster is configured for a quorum type of Node and File Share Majority with the file share witness server MBX-1.

Exchange and VSS — My Exchange writer is in a failed retryable state…

47 Replies

In Exchange 2007 and Exchange 2010 many customers are leveraging VSS based backups to retain and protect their Exchange data. By default Exchange provides two different VSS writers that share the same VSS writer ID but are loaded by two different services. The first is the Exchange Information Store VSS writer and the second is the Exchange Replication Service VSS writer. The Information Store writer allows for the backup of active / mounted databases and the replication service writer allows for the backup of passive databases (should a replicated database model be utilized). You can see the writers by running the command VSSADMIN LIST WRITERS from a command prompt.

Here is a sample put of a VSSAdmin List Writers from a Windows 2008 R2 SP1 server with Exchange 2010 SP1. Note how both writers share the same writer ID within the VSS framework.

Writer name: ‘Microsoft Exchange Replica Writer’
   Writer Id: {76fe1ac4-15f7-4bcd-987e-8e1acb462fb7}
   Writer Instance Id: {17e8df11-a8a2-4ee3-a3fb-e552b7da2d83}
   State: [1] Stable
   Last error: No error

Writer name: ‘Microsoft Exchange Writer’
   Writer Id: {76fe1ac4-15f7-4bcd-987e-8e1acb462fb7}
   Writer Instance Id: {e0ad4b68-8938-4be5-9b88-4c74df2b2d65}
   State: [1] Stable
   Last error: No error

In the course of protecting Exchange servers there maybe conditions that cause a backup job to fail. When an Exchange backup job fails the VSS framework aborts the backup and subsequently Exchange clears the backup in progress settings. When a failure is encountered either a single Exchange writer or both Exchange writers maybe left in a FAILED RETRYABLE state. We can utilize VSSAdmin List Writers again to query the writer status and see these results. Here is an example showing the Exchange Replication Service writer with a status 8 FAILED last error RETRYABLE.

Now the typical question that comes up at this point is how do I actually deal with an Exchange writer that consistently disallows backups. The answer – restart the service that the writer was associated with and/or fix whatever configuration issue is causing the failures. For example, given the above output I would restart the Exchange Replication Service in an attempt to return the writer to a Stable No Error state. (If it would have been the Microsoft Exchange Writer I would have restarted the Exchange Information Store Service).

The real question though is do I need to deal with a writer that is in a failed state? Unfortunately many administrators find themselves having to deal with a writer in a failed state because their experience is that while the writer is in a failed state subsequent backup jobs fail. If reviewing the issues carefully what you’ll find is that the backup jobs are not failing because of a VSS failure but rather they are failing because a writer was found in a failed state. From an Exchange / VSS perspective this is unexpected –> after all although the writer is failed the error is RETRYABLE –> essentially saying “hey…something failed but come on back and try me again…”

Let’s take a look at why this might be happening….

Within the VSS framework there are two states that we are interested in –> the Session State and the Current State. When a VSS session is in progress, and an administrator runs VSSAdmin List Writers, the state that is displayed is the current session state. When the VSS snapshot creation has completed, the current state becomes a session specific state and the status of the most recently completed session is copied to the current state. At this point when the administrator runs VSSAdmin List Writers the state of the most recently completed session is displayed. This is an important distinction –> the SESSION STATE AT THIS POINT REFLECTS THE STATUS OF THE LAST SESSION! The status of the last session does not imply anything in regards to the success <or> failure of future sessions.

Now that we know where VSSAdmin List Writers gets its information we’ll take a look at how the backup process should progress. (I’m going to attempt to present an overly simplified timeline of an expected backup)

The process starts with the VSS requester establishing a VSS session.

After the session is established the VSS requester requests metadata from the VSS framework.

At this point the VSS request and VSS framework further progress the snap shot process by determining components and preparing the snapshot set.

Once the components and snapshot sets have been prepared the VSS requester issues a PrepareForBackup. This in turns causes the VSS framework to prepare the components for backup.

After prepare backup is called the individual application level writers are now responsible for current writer status. The VSS requester is now allowed to call GatherWriterStatus. This call in turn should return the current writer status. For example, current writer status at this stage could be FREEZE / THAW / etc. This is regardless of if the previous status was FAILED or HEALTHY. This is the status that the VSS requester should be utilizing to make logic decisions at this point.

Once the snapshot is created the contents can then be transferred to the backup media. Once the transfer is complete, the VSS requester can inform the VSS framework that a backup has completed successfully and subsequently the VSS session ended.

In summary if the VSS requester is performing operations in an order that is expected, the writer status should be queried after the framework has received a prepare for backup event. This will ensure the writer status reflects that of the CURRENT SESSION IN PROGRESS and not the SESSION STATE OF THE PREVIOUS BACKUP.

The administrator can verify the functionality of the Exchange writer by utilizing the VSHADOW or DISKSHADOW utilities. These utilities utilize the workflow outlined in the successful handling of a failed retryable writer case. If either of these utilities are successful in creating the backup, and the writer in turn is returned to a healthy state you might consider following up with the backup vendor to ensure VSS calls are being made appropriately. Microsoft can also assist you in verifying the calls are made appropriately through assisting with both Exchange and OS VSS tracing.

Extra Extra: Recommended hotfix for your dag…

1 Reply

http://blogs.technet.com/b/exchange/archive/2011/11/20/recommended-windows-hotfix-for-database-availability-groups-running-windows-server-2008-r2.aspx

Exchange 2010: Implementing a dedicated backup network for a Database Availability Group…

18 Replies

Occasionally, customers that deploy highly available Mailbox servers use a dedicated or secondary network for backup operations. The way in which you do this in Exchange 2010 has changes, and it’s important that when you implement such a configuration that you don’t use the methods or instructions designed for previous versions of Exchange.

In Exchange 2003 and Exchange 2007, we leveraged the Windows Cluster service and used the cluster resource model. To implement a dedicated backup network, you would create a virtual IP address resource in the Exchange resource group corresponding to the network on which you wanted to perform backups. The network associated with the IP address would then be configured as follows:

· Allow cluster network communication on this network and Allow clients to connect through this network enabled (Windows 2008 and Windows 2008 R2)

· All Communications (Windows 2003 and Windows 2003 R2).

On the backup server a hosts file would be used to resolve the name of the Exchange Virtual Server (Exchange 2003) or Clustered Mailbox Server (Exchange 2007) using this dedicated IP address. Because each database was associated with a single server name this would allow the backup server to connect to the Exchange server name on the private network and leverage the backup agent installed on the node hosting those resources.

In Exchange 2010, there have been several changes that no longer allow this type of implementation to function. Exchange 2010 still leverages the Windows Cluster service for some of its high availability functionality, but it no longer uses the cluster resource model. Exchange 2010 includes a form of application level high availability known as the Database Availability Group (DAG). When an administrator creates a DAG they must provide a name and one or more IP addresses. The DAG name and the list of IP addresses are used when forming the DAG’s underlying cluster – these will become the Cluster Name Object (CNO) and the list of IPs will be associated with the cluster network name. All IP addresses assigned to a DAG must be on the MAPI network. This network is automatically configured to allow cluster network communications on this network and allow clients to connect through this network.

Exchange 2010 implements tightly coupled network integration with the Cluster service. This integration manages the settings of all networks found on the DAG members – for example Replication and backup networks. By default, Exchange 2010 sets these networks to allow cluster network communication on this network but does not set allow clients to connect through this network. When the setting allow clients to connect through this network is not enabled, virtual IP addresses cannot be bound to this network.

There is no straightforward way to create a dedicated backup network in Exchange 2010 using the legacy Exchange implementation. There are no application and service groups in which to create the IP address resources, ancillary networks do not support the settings necessary for a virtual IP address, and the integrated Exchange cmdlets do not allow you to assign an IP address to the DAG on a backup network.

Despite these challenges, some administrators have been semi-successful at implementing a variation of the solution (semi-successful as in, it works for a little while, but not for the long term). For example, administrators will find a way to change the network roles to allow virtual IPs to be created and will then update the Cluster core resources with the virtual IPs. This works, but only until Exchange reconfigures the network settings automatically, or until the administrator runs one of the integrated DAG cmdlets which removes the additional IP addresses being created.

So if that is the case how does one implement a dedicated backup networks, and what are some backup vendors doing? Unlike previous versions of Exchange where databases were associated with a server name, Exchange 2010 does not associated databases with a single server name per se. Instead, copies of a database are associated with a server. These database copies can exist across multiple members of the DAG with one member having an “active” database and one or more other members having “passive” databases. In order for backup vendors to determine database locations and status, some make a call to the DAG name to essentially perform a topology discovery. Remember that the DAG name is the name of the cluster, should have valid IP addresses for all subnets on which DAG members exist, and should be dynamically updating in DNS so that the DAG name always resolves correctly. Once this topology discovery is completed the backup server then initiates individual backup sessions to the DAG members themselves (via the DAG member names).

When implementing a dedicated backup network for an Exchange 2010, do not modify the cluster core resources. The backup servers should be allowed to do topology discovery over the MAPI network. This requires that the backup server has an interface that can query DNS, determine the IP address currently resolving to the cluster name, and establish a connection to that address.

Next, modify the hosts file on each backup server. In this configuration, each DAG member has a backup network interface with an IP address locally assigned to that interface. The hosts file entries on the backup server are used to resolve DAG member names.

How does this accomplish the task? Let’s take a look.

Here is an example 3-member DAG. The DAG has two networks, a MAPI network and a Backup network. Each member has an IP address statically assigned to each NIC..

When the backup software attempts to perform a backup operation, it queries DNS and determines that the IP address associated with the DAG is 10.0.0.100. The backup software connects to the DAG and performs a topology discovery.

The backup software determines that a database that needs to be backed up resides on NodeA. Normally the backup software would access the backup agent by querying DNS for the IP address associated with NodeA. If this happens, the backup would occur over the MAPI network and not the Backup network. To prevent this from happening, the administrator edited the hosts file of the backup server and added an entry for NodeA.company.com with an IP address of 10.1.1.1. The backup server uses this information and establishes a connection to the backup software agent running on NodeA via the Backup network.

In some scenarios, customers want to stop cluster heartbeat and continuous replication from using the Backup network. To do this, you can use the Set-DatababaseAvailabilityGroupNetwork cmdlet with the–IgnoreNetwork:$true and –ReplicationEnabled:$false parameters for the Backup network.

When implemented as described above, this configuration enables most backup applications to operate using a dedicated network without changing DAG settings that might be automatically disabled by the system.

================================

10/25/2011

Corrected location of host file entry change.

================================

12/18/2011

This weekend I reviewed a configuration that was using Backup Exec to protect their Exchange 2010 deployment. It was pointed out to me that on the properties of the job, on the network and security selection, there is an option to select which network / subnet could be utilized for backup operations. Some may find this helpful when configuring their jobs. I would defer to Symantec on specifics of establishing this configuration.

================================

Exchange 2010: Get-DatabaseAvailabilityGroup does not return all attributes of a DAG

4 Replies

When administrators run Get-DatabaseAvailabilityGroup they notice that certain fields within the output are not populated. In some scenarios this leads administrators to attempt to change settings of the DAG or believe that there is an operational issues with the DAG.

[PS] C:Windowssystem32>Get-DatabaseAvailabilityGroup DAG | fl

RunspaceId                             : 37b4f2b4-06b8-4e87-9252-968452ab3a28
Name                                   : DAG
Servers                                : {DAG-4, DAG-3, DAG-2, DAG-1}
WitnessServer                          : mbx-1.domain.com
WitnessDirectory                       : c:DAG-FSW
AlternateWitnessServer                 : mbx-2.domain.com
AlternateWitnessDirectory              : c:DAG-FSW
NetworkCompression                     : Enabled
NetworkEncryption                      : Enabled
DatacenterActivationMode               : DagOnly
StoppedMailboxServers                  : {}
StartedMailboxServers                  : {DAG-1.domain.com, DAG-2.domain.com, DAG-3.domain.com, DAG-4.domain.com}
DatabaseAvailabilityGroupIpv4Addresses : {10.0.0.24}
DatabaseAvailabilityGroupIpAddresses   : {10.0.0.24}
AllowCrossSiteRpcClientAccess          : False
OperationalServers                     :
PrimaryActiveManager                   :
ServersInMaintenance                   :
ThirdPartyReplication                  : Disabled
ReplicationPort                        : 0
NetworkNames                           : {}
WitnessShareInUse                      :
AdminDisplayName                       :
ExchangeVersion                        : 0.10 (14.0.100.0)
DistinguishedName                      : CN=DAG,CN=Database Availability Groups,CN=Exchange Administrative Group (FYDIB
                                         OHF23SPDLT),CN=Administrative Groups,CN=Organization,CN=Microsoft Exchange
                                         ,CN=Services,CN=Configuration,DC=Domain,DC=com
Identity                               : DAG
Guid                                   : 72c87136-6721-46e6-ac43-2ad5f6bd66d2
ObjectCategory                         : domain.com/Configuration/Schema/ms-Exch-MDB-Availability-Group
ObjectClass                            : {top, msExchMDBAvailabilityGroup}
WhenChanged                            : 10/13/2011 12:29:44 PM
WhenCreated                            : 9/19/2009 6:16:52 PM
WhenChangedUTC                         : 10/13/2011 4:29:44 PM
WhenCreatedUTC                         : 9/19/2009 10:16:52 PM
OrganizationId                         :
OriginatingServer                      : DC-2.domain.com
IsValid                                : True

The fields highlighted in red above cannot simply be read from Active Directory. These fields require calls to cluster services and / or replication services running on each member of the DAG. Depending on the number of members, network conditions, geographical locations of members, etc querying for these as a routine part of running the command could require additional time for the command to complete. Administrators that desire this information can add the –status switch to get-databaseavailabilitygroup and the fields will be returned as part of the output. Here is an example:

[PS] C:Windowssystem32>Get-DatabaseAvailabilityGroup DAG -Status | fl

RunspaceId                             : 37b4f2b4-06b8-4e87-9252-968452ab3a28
Name                                   : DAG
Servers                                : {DAG-4, DAG-3, DAG-2, DAG-1}
WitnessServer                          : mbx-1.domain.com
WitnessDirectory                       : c:DAG-FSW
AlternateWitnessServer                 : mbx-2.domain.com
AlternateWitnessDirectory              : c:DAG-FSW
NetworkCompression                     : Enabled
NetworkEncryption                      : Enabled
DatacenterActivationMode               : DagOnly
StoppedMailboxServers                  : {}
StartedMailboxServers                  : {DAG-1.domain.com, DAG-2.domain.com, DAG-3.home.e-mcmichae
                                         l.com, DAG-4.domain.com}
DatabaseAvailabilityGroupIpv4Addresses : {10.0.0.24}
DatabaseAvailabilityGroupIpAddresses   : {10.0.0.24}
AllowCrossSiteRpcClientAccess          : False
OperationalServers                     : {DAG-1, DAG-2, DAG-3, DAG-4}
PrimaryActiveManager                   : DAG-2
ServersInMaintenance                   : {DAG-4}
ThirdPartyReplication                  : Disabled
ReplicationPort                        : 64327
NetworkNames                           : {DAG-iSCSI, DAG-MAPI, DAG-REPL-A, DAG-REPL-B}
WitnessShareInUse                      : Primary
AdminDisplayName                       :
ExchangeVersion                        : 0.10 (14.0.100.0)
DistinguishedName                      : CN=DAG,CN=Database Availability Groups,CN=Exchange Administrative Group (FYDIB
                                         OHF23SPDLT),CN=Administrative Groups,CN=Organization,CN=Microsoft Exchange
                                         ,CN=Services,CN=Configuration,DC=domain,DC=com
Identity                               : DAG
Guid                                   : 72c87136-6721-46e6-ac43-2ad5f6bd66d2
ObjectCategory                         : domain.com/Configuration/Schema/ms-Exch-MDB-Availability-Group
ObjectClass                            : {top, msExchMDBAvailabilityGroup}
WhenChanged                            : 10/13/2011 12:29:44 PM
WhenCreated                            : 9/19/2009 6:16:52 PM
WhenChangedUTC                         : 10/13/2011 4:29:44 PM
WhenCreatedUTC                         : 9/19/2009 10:16:52 PM
OrganizationId                         :
OriginatingServer                      : DC-2.domain.com
IsValid                                : True

In general the command without the –status switch should return the necessary day to day information regarding the configuration of the DAG.

Error–567 ( JET_errDbTimeTooNew )

8 Replies

I recently worked with a customer who presented an interesting issue. The customer had installed an Exchange 2007 Cluster Continuous Replication solution where nodes leveraged independent direct attached storage. On the active node of the cluster the customer began to experience storage issues that lead to physical corruption of the Exchange database files. In this case the corruption noted was a –1018. In almost all cases a –1018 is indicative of a storage level error that occurs at a layer lower than the operating system.

In most cases customers would choose to switchover the solution to the passive copies - after all the passive copies are completely independent and physical corruption does not replicate through the log file stream. In this instance that is what the customer choose to do. Although the move appeared successful (in terms of resources moving from NodeA to NodeB) several databases did not mount. Subsequent attempts to manually mount the database also failed. When reviewing the event logs the following events were noted on the passive node (now attempting to become active) for the databases that failed to mount:

Time: 9/22/2011 7:19:59
PM
ID: 516

Level: Error

Source: ESE
Machine: Node.company.com

Message: Microsoft.Exchange.Cluster.ReplayService (6032) Recovery E03 SGSGCDBG001SGSGCDBG001-SG21: Database m:SG21MDBSGSGCDBG001-SG21-JE-T2.edb: Page 118956 (0x0001d0ac) failed verification due to a timestamp mismatch. The expected timestamp was 0x39cd983 but the actual timestamp on the page was 0x39cdd83. Recovery/restore will fail with error -567. If this condition persists then please restore the database from a previous backup. This problem is likely due to faulty hardware "losing" one or more flushes on this page sometime in the past. Please contact your hardware vendor for further assistance diagnosing the problem.

Time: 9/22/2011 7:19:28
PM
ID: 2095

Level: Error

Source: MSExchangeRepl

Machine: Node.company.com

Message: Log file X:SG38LogsE250002D510.log in SGSGCDBG001SGSGCDBG001-SG38 could not be replayed. Re-seeding the passive node is now required. Use the Update-StorageGroupCopy cmdlet in the Exchange Management Shell to perform a re-seed operation.

Time: 9/22/2011 7:19:28
PM
ID: 2097

Level: Error

Source: MSExchangeRepl

Machine: Node.company.com
Message: The Microsoft Exchange Replication Service encountered an unexpected Extensible Storage Engine (ESE) exception in storage group ‘SGSGCDBG001SGSGCDBG001-SG38’. The ESE exception is dbtime on page in advance of the dbtimeBefore in record (-567) ().

When utilizing the ERR tool we note that the error –567 is:

# for decimal -567 / hex 0xfffffdc9
JET_errDbTimeTooNew esent98.h
# /* dbtime on page in advance of the dbtimeBefore in record
# */
# 1 matches found for "-567"

In general DBTime errors are usually attributed also to failing storage. In this case though something did not seem right – would it be possible to have two independent storage devices experiences failures almost simultaneously. In all honesty it’s not outside the realm of possibility that those circumstances may have actually occurred. Unlike the one set of storage which was clearly displaying hardware faults on the storage devices the second storage device displayed no faults at all. There was no way to attribute this particular error to a local storage failure.

Is it possible that a storage failure on the previously active node caused corruption in a passive database copy? In this case the answer is…yes…

First and foremost one must draw a distinction between the types of corruption we can have within an Exchange database. You have physical corruption and you have logical corruption. Logical corruption is the type of corruption that will replicate through the log stream and subsequently may cause corruption within a passive database copy. In this case DBTime errors are considered logical corruption. Therefore, this logical corruption is introduced into the log file stream and subsequently replicated over to the passive node. In terms of DBTime corruption this will halt logging recovery of the database instance and prevent it from being a healthy replica (when not being activated) or preventing mounting the database (when being activated).

So how is it possible that this type of logical corruption occurred because of a storage failure on the source copy? Let’s investigate…

DBTime is a counter within an Exchange database that is incremented for each page level change that occurs – think of DBTime as the odometer in your car. If one determines the highest DBTime, and locates the page within the database that matches that DBTime, they have identified the last page changed within the database. When a page change occurs and that change is recorded to the log file we record three pieces of important information (although there is much more recorded). This information includes:

1) The page number that is being changed.

2) The current DBTime on that page.

3) The new DBTime for the page.

When logging recovery occurs the following rules are applied where DBTime is concerned:

1) Does the page in the log record exist in the database?

2) Is the previous DBTime recorded in the log record for the page match the current DBTime stamped on the page?

3) Is the new DBTime recorded in the log record for the page greater than the current DBTime stamped on the page?

When all page modifications have occurred to a database in the correct order then the three rules are always met. In this case the JET_errDBTimeTooNew occurs when check number 2 fails. Simply put, when I compare the current DBTime of the page recorded in the log record to the current DBTime stamped on the same page within the database, the database has a newer value. Therefore if I were to allow my change to be committed data loss would occur – logging recovery is halted.

Still – how did this happen because of storage issues on the previously active node? Let’s explore that further…

So let’s assume we can isolate all changes to a single page. In this case we will say page 45. Page 45 has a current DBTime of 400:

At this time we make a change to page 45. The log record records page 45, current DBTime 400, and new DBTime of 410. When the change is committed to the database the DBTime on the page is updated to the new DBTime.

Another page change to page 45 occurs. The log record records page 45, current DBTime 410, and new DBTime of 500. When the change is committed to the database the DBTime on the page is updated to the new DBTime.

Now this is where the storage issue is introduced. In this case Exchange was informed by the storage subsystem that the write to the database was successful. When this information was processed Exchange purged the change from the database cache. Unfortunately the write was “lost” and therefore the DBTime on the page never really updated to reflect the correct values. So now a new change to page 45 is issued. The log record records page 45, current DBTime 410, and new dbTime 600. (See the issue – the current DBTime on the page should have reflected 500 but because of the lost flush reflects 410).

At this time the administrator moves the clustered mailbox server to the passive node. The log file referenced in this example now needs to be replayed into the database. Remember the rules above for log replay in terms of DB Time. So in our example the first log record is encountered:

Does page 45 exist = Yes.

Is the current dbTime on the page 400 = Yes.

Is the new dbTime greater than current dbTime on the page = Yes.

Transaction allowed to proceed = Yes.

The second log record is now evaluated.

Does page 45 exist = Yes.

Is the current dbTime on the page 410 = Yes.

Is the new dbTime greater than current dbTime on the page = Yes.

Transaction allowed to proceed = Yes.

Note that the dbTime was correctly updated to 500. This was the previous write that was lost to the original database (and therefore the dbTime was never updated in the original database).

The third log record is now evaluated.

Does page 45 exist = Yes.

Is the current dbTime on the page 410 = NO

Is the new dbTIME greater than current dbTime on the page = Yes.

Transaction allowed to proceed = NO JET_errDBTimeTooNew

As you can see the dbTime on the page which is currently 500 is greater (or newer) then the previous dbTime recorded for the page from the previous active database (410). Therefore the commit is blocked and logging recovery fails. In our case this prevented the CMS from coming online on the second node.

To rectify this situation we would have normally just moved the CMS back to the original node and then reseeded these database copies (therefore bypassing the need to replay the log file in question). In this case a restoration was necessary since both database copies were essentially unusable due to the mix of corruption present. Unfortunately this type of corruption is only ever detected during logging recovery – there is no proactive way to detect this form of logical corruption.

Exchange 2010: HomeMTA and msExchHomeServerName are not updated on mailboxes.

13 Replies

In Exchange 2003 and Exchange 2007 when clients would attempt to connect to a mailbox it would be based on the server where that mailbox was homed. Specifically these attributes would contain information about the server where a particular mailbox was homed:

HomeMTA
msExchHomeServerName

In Exchange 2010 a mailbox object is no longer associated with a server but rather is associated with a database. A database has copies which are associated with a particular server. When a client or application attempts to access the mailbox, the active manager process is responsible for locating the server that hosts the active copy of the database and referring mailbox requests to that server. Although not utilized, the Exchange 2010 mailbox provisioning process still stamps HomeMTA and msExchHomeServerName. In this case the attributes are stamped based on the server where the database copy was active at the time the mailbox was provisioned.

Management commandlets like get-mailbox will return the server name stamped in msExchHomeServer. In many cases this is a valid server within the environment. In some instances, the server mentioned has been decommissioned and is no longer available. Although this server name is displayed this is not an issue. There should be no reason that administrators need to update these values as they are not utilized in Exchange 2010.

===================================================

[PS] C:Windowssystem32>Get-Mailbox Tim

Name                      Alias                ServerName       ProhibitSendQuota
—-                      —–                ———-       —————–
Timothy J. McMichael      Tim                  dag-4            unlimited

homeMTA: CN=Microsoft MTA,CN=DAG-4,CN=Servers,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=Organization,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=domain,DC=com;

msExchHomeServerName: /o=Organization/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Configuration/cn=Servers/cn=DAG-4;

===================================================

10/2/2011

Updated second paragraph where I referenced homeMDB instead of homeMTA.

===================================================

Exchange Server 2010 and System Center Data Protection Manager 2010

6 Replies

When using System Center Data Protection Manager 2010 to protect an Exchange Server 2010 solution there are four essential steps that need to occur in order for the backup to be successful.

1) Volume shadow copy is made of the Exchange data on the host where the backup is initiated.

2) The data on the shadow copies is transferred to the Data Protection Manager server.

3) All Exchange log files and database files in the backup set have an optional consistency check performed.

4) Backup complete is performed allowing for log truncation activities (if applicable).

Step #1: Create shadow copies

Data Protection Manager 2010 performs three different types of shadow copy backup operations against an Exchange 2010 server. The type of shadow copy performed is dependent both on the job settings and the configuration of the Exchange installation.

The three types of shadow copies performed:

1) Full Shadow Copy

The full shadow copy is performed as part of initial replica creation and during each express full backup. The full shadow copy will include all Exchange log files and all Exchange database files and includes a call for log truncation to occur upon successful backup completion. Full shadow copies will occur on all standalone databases, and on selected database copies if the Exchange Server is in a Database Availability Group configuration. (Only a single copy of a database in a DAG may be enabled for full shadow copy).

2) Incremental Shadow Copy

The incremental shadow copy will as part of continuous protection of the mailbox database. The incremental shadow copy will include all Exchange log files and includes a call for log truncation to occur upon successful backup completion. Incremental shadow copies can occur on all standalone databases and on selected database copies if the Exchange Server is in a Database Availability Group configuration. (Only a single copy of a database in a DAG may be enabled for incremental shadow copy – selection is inherited by the copy enabled for full shadow copy and cannot be specified separately).

3) Copy Shadow Copy

The copy shadow copy is performed on selected database copies if the Exchange Server is in a Database Availability Group configuration. The copy shadow copy will be performed on initial replica creation and during each express full backup. A copy backup includes all Exchange log files and all Exchange database files but does not call for log truncation to occur upon successful full backup. (The databases selected for this operation could be all or none of the copies not enabled for full shadow copy).

The creation of shadow copies is the first part of an Exchange backup using DPM 2010. An administrator would expect the shadow copy process to complete quickly. The creation of the shadow copies must be successful in order for the backup process to continue.

For a Full Shadow Copy (standalone) the administrator may note the following events in the application log :

Index:    1
Time:     11/29/2010 8:28:04 AM
ID:       9606
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7a595f8f-2a18-4f1a-a68d-aa3757ba6c3e) has prepared for backup successfully.

Index:    2
Time:     11/29/2010 8:28:07 AM
ID:       2005
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) Shadow copy instance 4 starting. This will be a Full shadow copy.

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

Index:    3
Time:     11/29/2010 8:28:07 AM
ID:       9811
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 4) has successfully prepared the database engine for a full or copy backup of database ‘MBX-1-DB0’.

Index:    4
Time:     11/29/2010 8:28:07 AM
ID:       9608
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7a595f8f-2a18-4f1a-a68d-aa3757ba6c3e:4) has prepared for Snapshot successfully.

Index:    5
Time:     11/29/2010 8:28:07 AM
ID:       2001
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) Shadow copy instance 4 freeze started.

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

Index:    6
Time:     11/29/2010 8:28:07 AM
ID:       2001
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) MBX-1-DB0: Shadow copy instance 4 freeze started.

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

Index:    7
Time:     11/29/2010 8:28:07 AM
ID:       9610
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7a595f8f-2a18-4f1a-a68d-aa3757ba6c3e:4) has frozen the database(s) successfully.

Index:    8
Time:     11/29/2010 8:28:07 AM
ID:       2003
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) Shadow copy instance 4 freeze ended.

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

Index:    9
Time:     11/29/2010 8:28:07 AM
ID:       9612
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7a595f8f-2a18-4f1a-a68d-aa3757ba6c3e:4) has thawed the database(s) successfully.

Index:    10
Time:     11/29/2010 8:28:08 AM
ID:       9622
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7a595f8f-2a18-4f1a-a68d-aa3757ba6c3e:4) has processed the post-snapshot event successfully.

For an Incremental Shadow Copy (standalone) the administrator may note the following events in the application log:

Index:    0
Time:     11/29/2010 8:49:39 AM
ID:       9606
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7d3e1a06-76ce-4b12-a313-98edd703705a) has prepared for backup successfully.

Index:    1
Time:     11/29/2010 8:49:42 AM
ID:       2008
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) Shadow copy instance 8 starting. This will be an Incremental shadow copy.

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

Index:    2
Time:     11/29/2010 8:49:42 AM
ID:       9812
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 8) has successfully prepared the database engine for an incremental or differential backup of database ‘MBX-1-DB0’.

Index:    3
Time:     11/29/2010 8:49:42 AM
ID:       9608
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7d3e1a06-76ce-4b12-a313-98edd703705a:8) has prepared for Snapshot successfully.

Index:    4
Time:     11/29/2010 8:49:42 AM
ID:       2001
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) Shadow copy instance 8 freeze started.

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

Index:    5
Time:     11/29/2010 8:49:42 AM
ID:       2001
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) MBX-1-DB0: Shadow copy instance 8 freeze started.

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

Index:    6
Time:     11/29/2010 8:49:42 AM
ID:       9610
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7d3e1a06-76ce-4b12-a313-98edd703705a:8) has frozen the database(s) successfully.

Index:    7
Time:     11/29/2010 8:49:43 AM
ID:       2003
Level:    Information
Source: ESE
Machine: MBX-1.exchange.msft
Message: Information Store (3596) Shadow copy instance 8 freeze ended.

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

Index:    8
Time:     11/29/2010 8:49:43 AM
ID:       9612
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7d3e1a06-76ce-4b12-a313-98edd703705a:8) has thawed the database(s) successfully.

Index:    9
Time:     11/29/2010 8:49:44 AM
ID:       9622
Level:    Information
Source: MSExchangeIS
Machine: MBX-1.exchange.msft
Message: Exchange VSS Writer (instance 7d3e1a06-76ce-4b12-a313-98edd703705a:8) has processed the post-snapshot event successfully.

For a Full Shadow Copy (Database Availability Group / Active Mailbox Database Copy hosted on server MBX-2) the administrator may note the following events in the application log:

Index:    20
Time:     11/29/2010 9:04:39 AM
ID:       2021
Level:    Information
Source: MSExchangeRepl
Machine: MBX-2.exchange.msft
Message: The Microsoft Exchange VSS Writer has successfully collected the metadata document in preparation for backup.

Index:    21
Time:     11/29/2010 9:04:40 AM
ID:       9606
Level:    Information
Source: MSExchangeIS
Machine: MBX-2.exchange.msft
Message: Exchange VSS Writer (instance 714e46f9-22ee-4b8a-a1d6-92bc6c84083c) has prepared for backup successfully.

Index:    22
Time:     11/29/2010 9:04:43 AM
ID:       2005
Level:    Information
Source: ESE
Machine: MBX-2.exchange.msft
Message: Information Store (3360) Shadow copy instance 2 starting. This will be a Full shadow copy.

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

Index:    23
Time:     11/29/2010 9:04:43 AM
ID:       9811
Level:    Information
Source: MSExchangeIS
Machine: MBX-2.exchange.msft
Message: Exchange VSS Writer (instance 2) has successfully prepared the database engine for a full or copy backup of database ‘DAG-DB0’.

Index:    24
Time:     11/29/2010 9:04:43 AM
ID:       9608
Level:    Information
Source: MSExchangeIS
Machine: MBX-2.exchange.msft
Message: Exchange VSS Writer (instance 714e46f9-22ee-4b8a-a1d6-92bc6c84083c:2) has prepared for Snapshot successfully.

Index:    25
Time:     11/29/2010 9:04:43 AM
ID:       2001
Level:    Information
Source: ESE
Machine: MBX-2.exchange.msft
Message: Information Store (3360) Shadow copy instance 2 freeze started.

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

Index:    26
Time:     11/29/2010 9:04:43 AM
ID:       2001
Level:    Information
Source: ESE
Machine: MBX-2.exchange.msft
Message: Information Store (3360) DAG-DB0: Shadow copy instance 2 freeze started.

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

Index:    27
Time:     11/29/2010 9:04:43 AM
ID:       9610
Level:    Information
Source: MSExchangeIS
Machine: MBX-2.exchange.msft
Message: Exchange VSS Writer (instance 714e46f9-22ee-4b8a-a1d6-92bc6c84083c:2) has frozen the database(s) successfully.

Index:    28
Time:     11/29/2010 9:04:44 AM
ID:       2003
Level:    Information
Source: ESE
Machine: MBX-2.exchange.msft
Message: Information Store (3360) Shadow copy instance 2 freeze ended.

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

Index:    29
Time:     11/29/2010 9:04:44 AM
ID:       9612
Level:    Information
Source: MSExchangeIS
Machine: MBX-2.exchange.msft
Message: Exchange VSS Writer (instance 714e46f9-22ee-4b8a-a1d6-92bc6c84083c:2) has thawed the database(s) successfully.

Index:    30
Time:     11/29/2010 9:04:45 AM
ID:       9622
Level:    Information
Source: MSExchangeIS
Machine: MBX-2.exchange.msft
Message: Exchange VSS Writer (instance 714e46f9-22ee-4b8a-a1d6-92bc6c84083c:2) has processed the post-snapshot event successfully.

For a Copy Shadow Copy (Database Availability Group / Passive Mailbox Database Copy hosted on server MBX-3) the administrator may note the following events in the application log:

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:21 AM
Event ID:      2021
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange VSS Writer has successfully collected the metadata document in preparation for backup.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:25 AM
Event ID:      2110
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 95661579-1ddb-4826-9e0a-a0ceed92a2aa has successfully prepared for a full or a copy backup of database ‘DAG-DB0’. The following database will be backed up: DAG-DB0.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:25 AM
Event ID:      2023
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange Replication service VSS Writer (Instance 95661579-1ddb-4826-9e0a-a0ceed92a2aa) successfully prepared for backup.

Log Name:      Application
Source:        MSExchangeIS Mailbox Store
Date:          11/29/2010 6:01:35 AM
Event ID:      9539
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange Information Store database "09067c7d-64f6-4b2a-aa91-aca0229c2025: /o=Exchange/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Configuration/cn=Servers/cn=MBX-1/cn=Microsoft Private MDB" was stopped.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:35 AM
Event ID:      2027
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 95661579-1ddb-4826-9e0a-a0ceed92a2aa has successfully frozen the databases.

Log Name:      Application
Source:        ESE BACKUP
Date:          11/29/2010 6:01:35 AM
Event ID:      960
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
msexchangerepl (2228) This computer is performing a surrogate backup. The master server is MBX-2.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:35 AM
Event ID:      2025
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange Replication service VSS Writer (Instance 95661579-1ddb-4826-9e0a-a0ceed92a2aa) successfully prepared for a snapshot.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:36 AM
Event ID:      2029
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 95661579-1ddb-4826-9e0a-a0ceed92a2aa has successfully thawed the databases.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:01:37 AM
Event ID:      2035
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange Replication service VSS Writer (Instance 95661579-1ddb-4826-9e0a-a0ceed92a2aa) has successfully processed the post-snapshot event.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:03:37 AM
Event ID:      2114
Task Category: Service
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The replication instance for database DAG-DB0 has started copying log files. The first log file copied was generation 187.

Log Name:      Application
Source:        MSExchangeIS Mailbox Store
Date:          11/29/2010 6:03:37 AM
Event ID:      1000
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Attempting to start the Information Store "DAG-DB0".

Log Name:      Application
Source:        ESE BACKUP
Date:          11/29/2010 6:03:41 AM
Event ID:      963
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
msexchangerepl (2228) The surrogate backup procedure to MBX-2 has been successfully completed.

For a Full Shadow Copy (Database Availability Group / Passive Mailbox Database Copy hosted on server MBX-2) the administrator may note the following events in the application log:

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:18:17 AM
Event ID:      2021
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange VSS Writer has successfully collected the metadata document in preparation for backup.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:26 AM
Event ID:      2110
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 06f76857-2e99-436a-baa1-c0336c7f918c has successfully prepared for a full or a copy backup of database ‘DAG-DB1’. The following database will be backed up: DAG-DB1.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:26 AM
Event ID:      2023
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange Replication service VSS Writer (Instance 06f76857-2e99-436a-baa1-c0336c7f918c) successfully prepared for backup.

Log Name:      Application
Source:        MSExchangeIS Mailbox Store
Date:          11/29/2010 6:21:29 AM
Event ID:      9539
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange Information Store database "8c319775-6c8b-4780-b90f-81a6ac63714d: /o=Exchange/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Configuration/cn=Servers/cn=MBX-1/cn=Microsoft Private MDB" was stopped.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:29 AM
Event ID:      2027
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 06f76857-2e99-436a-baa1-c0336c7f918c has successfully frozen the databases.

Log Name:      Application
Source:        ESE BACKUP
Date:          11/29/2010 6:21:29 AM
Event ID:      960
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
msexchangerepl (2356) This computer is performing a surrogate backup. The master server is MBX-3.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:30 AM
Event ID:      2025
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange Replication service VSS Writer (Instance 06f76857-2e99-436a-baa1-c0336c7f918c) successfully prepared for a snapshot.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:30 AM
Event ID:      2027
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 06f76857-2e99-436a-baa1-c0336c7f918c has successfully frozen the databases.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:31 AM
Event ID:      2029
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange VSS Writer instance 06f76857-2e99-436a-baa1-c0336c7f918c has successfully thawed the databases.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:31 AM
Event ID:      2035
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The Microsoft Exchange Replication service VSS Writer (Instance 06f76857-2e99-436a-baa1-c0336c7f918c) has successfully processed the post-snapshot event.

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:21:34 AM
Event ID:      2114
Task Category: Service
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
The replication instance for database DAG-DB1 has started copying log files. The first log file copied was generation 194.

Log Name:      Application
Source:        MSExchangeIS Mailbox Store
Date:          11/29/2010 6:21:34 AM
Event ID:      1000
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Attempting to start the Information Store "DAG-DB1".

Log Name:      Application
Source:        ESE BACKUP
Date:          11/29/2010 6:23:35 AM
Event ID:      963
Task Category: General
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
msexchangerepl (2356) The surrogate backup procedure to MBX-3 has been successfully completed.

For a Copy Shadow Copy (Database Availability Group / Active Mailbox Database Copy hosted on server MBX-3) the administrator may not the following events in the application log:

Log Name:      Application
Source:        MSExchangeRepl
Date:          11/29/2010 6:56:39 AM
Event ID:      2021
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
The Microsoft Exchange VSS Writer has successfully collected the metadata document in preparation for backup.

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 6:56:40 AM
Event ID:      9606
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Exchange VSS Writer (instance 266b4cbc-3c4f-4e0d-891f-ad18193b80f4) has prepared for backup successfully.

Log Name:      Application
Source:        ESE
Date:          11/29/2010 6:56:42 AM
Event ID:      2009
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Information Store (3220) Shadow copy instance 2 starting. This will be a Copy shadow copy.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 6:56:42 AM
Event ID:      9811
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Exchange VSS Writer (instance 2) has successfully prepared the database engine for a full or copy backup of database ‘DAG-DB1’.

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 6:56:42 AM
Event ID:      9608
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Exchange VSS Writer (instance 266b4cbc-3c4f-4e0d-891f-ad18193b80f4:2) has prepared for Snapshot successfully.

Log Name:      Application
Source:        ESE
Date:          11/29/2010 6:56:43 AM
Event ID:      2001
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Information Store (3220) Shadow copy instance 2 freeze started.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 6:56:43 AM
Event ID:      9610
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Exchange VSS Writer (instance 266b4cbc-3c4f-4e0d-891f-ad18193b80f4:2) has frozen the database(s) successfully.

Log Name:      Application
Source:        ESE
Date:          11/29/2010 6:56:43 AM
Event ID:      2003
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Information Store (3220) Shadow copy instance 2 freeze ended.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 6:56:43 AM
Event ID:      9612
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Exchange VSS Writer (instance 266b4cbc-3c4f-4e0d-891f-ad18193b80f4:2) has thawed the database(s) successfully.

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 6:56:44 AM
Event ID:      9622
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-3.exchange.msft
Description:
Exchange VSS Writer (instance 266b4cbc-3c4f-4e0d-891f-ad18193b80f4:2) has processed the post-snapshot event successfully.

Step #2: Transferring shadow copy data to the DPM 2010 server

After the successful creation of shadow copies the data in the shadow copy volume is transferred to the DPM 2010 server. (Note: If the protection method is to tape instead of to disk – Step #2 and Step #3 are reversed). The data is transferred via the network connection between the Exchange server hosting the shadow copy data and the DPM 2010 server.

The amount of data to be copied to the DPM server depends on the type of backup performed.

For a Full Shadow Copy <or> a Copy Shadow Copy that is the initial replica creation the data transfer to the DPM server will include all log files at the time of backup initiation and the full database.

For a Full Shadow Copy <or> a Copy Shadow Copy that is an express full backup the data transfer to the DPM server will include all log files and delta changes to the database from the initial replica creation or previous express full backup.

For an Incremental Shadow Copy the data transfer to the DPM server will include all log files.

The amount of time that the transfer to the DPM server takes is largely dependent on the size of the data set to be transferred, performance of the hosts involved, and performance of the network.

DPM 2010 does allow the administrator to optimize the performance of the protection group by enabling a setting to allow on the wire compression. This setting is not enabled by default.

Once the data has been successfully transmitted to the DPM 2010 server the backup can proceed to the next step.

Step #3: Running consistency check

After the data has been streamed to the DPM 2010 server the process of consistency checking can begin. (Note: If the protection method is to tape instead of disk – Step #2 and Step #3 are reversed. Consistency checking is then performed on the Exchange Server hosting the shadow copy storage rather then the DPM 2010 server).

Consistency checking in DPM is completely optional and can have the following three settings:

Disabled

Enabled – Log Files Only

Enabled – Database and Log Files

We do have some recommendations on how consistency checking is utilized. If the Exchange Server 2010 mailbox database is standalone, it is recommended that both log file consistency check and database consistency check be performed. This assumes that DPM 2010 is the primary recovery method for this database. If the Exchange Server 2010 mailbox database is hosted in a Database Availability Group, it is recommended that only the log files be consistency checked. This assumes that the DAG is the primary recovery method for this database.

The consistency check will verify the integrity of the log files and the database files that reside on the DPM server. Should a consistency check be performed, and a corruption be identified, the backup will be considered failed.

By copying delta data sets to the DPM 2010 server, and performing consistency check on the DPM 2010 server itself, the performance impacts associated with consistency checking are offloaded from the Exchange Server itself. (Note that this assumes protection to disk rather then protection to tape). The consistency check on the DPM 2010 server is achieved by using eseutil.exe and ese.dll from your Exchange installations. It is important that administrators ensure that the highest version of these two binaries exists on the DPM 2010 server. For example, if when DPM was originally installed the administrator was using Exchange Server 2010 RTM and a single mailbox server is upgraded to Exchange Server 2010 SP1 – the binaries for eseutil.exe and ese.dll on the DPM server should be replaced with the Exchange Server 2010 SP1 binaries, since this is the highest revision in use in the protected environment.

The length of time the consistency check takes is largely dependent on the size of the database and the number of log files included in the backup set. Recently we have encountered some customers that have reported DPM backups not completing or not completing in a timely fashion. After reviewing the environments, consistency check was enabled for log files as recommended. In these cases there was a significant number of delta log files due to migrations (circa 100 gig in my reference scenario). In this case we simply worked around this by temporarily disabling consistency checking and allowing the express full backup to complete. Once these logs were truncated and we were back to a “normal” log generation cycle, consistency checking was re-enabled as recommended.

Step #4: Backup complete

At this stage the shadow copies, consistency check, and data transfer have completed successfully. At this time the Exchange writer can be informed that the backup completed successfully. It is also at this time that if a full shadow copy <or> incremental shadow copy was performed that log truncation can occur for logs that are eligible for truncation. This is a very important step, if backup complete is not called by the application future backups are subject to fail with an error that a backup is already in progress. (This may necessitate restarting the Information Store service on order to clear this condition). Please note that log truncation no longer occurs as a part of the backup process, therefore it is not necessary for logs to truncate in order for the backup to be completed successfully. It may be several minutes until the log file truncation is actually processed on the hosts.

A note regarding log truncation…

On a Database Availability Group server there is a 225 event indicating that no log files can be truncated. If careful attention is paid to the event it will be noticed that the source of the event is ESE. This event is expected on a DAG member, since ESE is not responsible for determining which log files in a replicated environment should be truncated.

The following events may be found in the application log regarding the Exchange backup when a Full Shadow Copy <or> Incremental Shadow Copy are performed of a Database Availability Group:

Log Name:      Application
Source:        ESE
Date:          11/29/2010 7:34:30 AM
Event ID:      225
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Information Store (3360) DAG-DB0: No log files can be truncated.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:34:30 AM
Event ID:      9827
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Exchange VSS Writer (instance 10105fe3-5935-46dc-8aa8-4edb9ca0cb48:4) has successfully completed the full or incremental backup of replicated database ‘DAG-DB0’. The log files will be truncated after they have been replayed.

Log Name:      Application
Source:        ESE
Date:          11/29/2010 7:34:30 AM
Event ID:      2006
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Information Store (3360) Shadow copy instance 4 completed successfully.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:34:30 AM
Event ID:      9616
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Exchange VSS Writer (instance 10105fe3-5935-46dc-8aa8-4edb9ca0cb48:4) has processed the backup completion event successfully.

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:34:31 AM
Event ID:      9648
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Exchange VSS Writer (instance 10105fe3-5935-46dc-8aa8-4edb9ca0cb48:4) has processed the backup shutdown event successfully.

The following events may be found in the application log regarding the Exchange backup when a Full Shadow Copy <or> Incremental Shadow Copy is performed of a Standalone Server:

Log Name:      Application
Source:        ESE
Date:          11/29/2010 7:39:36 AM
Event ID:      224
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Information Store (3596) MBX-1-DB0: Deleting log files c:MBX-1MBX-1-DB0E00000000DF.log to c:MBX-1MBX-1-DB0E00000000E5.log.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:39:36 AM
Event ID:      9780
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Exchange VSS Writer (instance 7f301ea2-f4ee-4521-b386-31c159293dcd:11) has successfully completed the full or incremental backup of database ‘MBX-1-DB0’.

The database engine has also successfully executed log file truncation procedures for this database. (Note that this may or may not have resulted in the actual truncation of log files, depending on whether any log files existed that were candidates for truncation.)

Log Name:      Application
Source:        ESE
Date:          11/29/2010 7:39:36 AM
Event ID:      2006
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Information Store (3596) Shadow copy instance 11 completed successfully.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:39:36 AM
Event ID:      9616
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Exchange VSS Writer (instance 7f301ea2-f4ee-4521-b386-31c159293dcd:11) has processed the backup completion event successfully.

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:39:38 AM
Event ID:      9648
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-1.exchange.msft
Description:
Exchange VSS Writer (instance 7f301ea2-f4ee-4521-b386-31c159293dcd:11) has processed the backup shutdown event successfully.

The following events may be found in the application log regarding the Exchange backup when a Copy Shadow Copy is performed:

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:49:23 AM
Event ID:      9781
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Exchange VSS Writer (instance b7990a10-5077-49f7-ad9b-f40e6a92019e:5) has successfully completed the copy or differential backup of database ‘DAG-DB0’. No logfiles were truncated for this database.

Log Name:      Application
Source:        ESE
Date:          11/29/2010 7:49:23 AM
Event ID:      2006
Task Category: ShadowCopy
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Information Store (3360) Shadow copy instance 5 completed successfully.

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

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:49:23 AM
Event ID:      9616
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Exchange VSS Writer (instance b7990a10-5077-49f7-ad9b-f40e6a92019e:5) has processed the backup completion event successfully.

Log Name:      Application
Source:        MSExchangeIS
Date:          11/29/2010 7:49:25 AM
Event ID:      9648
Task Category: Exchange VSS Writer
Level:         Information
Keywords:      Classic
User:          N/A
Computer:      MBX-2.exchange.msft
Description:
Exchange VSS Writer (instance b7990a10-5077-49f7-ad9b-f40e6a92019e:5) has processed the backup shutdown event successfully.

Exchange 2010: Collapsing DAG Networks

29 Replies

As a post configuration step in an Exchange 2010 Database Availability Group installation the administrator may need to collapse Database Availability Group Networks. Unfortunately this is a commonly missed configuration which results in the replication of log files in an unexpected manner.

Let’s take a look at the following Exchange installation.

In this case we are dealing with a total of four subnets, two subnets assigned to hosts in the primary data center and two subnets assigned to hosts in the secondary data center. Each of the MAPI networks is routable via default gateway settings. Each of the replication networks is routable by using the appropriately established static routes.

When the Database Availability Group is established the Failover Clustering services are leveraged for certain functions. One of the functions of the Failover Cluster Service is the enumeration of networks on nodes. When the cluster service starts the IP address bindings of each network card is reviewed and the subnet determined. Failover Clustering then creates a Cluster Network for each subnet. Nodes that have an IP address in a cluster network then have their network interface placed in the appropriate cluster network. In this example there are four subnets – therefore Failover Clustering will enumerate four cluster networks. Each of the individual cluster networks will contain two network interfaces, since each node has at least one network interface assigned to each subnet.

Here is an example of the cluster network enumeration as seen in failover cluster manager.

Here is an example of the network ports placed into a cluster network.

The Exchange Replication Service enumerates the cluster networks as reported by cluster and establishes an initial set of Database Availability Group Networks. You can view the default Database Availability Group Networks in the Exchange Management Console. Since Failover Clustering reports 4 cluster networks, the default set of DAG Networks is now four. Here is an example:

In this example you can see the default four DAG networks. Each DAG Network, like each Cluster Network, has assigned a network port from each host. DAG Networks is how the replication service determines what connectivity is available for log shipping activities. Based on this DAG network topology the replication service knows the following about DAG node communications:

192.168.0.3 <-> 192.168.0.4

10.0.0.1 <-> 10.0.0.2

10.0.1.1 <-> 10.0.1.2

192.168.1.3 <-> 192.168.1.4

What is missing here is any relationship between the 192.168.0.X and 192.168.1.X subnets as well as the 10.0.0.X and 10.0.1.X subnets. As of now the replication service has no idea how a node in 192.168.0.X can communicate with a remote node –> can it do so on 192.168.1.X or 10.0.1.X? In this situation we do not want DAG communications to fail so we resort to DNS name resolution. For example, when the server MBX-4 wants to replicate log files that are hosted on MBX-2, it looks at the DAG networks and determines that there are no networks that contain both MBX-4 and MBX-2 – therefore the replication service cannot make a direct TCP connection to the known IP address for MBX-2. Rather then fail replication, we issue a DNS query. The DNS query should always return an IP address that corresponds to a MAPI network (replication networks should not be registered in DNS). Therefore, the final connection from MBX-4 to MBX-2 is performed on IP Address 192.168.0.3. The replication network IS NEVER USED.

This behavior is different though for communications from MBX-2 to MBX-3. If MBX-3 needs to pull log files from MBX-2 the replication service knows that 10.0.0.X can be used, since DAGNetwork02 contains both network ports. Therefore, the replication service can bypass DNS name resolution and make a direct IP connection from 10.0.0.2 to 10.0.0.1 to pull logs from MBX-2 to MBX-3.

The administrator can correct this condition by appropriately collapsing the DAG networks. In this example we know that the underlying routing topology allows for the following:

192.168.0.X <-> 192.168.1.X

10.0.0.X <-> 10.0.1.X

At this point we need to re-assign subnets to the appropriate DAG networks. In this example we will take the 10.0.1.X subnet from DAGNetwork05 and move it to DAGNetwork02. This will leave an empty DAGNetwork05 which can be deleted. We will also take the 192.168.1.X from DAGNetwork02 and move it to DAGNetwork01. This will leave an empty DAGNetwork02. The following example shows the desired final DAG network layout.

Once this is done we will disable replication on the MAPI network allowing only the replication network to initially service log shipping activities. Why do you disable the MAPI network from log shipping activities? Remember that if no other network exists in a DAG to replicate log files we will utilize the MAPI network for log shipping. If the MAPI network is replication enabled, then when the replication service is choosing a network to perform log shipping it considers it at the same weight as identified replication networks. By disabling the MAPI network it is no longer considered at the same weight and therefore all initial log shipping activities are balanced between the enumerated replication networks.

You can use the get-mailboxdatabasecopystatus * –connectionStatus | fl name,outgoingconnections,incominglogcopyingnetwork you can view the networks that are being utilized for inbound and outbound operations.

In this example you can see that all incoming and outgoing connections are occurring on DAGNetwork02.

You can also review a netstat –an an see that log copying activities are occurring on the 10.0.0.X network utilizing port 64327 (the default DAG replication port).