Share via

WSE 2016: Error 87 when trying to restore backups of one volume on a client computer

Douglas Muir 1 Reputation point
2020-11-09T21:28:50.017+00:00

WSE 2016: Error 87 when trying to restore backups of one volume on a client computer
Running WSE2016 on a small server that it is used exclusively for backing up 4-6 client computers. For one of the client computers an error occurs when I try and restore a file from any backup of one volume out of 4 volumes being backed up. The result is I can’t restore files from that volume.

The backup and restore of data from the other client computers works perfectly. On the client where the error is occurring; the backup completes successfully for all 4 volumes, and restoring files works perfectly for the other 3 volumes. The error always occurs on the same volume.

The error occurs as follows

  1. The WSE Dashboard is opened by logging in from a client.
  2. The Devices tab is selected, followed by the client computer (with the 4 volumes).
  3. From the task list in the right hand pane, “restore files or folders …” is selected.
  4. The available backups for the client is listed and a backup is elected.
  5. The window to choose a volume is displayed.
  6. I select the volume that generates the error.
  7. The process to open the volume starts and continues to about 98% when the error window is generated.
  8. The error is “The restore process did not succeed. The system cannot find the path specified.”
  9. When I select Cancel to close the error window, the option in the task list in the right hand pane, “restore files or folders …” disappears for all the client computers connected to the server.

The only way to restore the option is to restart the server.

The error is not specific to a single backup of that volume. It has occurred on every backup of that volume I have tried to open. The error also occurs when I attempt to restore files from that volume from any client computer connected to the server. It is not solely occurring when the restore is attempted from the client computer where the volume is.

On the WSE Dashboard in the list of “computers tasks”, I have clicked on the “client computer backup tasks” and on the Tools Tab I have run the task to repair the database. The repair process completes and reports it did not find any errors in the database.

I have also run the command SFC /SCANNOW from an elevated command prompt. It finds no errors/violations.

I can only see one error being reported in the log files in the log file “backup-110720.log”. LIBRARY E:\ is the volume that I am unable to restore backups.

[11/07/2020 15:15:08 23b4] StatusPublisher: Sending Current Operation Status. : 4,S-1-5-21-4060662051-821765639-3708682090-1119, 100, LIBRARY, 0
[11/07/2020 15:15:08 23b4] CommitFile: Rolling Back
[11/07/2020 15:15:08 23b4] RestoreOperation: Restore of LIBRARY E:\ by LIBRARY preparation phase completed.
[11/07/2020 15:15:08 23b4] StatusPublisher: Sending Current Operation Status. : 0,, 0, , 0
[11/07/2020 15:15:08 23b4] Sort: size 28, count 561350, fraction 0.5
[11/07/2020 15:15:08 23b4] Sort: size 44, count 10107, fraction 1
[11/07/2020 15:15:13 23b4] MainService: Error: The Windows Server Client Computer Backup Service encountered the following error: Error code: 87 API name: ReadFile File: H:\ServerFolders\Client Computer Backups\Data.2048.0.dat Error: 87
[11/07/2020 15:15:13 23b4] MainService: Error: The Windows Server Client Computer Backup Service failed at (462) of (admin\serveressentials\backup\pc\util\diskfile.cpp)
[11/07/2020 15:16:13 1f80] *******************************************************************
[11/07/2020 15:16:13 1f80] Backup Service Started.
[11/07/2020 15:16:13 13e4] Listener: Created
[11/07/2020 15:16:13 13e4] StartStopFiles: Backup data file directory is H:\ServerFolders\Client Computer Backups

Any suggestions on how to fix this?
Thanks

Windows Server
Windows Server
A family of Microsoft server operating systems that support enterprise-level management, data storage, applications, and communications.
12,920 questions
0 comments

3 answers

Sort by: Most helpful
Most helpful Newest Oldest
  1. Jenny Yan-MSFT 9,336 Reputation points
    2020-11-10T09:22:45.447+00:00

    Hi,
    MainService: Error: The Windows Server Client Computer Backup Service encountered the following error: Error code: 87 API name: ReadFile File: H:\ServerFolders\Client Computer Backups\Data.2048.0.dat Error: 87
    Per the error details you shared, there is problem when reading the data file in the path, which might be locked by third party process if any.

    admin\serveressentials\backup\pc\util\diskfile.cpp
    The .cpp file is one of the C++ file extension.

    Kindly note that I am going to test a client backup and verify if anything useful could be found.

    Best Regards,
    Jenny

    0 comments
  2. Jenny Yan-MSFT 9,336 Reputation points
    2020-11-13T02:08:19.103+00:00

    Hi,
    Here is the update after simple test. We found it was mountbackup.log that related to the process of restoring rather than the backup log you shared.

    Since then, please try to do clean boot(on client PC) to temp disable third party services/tools and verify if the restore could be achieved.
    how-to-perform-a-clean-boot-in-windows
    https://support.microsoft.com/en-sg/help/929135/how-to-perform-a-clean-boot-in-windows

    Hope this helps and please help to accept as Answer if the response is useful.

    Thanks,
    Jenny

    0 comments
  3. Douglas Muir 1 Reputation point
    2020-11-20T00:00:32.687+00:00

    Thanks for your reply.

    I performed a clean boot on the client PC and repeated the attempt to restore a file from the backup volume that would not complete with the “Path not Found error message”. I still cannot restore a file from any backups of that volume.
    I repeated the same exercise as before, I first was able to restore a file from a backup of the ‘C’ drive, when I tried to restore a file from the backup of the ‘E” drive I got the path not found error.

    I have included extract of the server side log file ‘backup-111920.log’ and the client pc log file ‘MountBackup-111920.log’. I have included extracts, first for the successful restore and then for the restore that failed.
    The error in the MountBackup log file appears to be generated after the error being recorded in the server side Backup.log

    Server side backup log of successful restore:
    [11/19/2020 15:05:25 2160] StatusPublisher: Sending Current Operation Status. : 4,S-1-5-21-4060662051-821765639-3708682090-1119, 100, LIBRARY, 0
    [11/19/2020 15:05:25 2160] CommitFile: Rolling Back
    [11/19/2020 15:05:25 2160] RestoreOperation: Restore of LIBRARY C:\ by LIBRARY preparation phase completed.
    [11/19/2020 15:05:25 2160] StatusPublisher: Sending Current Operation Status. : 0,, 0, , 0
    [11/19/2020 15:05:25 2160] Sort: size 28, count 1929017, fraction 0.5
    [11/19/2020 15:05:25 2160] Sort: size 44, count 10659, fraction 1
    [11/19/2020 15:05:27 2160] RestoreOperation: Client phase 6 count 0
    [11/19/2020 15:05:27 2160] RestoreOperation: Client phase 7 count 0
    [11/19/2020 15:05:55 2160] RestoreOperation: Restore of LIBRARY C:\ by LIBRARY completed successfully.
    [11/19/2020 15:05:55 2160] BackupProtocol: Got closed code 10
    [11/19/2020 15:05:55 2160] Session: ThreadMain end for 0000022A2A0E6590
    [11/19/2020 15:05:55 2160] ReconnectableStream: Destroyed ServerReconnectableStream for {57947E03-B512-4D75-99A8-276CFEEBD7F8}
    [11/19/2020 15:05:59 788] Session: DoGetBackupSets S-1-5-21-4060662051-821765639-3708682090-1119
    [11/19/2020 15:05:59 788] Session: DoGetVolumes S-1-5-21-4060662051-821765639-3708682090-1119 1

    Client side restore Mount backup log
    [11/19/2020 15:05:25 980] PrepareBackupServerForMount: The backup server reported 100 percent complete
    [11/19/2020 15:05:25 980] PrepareBackupServerForMount: Waiting for the backup server completed
    [11/19/2020 15:05:25 980] TICK,PREPED, 16844
    [11/19/2020 15:05:25 980] Creating volume
    [11/19/2020 15:05:25 980] MountedRestoreHelper::CreateVolume() - Success with IOCTL_BACKUPREADER_CREATE_VOLUME, volumeID=0
    [11/19/2020 15:05:27 980] Driver transition (mounting volume) for 0 OK
    [11/19/2020 15:05:27 980] Mounting volume
    [11/19/2020 15:05:27 980] MountedRestoreHelper::Mount() - Success with IOCTL_BACKUPREADER_MOUNT_VOLUME IOCTL
    [11/19/2020 15:05:27 980] Got volume guid path \?\Volume{5a32ea55-2abb-11eb-8053-b06ebf3a3f75}
    [11/19/2020 15:05:27 980] SetVolumeMountPoint returned error code 87. This might be benign
    [11/19/2020 15:05:27 980] Starting reader thread
    [11/19/2020 15:05:27 980] TICK,THREAD RESTARTED, 18687
    [11/19/2020 15:05:27 980] Driver transition (mounted volume) for 0 OK
    [11/19/2020 15:05:27 980] TICK,MOUNTED, 18687
    [11/19/2020 15:05:27 2738] Cluster reads=1, writes=0, errors=0. [0:4]
    [11/19/2020 15:05:28 2d64] Got letter Z, mount point Z:\
    [11/19/2020 15:05:28 2d64] Deleting cluster cache
    [11/19/2020 15:05:55 5d4] Deleting mount point at Z:\
    [11/19/2020 15:05:55 5d4] Calling m_Restore.UnMountDrive
    [11/19/2020 15:05:55 2738] MountedRestoreHelper::GetClusterRequestFromDriver() - aborting due to stop event
    [11/19/2020 15:05:55 2738] RestoreHelper::T_ClusterThread - we're stopping, shutting down our driver connection
    [11/19/2020 15:05:55 2738] MountedRestoreHelper::UnMount() - Success with IOCTL_BACKUPREADER_DELETE_VOLUME IOCTL
    [11/19/2020 15:05:55 2738] Total cluster reads=1129, writes=0, errors=0.
    [11/19/2020 15:05:55 980] Cluster thread exited
    [11/19/2020 15:05:55 980] Cluster reader thread finished
    [11/19/2020 15:05:55 980] Exiting thread...
    [11/19/2020 15:05:55 5d4] BackupProtocol: disconnecting protocol: RestoreHelper: Disconnecting from server
    [11/19/2020 15:05:55 5d4] m_Restore.UnMountDrive returned
    [11/19/2020 15:05:55 5d4] Calling m_Restore.DisconnectServer

    Server side backup log of unsuccessful restore:
    [11/19/2020 15:06:07 2378] StatusPublisher: Sending Current Operation Status. : 4,S-1-5-21-4060662051-821765639-3708682090-1119, 99, LIBRARY, 0
    [11/19/2020 15:06:07 2378] StatusPublisher: Sending Current Operation Status. : 4,S-1-5-21-4060662051-821765639-3708682090-1119, 100, LIBRARY, 0
    [11/19/2020 15:06:07 2378] CommitFile: Rolling Back
    [11/19/2020 15:06:07 2378] RestoreOperation: Restore of LIBRARY E:\ by LIBRARY preparation phase completed.
    [11/19/2020 15:06:07 2378] StatusPublisher: Sending Current Operation Status. : 0,, 0, , 0
    [11/19/2020 15:06:07 2378] Sort: size 28, count 567572, fraction 0.5
    [11/19/2020 15:06:07 2378] Sort: size 44, count 10117, fraction 1
    [11/19/2020 15:06:12 2378] MainService: Error: The Windows Server Client Computer Backup Service encountered the following error: Error code: 87 API name: ReadFile File: H:\ServerFolders\Client Computer Backups\Data.2048.0.dat Error: 87
    [11/19/2020 15:06:12 2378] MainService: Error: The Windows Server Client Computer Backup Service failed at (462) of (admin\serveressentials\backup\pc\util\diskfile.cpp)
    [11/19/2020 15:07:13 1d7c] *******************************************************************
    [11/19/2020 15:07:13 1d7c] Backup Service Started.
    [11/19/2020 15:07:13 1b9c] Listener: Created
    [11/19/2020 15:07:13 1b9c] StartStopFiles: Backup data file directory is H:\ServerFolders\Client Computer Backups
    [11/19/2020 15:07:13 1b9c] CommitFile: Finishing old commit. Commit flag 0
    [11/19/2020 15:07:13 1b9c] CommitFile: Deleting all files with pattern: *.new
    [11/19/2020 15:07:13 1b9c] CommitFile: Deleting all files with pattern: *.confignew
    [11/19/2020 15:07:13 1b9c] CommitFile: Deleting all files with pattern: *.ccnew
    [11/19/2020 15:07:13 1b9c] CommitFile: Deleting all files with pattern: *.tmp
    [11/19/2020 15:07:13 1b9c] DatabaseInfo: Versions code (12, 12) database (12, 12)
    [11/19/2020 15:07:13 1b9c] BCC: Running basic consistency checker

    Client side restore Mount backup log:
    [11/19/2020 15:06:07 2e0c] PrepareBackupServerForMount: The backup server reported 100 percent complete
    [11/19/2020 15:06:07 2e0c] PrepareBackupServerForMount: Waiting for the backup server completed
    [11/19/2020 15:06:07 2e0c] TICK,PREPED, 2360
    [11/19/2020 15:06:07 2e0c] Creating volume
    [11/19/2020 15:06:07 2e0c] MountedRestoreHelper::CreateVolume() - Success with IOCTL_BACKUPREADER_CREATE_VOLUME, volumeID=0
    [11/19/2020 15:06:07 2e0c] BackupProtocol: Got abort code BACKUPSERVER -1 12
    [11/19/2020 15:06:07 2e0c] Got an invalid op back(0), failing.
    [11/19/2020 15:06:07 2e0c] ERROR: Prefetching NTFS clusters failed with error 59
    [11/19/2020 15:06:07 2e0c] Driver transition (mounting volume) for 0 OK
    [11/19/2020 15:06:07 2e0c] Mounting volume
    [11/19/2020 15:06:07 2e0c] MountedRestoreHelper::Mount() - Success with IOCTL_BACKUPREADER_MOUNT_VOLUME IOCTL
    [11/19/2020 15:06:07 2e0c] Got volume guid path \?\Volume{5a32ea8a-2abb-11eb-8053-b06ebf3a3f75}
    [11/19/2020 15:06:07 2e0c] SetVolumeMountPoint returned error code 87. This might be benign
    [11/19/2020 15:06:07 2e0c] Starting reader thread
    [11/19/2020 15:06:07 2e0c] TICK,THREAD RESTARTED, 2532
    [11/19/2020 15:06:07 2e0c] Driver transition (mounted volume) for 0 OK
    [11/19/2020 15:06:07 2e0c] TICK,MOUNTED, 2532
    [11/19/2020 15:06:07 2f70] Got an invalid op back(0), failing.
    [11/19/2020 15:06:07 2f70] RestoreHelper::T_ClusterThread - an error occurred (59), closing up the driver
    [11/19/2020 15:06:07 2f70] MountedRestoreHelper::UnMount() - Success with IOCTL_BACKUPREADER_DELETE_VOLUME IOCTL
    [11/19/2020 15:06:07 2f70] Total cluster reads=0, writes=0, errors=0.
    [11/19/2020 15:06:07 2e0c] Cluster thread exited
    [11/19/2020 15:06:07 2e0c] Cluster reader thread finished
    [11/19/2020 15:06:07 2e0c] Exiting thread...
    [11/19/2020 15:06:13 21dc] Got letter Z, mount point Z:\
    [11/19/2020 15:06:13 21dc] Deleting cluster cache
    [11/19/2020 15:06:15 5d4] Deleting mount point at Z:\
    [11/19/2020 15:06:15 5d4] ERROR: UnmountBackup failed, HR=0x80070002 (at func: DeleteVolumeMountPoint, admin\serveressentials\backup\pc\sfr\mountbackup\viewbackup.cpp (533)
    [11/19/2020 15:06:15 5d4] Calling m_Restore.UnMountDrive
    [11/19/2020 15:06:15 5d4] BackupProtocol: disconnecting protocol: RestoreHelper: Disconnecting from server
    [11/19/2020 15:06:15 5d4] m_Restore.UnMountDrive returned
    [11/19/2020 15:06:15 5d4] Calling m_Restore.DisconnectServer
    [11/19/2020 15:06:15 5d4] BackupProtocol: disconnecting protocol: RestoreHelper: Disconnecting from server
    [11/19/2020 15:06:15 5d4] m_Restore.DisconnectServer OK
    [11/19/2020 15:06:15 5d4] BackupProtocol: disconnecting protocol: RestoreHelper: Disconnecting from server
    [11/19/2020 15:06:15 5d4] BackupProtocol: disconnecting protocol: RestoreHelper: Disconnecting from server
    [11/19/2020 15:06:15 5d4] ReconnectableStream: Destroyed ClientReconnectableStream for {F120752C-C11C-4824-962A-84912BFE0984}

    Any further suggestions? Thanks

    0 comments

Your answer

Answers can be marked as Accepted Answers by the question author, which helps users to know the answer solved the author's problem.