Restore to Recovery Storage Group Fails with 0xa0008488 in Backup Executive

This issue dealt specifically with a customer attempting to restore a 120GB mail store to a Recovery Storage Group.

The customer was using Exchange 2003 SP2 and Backup Executive 9.1.

Primary Issue & Symptoms:

Customer was attempting to restore an Exchange 2003 Mailbox Database to a Recovery Storage Group.  Backup Executive would initalize the job successfully but the customer was noticing that the byte count never increased above 238 bytes.  After 3 hours the restore would eventually timeout and the following error and status code would be documented in the restore log:

Job Competion Status
Job Ended: <time stamp>
Completed Status:  Failed
Final Error:  0xa0008488 -- Access is Denied

Troubleshooting Steps:

Clearly the "Access Is Denied" error suggests a permissions related issue.  Reviewing the configuration of the Recovery Storage Group showed that the Database Path for the linked store was being written to the f:\.

The first thing I did was review the NTFS permissions across the drives and did not notice any issues.

I then had the customer create a folder share on the root of the f:\, and verified that users could access the share remotely.

I  then had the customer create a Test mail store (within the Production Storage Group where the database he was attempting to restore resided) and then had them add a single Test Mailbox to the store.  We sent the Test User a single message and then backed up Test Store with NTBackup as well as Backup Executive.  We added the Test Store as a "linked database" with the RSG, and ensured that the linked database and log file path was also confgured for the f:\.  We then attempted a restore of Test via NTBackup.

This restore operation also failed, however NTBackup returned a different error stating that it was "Unable to Create the Log Path".  A review of the application log showed the following additional error:

Event Type:  Error
Event Source: ESE Backup
Event ID: 950
Description:  Unexpected file system error 53 encountered while opening the restore environment file."

What is interesting about this event and error is:

1.  It suggests that the natue of the error was during the creation of the Exchange restore environment file (e.g. restore.env).
2.  The System Error Code of 53.  This equates to ERROR_BAD_NETPATH

At this point, I wanted to verify that Test could be restored to a drive outside of the f:\.  So, we removed the linked stores, and rebuilt the RSG linking Test then configuring the Log and Database paths to the e:\.

We then attempted a restore of Test with NTBackup which completed successfully. 
Removed the stores and retested a restore with Backup Executive which also restored successfully.

Conclusion 1:  

Again, clearly the f:\ is suspect here as evident by the fact that both NTBackup and Backup Executive can both restore to a location outside of f:\.  This would also suggest no issue with Backup Executive or NTBackup as well as no issue with the configuration of the RSG itself (as restores can be completed regardless of Agent).

The obvious question here is what is unique about the f:\?  At this point I was informed that the f:\ was in fact an External USB Drive that had "temporarily" been added for these specific recovery operations because there was not enough free space locally on any drive to support the size of the file being restored.  In short, the customer had never tested this before. 

Troubleshooting (Continued):

When any valid Backup/Restore agent (e.g. one that subscribes to the rules and methods of the APIs responsible for Exchange aware backup/restore) restores an Exchange Database (regardless of whether or not it resides in an RSG or production directory), ESE (the Extensible Storage Engine) needs to be able to physically map the path specified for the Temporary Location for the restore (e.g. the path specified for logs coming off tape as well as for the creation of the restore environment file).  It does this via a UNC path that includes within the path the Admin Share for the target drive.

 "\\ Server Name\<AdminShare of Drive>\Temp Directory Specified for Log Files"

 Example:  \\ My Server\f$\MyRestore

So to verify that the shares were setup properly, I had the customer open CMD and enter:  NET SHARE
NET SHARE will list all configured Shares on a System.
Reviewing the Output of NET SHARE, clearly showed that Default Admin share was not created for the f:\, but was present for all other drives.  Which explained why a restore to the e:\ in the previous example worked successfully and also provided a logically sound reason for System Error 53 in the 950 Event.

Conclusion 2:

The fact that the Default Admin share for the f:\ was not present suggested the following:

1.  An Administrator had manually removed the Admin Share (which seemed unlikely).
2.  There was a problem with Disk Manager creating the share for External Storage (more likely). 

Admin Shares (drive$) are created during startup when the SERVER service fully initalizes.  My suspicion was that most likely the issue with the Admin Share not being created on the External Storage was occuring because the External Storage Device wasn't fully initalized by the Disk Manager System when the SERVER service has completed startup.  As such, the SERVER service assigned no share to the drive because it wasn't technically valid at the time of assignment.

I tested this hypothesis internally with a personal USB Hard-Drive and witnessed the identical behavior (there was no "Default Share" for my USB Hard-Drive).

Troubleshooting (cont.):

On my own system (one without Exchange installed), I restarted the SERVER service and re-ran NET SHARE.  The result was that my own personal External USB Drive now showed a proper ADMIN Share.  This seemed to back up my conclusions about how the SERVER service creates shares for the External USB Drive.

The next logical step in this case was to restart the SERVER service on the Exchange Server where the RSG had been configured.

There are two primary Exchange Services that have a dependency of the SERVER service.  Namely the Information Store (MSExchangeIS), and the System Attendant (MSExchangeSA).

Prior to restarting the SERVER service, I had the customer manually dismount all production stores (to force all pending writes into the store and bring the databases into a CONSISTENT or "Clean Shutdown" State), then proceeded to manually stop the Information Store and System Attendant (as well as the Computer Browser service which is dependent on the SERVER service) .  With these sevices offline, I restarted the Server service from the command line:

net stop srv
net start srv

With the SERVER service back online, I proceeded to bring the Computer Browser, Exchange Information Store, and Exchange System Attendant Services back online. 

At this point ran NET SHARE.

Result:  The f:\ was now showing as have a valid Default Admin Share.  From the cmd line you would see something like this:

NET SHARE

Share name   Resource                        Remark
-------------------------------------------------------------------------------
F$           F:\                             Default share

We then rebuilt our Recovery Storage Group, linked the original database back to the RSG, specificed our Database, Log and TEMP paths onto the f:\ and successfully restored the mail database via Backup Executive.

Conclusion:

It would appear that when External USB Storage is used, Windows does not automatically create the Admin Shares for the USB drive.  As previously discussed, Admin Shares are created during server startup when the SERVER service fully initializes.  My "professional opinion" (I am after all an Exchange Specialist not a Windows specialist), is that most likely this occurs because the External Storage isn't fully initialized by the Disk Manager System when the SERVER service has completed startup.  This is why a "reboot" of the server wouldn't correct the issue (it would simply recreate the issue).  By restarting the SERVER service with the USB Drive fully initalized, you effectively force the shares to be re-evaluated and recreated.

So what is important to remember here is that if you ever have to perform a similar operation (restoring an Exchange Database to an External Drive), you need to ensure that the Admin Share for the Drive is configured properly prior to attempting the restore (as Exchange needs to directly map to the the UNC path specified via the Admin Share). The Admin Share itself is not needed for a backup, but it should go without saying that no production Exchange Database should ever by physically located on a USB drive.  Otherwise, you and I will probably be working on an Exchange Performance related issue in the near to distant future (hello RPC pop-up).

Hope you find this interesting.

Happy Trails.

Eric