Follow

arcserve-KB : UDP | Exchange Online protect || Failed to write data to mounted volume Error=[This operation returned because the timeout period expired.].

Last Update: 2018-05-14 14:06:48 UTC
Problem Description:  Every time the Exchange Online protection Job is run it fails with the following error “Failed to write data to mounted volume [2b5c9498-21be-453d-a644-6fd44a16c3a4]. Error=[This operation returned because the timeout period expired.].”

Env:

UDP 6.5 update 2

Excerpts from the logs:

Activity logs:

Warning    28-11-17 21:12:31    Office365    Exchangeonline.netwiz.com   16812  Local Site    25084    A makeup job is scheduled at 28/11/2017 21:22:31 for previous failed backup job [jobID=16812].
Error    28-11-17 21:12:24    Office365    Exchangeonline.netwiz.com   16812  Local Site    10114   
Backup job failed.
Error    28-11-17 21:12:23    Office365    Exchangeonline.netwiz.com    16812  Local Site    10198    Failed to Dismount Writable Recovery Point.
Error    28-11-17 21:12:23    Office365   Exchangeonline.netwiz.com    16812  Local Site    14008    The destination volume is dismounted.
Warning    28-11-17 21:12:22    Office365   Exchangeonline.netwiz.com    16812  Local Site    14014    Backup successful for 56 mailbox(es), incomplete for 311 mailbox(es). Next backup job will attempt to process incomplete mailbox(es).
Information    28-11-17 21:12:22    Office365   Exchangeonline.netwiz.com   16812  Local Site    14024    Backed up 24 folders, 9902 items, 1,404,178.00 KB for Mailbox [User mailbox name] in 0 days, 1 hours, 31 minutes, and 2 seconds. The average throughput is 15.06 MB/Min.
Error    28-11-17 21:03:29    Office365   Exchangeonline.netwiz.com    16812  Local Site    10207    Failed to write data to mounted volume [2b5c9498-21be-453d-a644-6fd44a16c3a4]. Error=[This operation returned because the timeout period expired.].

Backup_Job16812_20171127162221_0.log.

2017-11-28 21:03:29.180    E    0030    0000  0   
Exception Type:Arcserve.Office365.Exchange.Ex.Office365Exception
Exception Message:Unable to find the specified file.
Hresult:[-2146233088][80131500]
Exception StackTrace:
2017-11-28 21:03:29.180    E    0030    0000  01    
Exception Type:System.IO.FileNotFoundException
Exception Message:Unable to find the specified file.
Hresult:[-2147024894][80070002]
Exception StackTrace:  at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)    at System.IO.FileStream.WriteCore(Byte[] buffer, Int32 offset, Int32 count)    at System.IO.FileStream.Write(Byte[] array, Int32 offset, Int32 count)    at Arcserve.Office365.Exchange.Util.ReadWriteLockExtension.LockToken.Dispose()    at Arcserve.Office365.Exchange.Util.IOEx.WriteDataToStream(Stream stream, Byte[] buffer, Int32 offset, Int32 length)    at Arcserve.Office365.Exchange.StorageAccess.MountSession.Backup.ExportItemWriter.WriteBufferToStorage(IItemDataSync item, Byte[] buffer, Int32 length)    at Arcserve.Office365.Exchange.EwsApi.Impl.Common.ExportUploadHelper.WriteDataToStream(XmlReader xmlReader, Int32 depth, Action`3 writeBuffer, Action`1 writeError, IItemDataSync itemData)    at Arcserve.Office365.Exchange.EwsApi.Impl.Common.ExportUploadHelper.ParseExportResultXml(HttpWebResponse webResponse, Dictionary`2 dic, IEnumerable`1 exportItems, IExportItemsOper exportOper)

2017-11-28 21:12:22.794    W    0001    0000      The Backup[16812] job completed with warning. Mailbox result:TotalCount:367, SuccessCount:56, PartialSuccessCount:8, SuccessSkipCount:0, FailedCount:0, UndealedCount:303. The incompleted count =FailedCount + UnDealedCount + PartialSuccessCount : 311.. Folder result:TotalCount:4625, SuccessCount:4464, PartialSuccessCount:8, SuccessSkipCount:0, FailedCount:0, UndealedCount:153. The incompleted count =FailedCount + UnDealedCount + PartialSuccessCount : 161.. Item result:TotalCount:1668531, SuccessCount:1634213, PartialSuccessCount:0, SuccessSkipCount:1, FailedCount:150, UndealedCount:34167. The incompleted count =FailedCount + UnDealedCount + PartialSuccessCount : 34317 TransferSize:297,357.00MB, Speend:171.88 MB/Minute.. takes 1 day(s), 4 hour(s),50 minute(s),1 second(s)..
2017-11-28 21:12:22.794    I    0001    0000  Activity logType:[1],activity logMessage:[Backup successful for 56 mailbox(es), incomplete for 311 mailbox(es). Next backup job will attempt to process incomplete mailbox(es).].
2017-11-28 21:12:23.044    E    0001    0000  0    backup incompleted, error detail:ChildLevel:[0], Type:[Arcserve.Office365.Exchange.Ex.Office365Exception], HResult:[-2146233088][80131500], Message:[The system cannot find the path specified. (Exception from HRESULT: 0x80070003)], Source:[Arcserve.Office365.Exchange.DataProtect.Interface], HelpLink:[].
StackTrace:[  at Arcserve.Office365.Exchange.DataProtect.Interface.Backup.Sync.BackupFlowTemplate.BackupSync()
  at Arcserve.Office365.Exchange.Com.Impl.BackupForCom.DoBackup(String dataFolder, String mountVolPath, String catalogFolder, String lastCatalogFolder, String adminUserName, String adminPassword, Boolean isFull, String backupMailboxes, String exBackupFolders)].
Data:

ChildLevel:[1], Type:[Arcserve.Office365.Exchange.Ex.Office365Exception], HResult:[-2146233088][80131500], Message:[The system cannot find the path specified. (Exception from HRESULT: 0x80070003)], Source:[Arcserve.Office365.Exchange.DataProtect.Interface], HelpLink:[].
StackTrace:[  at Arcserve.Office365.Exchange.DataProtect.Interface.Backup.Sync.BackupFlowTemplate.BackupMailboxByTask(ICollection`1 mailboxesUAD)
  at Arcserve.Office365.Exchange.DataProtect.Interface.Backup.Sync.BackupFlowTemplate.BackupSync()].
Data:

ChildLevel:[2], Type:[Arcserve.Office365.Exchange.Ex.Office365ExistException], HResult:[-2146233088][80131500], Message:[The system cannot find the path specified. (Exception from HRESULT: 0x80070003)], Source:[], HelpLink:[].
StackTrace:[].
Data:

ChildLevel:[3], Type:[Arcserve.Office365.Exchange.Ex.Office365ExistException], HResult:[-2146233088][80131500], Message:[The system cannot find the path specified. (Exception from HRESULT: 0x80070003)], Source:[Arcserve.Office365.Exchange.EwsApi], HelpLink:[].
StackTrace:[  at Arcserve.Office365.Exchange.EwsApi.Ex.ExceptionEx.JudgeException(Exception e, Action`2 MustExcute, Action`2 writeToActivityLog, Action`2 cancelExistExceptionProcess)
  at Arcserve.Office365.Exchange.DataProtect.Interface.Backup.Sync.BackupFlowTemplate.DoEachMailbox(MailboxDataSyncWithStatus mailboxesItem)
  at Arcserve.Office365.Exchange.DataProtect.Interface.Backup.Sync.BackupFlowTemplate.<>c__DisplayClassa.<BackupMailboxByTask>b__5()].
Data:
.
Exception Type:Arcserve.Office365.Exchange.Ex.Office365Exception
Exception Message:The system cannot find the path specified. (Exception from HRESULT: 0x80070003)
Hresult:[-2146233088][80131500]
Exception StackTrace:  at Arcserve.Office365.Exchange.DataProtect.Interface.Backup.Sync.BackupFlowTemplate.BackupSync()    at Arcserve.Office365.Exchange.Com.Impl.BackupForCom.DoBackup(String dataFolder, String mountVolPath, String catalogFolder, String lastCatalogFolder, String adminUserName, String adminPassword, Boolean isFull, String backupMailboxes, String exBackupFolders)

2017-11-28 21:12:23.403    I    0001    0000  Release context, old thread id:1, new thread id:1, init count:1, release count:1.

ArcMountDriver.log

[2017/11/28 20:52:24:791  00  17328  18360  0X00000001] AcquireSlice::Wait for flush done:4717,4717Pointer:0 @CWRPCache::AcquireSlice:697    {AFMntExec.exe::AFStor.dll(4175.667)}
[2017/11/28 20:55:50:991  00  17328  18360  0X00000001] AcquireSlice::Wait for flush done:4115,4115Pointer:0 @CWRPCache::AcquireSlice:697    {AFMntExec.exe::AFStor.dll(4175.667)}
[2017/11/28 20:55:50:991  00  17328  18360  0X00000001] AcquireSlice::Wait for flush done:42,42Pointer:0 @CWRPCache::AcquireSlice:697    {AFMntExec.exe::AFStor.dll(4175.667)}
[2017/11/28 21:03:29:117  01  17328  18348  0Xffffffff] IO work thread [18360] timeout, NOT killed. {AFMntExec.exe::AFMntMgr.dll(4175.667)}
[2017/11/28 21:03:29:117  00  17328  18348  0X000005b4] Read/Write 300 s timeout, Len: 4096, Off: 1838772224, Thread ExitCode: 0
 {AFMntExec.exe::AFMntMgr.dll(4175.667)}
[2017/11/28 21:03:29:148  00  17328  18348  0X000005b4] IO request error :
1460 | This operation returned because the timeout period expired..  {AFMntExec.exe::AFMntMgr.dll(4175.667)}
[2017/11/28 21:03:29:148  00  17328  18348  0X000005b4] !!!! [WRP] IO Error 1460. Volume will be dismounted.  {AFMntExec.exe::AFMntMgr.dll(4175.667)}
[2017/11/28 21:03:29:148  02  17328  18348            ] Data thread quit. Set map memory user mode flag to 1  {AFMntExec.exe::AFMntMgr.dll(4175.667)}
[2017/11/28 21:03:29:164  01  17328  18360            ] Write 4096 @ 1838772224, Used time 300046 ms  {AFMntExec.exe::AFMntMgr.dll(4175.667)}
[2017/11/28 21:03:29:164  02  17328  18348            ] CSessionVolume::Close: Pending IO count 0.  {AFMntExec.exe::AFVirtVolume.dll(4175.667)}
[2017/11/28 21:03:29:164  02  17328  18360            ] Working thread quit.  {AFMntExec.exe::AFMntMgr.dll(4175.667)}


Note: The mounted volume here is referred to the mount point – More info - We create a mount point and write data to it during the backup job run. Those data will be saved in the recovery point.




Resolution:

On the Proxy Server used for the Exchange Online protection jobs  we need to create the following registry and reboot the server, then retry the backup:

[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\Executive]
'AdditionalCriticalWorkerThreads'=dword:00000010




More Description:  https://msdn.microsoft.com/en-us/library/ee377058(v=bts.10).aspx

The AdditionalCriticalWorkerThreads value increases the number of critical worker threads created for a specified work queue. Critical worker threads process time-critical work items and have their stack present in physical memory at all times. An insufficient number of threads will reduce the rate at which time-critical work items are serviced; a value that is too high will consume system resources unnecessarily.

Key:

HKLM\SYSTEM\CurrentControlSet\Control\SessionManager\Executive

Value:

AdditionalCriticalWorkerThreads

Data Type:

REG_DWORD

Range:

0x0 (default) to 0x10 (16)

Recommended value:

0x10 (16)

Value exists by default?

Yes



Was this article helpful?
0 out of 0 found this helpful
Have more questions? Submit a request

Comments