Archived Items are not restored in spite of the DTrace saying that it was successful

Question

Hello,

We are using EV 10.0.4 with Exchange 2013. We have Virtual Vault enabled. We have a situation where in the archived items are not being restored.

We isolated the fact that the item could have been moved from the original location and hence tried restoring an item from the original location itself.

The item would go through the process of retrieval (change of icons) and then turn back to the shortcut itself.

Ran a Dtrace in the background (Client Trace as well as on the server), with the Retrieval Task and Storage Restore. The Dtrace suggests that the restore of the item was successful.

An excerpt of the Dtrace:

12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CClientIdentity::CheckAccess:#501} [VF-ROOT\KavitaR] is requesting permissions [1] on Vault [17FA68A681E82564C84C1B84C26EC1FC41110000evserver01].
	1533&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::SetReadLock:#263} [VaultPermCacheLock] WaitForSingleObject on write mutex [0x640] returned [0x0]
	1534&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::SetReadLock:#293} [VaultPermCacheLock] WaitForMultipleObjects on thread mutex [0x644], semaphore [0x634] returned [0x0]
	1535&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::SetReadLock:#306} [VaultPermCacheLock] we are now reading so no writes allowed
	1536&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::ResetReadLock:#190} [VaultPermCacheLock] WaitForSingleObject on [0x644] returned [0x0]
	1537&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::ResetReadLock:#220} [VaultPermCacheLock] Released Semaphore, previous count was [99]
	1538&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::ResetReadLock:#225} [VaultPermCacheLock] we were the last reader so we are now write ready
	1540&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
	1541&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
	1543&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
	1544&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
	1545&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::SetWriteLock:#369} [VaultPermCacheLock] WaitForSingleObject on write mutex [0x640] returned [0x0]
	1546&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CReadWriteLock::SetWriteLock:#387} [VaultPermCacheLock] WaitForMultipleObjects on thread mutex [0x644], event [0x610] returned [0x0]
	1547&nbsp;12:53:20.478&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CClientIdentity::CheckAccess(vSIDS)} (Exit) Status: [Success]
	1548&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CCARestHelper::RetrieveMarkedItems:#290} Calling RestoreItemV35
	1549&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CRestorationAgent::RestoreItemV35:#393} Restoring Saveset [201509101912387~201508271244170000~Z~C10CC08984ED6A78A5C1B5BB7A2B2181] Transaction [414D8C47DBA4194592AC706E4A11F791] from Vault [17FA68A681E82564C84C1B84C26EC1FC41110000evserver01]. Retry [0] of [3].
	1550&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CStorageRestore::CStorageRestore} (Entry)
	1551&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CStorageRestore::CStorageRestore} (Exit) Status: [Success]
	1552&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CRestorationAgent::RestoreItemV35:#437} Allocating a [899] byte buffer for the Agents data...
	1553&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CRestorationAgent::RestoreItemV35:#456} Written [326] bytes of Agents data to buffer so far.
	1554&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CRestorationAgent::RestoreItemV35:#472} Written [283] byte shortcut accessor to buffer: [0x0]
	1555&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CRestorationAgent::RestoreItemV35:#486} Passing restore request to Storage Service...
	1556&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CStorageRestore::Fetch} (Entry)
	1557&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::CQueue} (Entry)
	1558&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::CQueue} (Exit)
	1559&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:H&nbsp;{CStorageRestore::Fetch}|Fetching saveset.|SavesetID: 201509101912387~201508271244170000~Z~C10CC08984ED6A78A5C1B5BB7A2B2181|VaultID: 17FA68A681E82564C84C1B84C26EC1FC41110000evserver01|TransactionID: 414D8C47DBA4194592AC706E4A11F791|ServiceEntryID: |RestTaskEntryID: 1F0A43A3F8AED0F4E94F4C98ECB7944811012000evserver01|CallerSID: |PSTFile: NULL|RestoreAndDelete: FALSE|PSTFormat: UNICODE|RestoreShortcuts: FALSE|
	1561&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
	1562&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
	1563&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{VaultCoCreateInstanceEx} CLSID [{4EC6FF76-C97A-11D1-90E0-0000F879BE6A}] Server Name [(null)] Used Server Name [(null)] Num of attempts [1] Total elapsed [0.000s] Result [Success&nbsp; (0)]
	1564&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CDirectoryVaultObject::GetAttributeListFromType Unknown type - RetrievalTaskView
	1565&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CStorageRestore::Fetch}|Spool Queue is: DIRECT=OS:evapp-arc01\Private$\Enterprise Vault Spool Queue|Create Queue: False
	1566&nbsp;12:53:20.494&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::SetVaultSiteAccount} (Entry)
	1567&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CQueue::SetVaultSiteAccount}|Cached SiteId: |Cached StorageEntryId: |SiteID: True|New Entry ID: 1B1A3798240C102499DCE0301C19D2F231d10000evserver01
	1569&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
	1570&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
	1571&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CQueue::SetVaultSiteAccount}|Site Account Details: &lt;Domain_Name&gt;\VSA
	1572&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::SetVaultSiteAccount} (Exit) Status: [Success]
	1573&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Open} (Entry) Opening queue [DIRECT=OS:&lt;EV Servername&gt;\Private$\Enterprise Vault Spool Queue].
	1574&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Close} (Entry)
	1575&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Close} (Exit) Status: [Success]
	1576&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Open} (Exit) Status: [Success]
	1577&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Close} (Entry)
	1578&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Close} (Exit) Status: [Success]
	1580&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
	1581&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
	1582&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{VaultCoCreateInstanceEx} CLSID [{4EC6FF76-C97A-11D1-90E0-0000F879BE6A}] Server Name [(null)] Used Server Name [(null)] Num of attempts [1] Total elapsed [0.000s] Result [Success&nbsp; (0)]
	1583&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CStorageRestore::Fetch}|Restore Queue: DIRECT=OS:&lt;EV Servername&gt;\Private$\Enterprise Vault Storage Restore
	1584&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CStorageRestore::Fetch}|Loading restore parameters to queue: DIRECT=OS:&lt;EV Servername&gt;\Private$\Enterprise Vault Spool Queue
	1585&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::CQueue} (Entry)
	1586&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::CQueue} (Exit)
	1587&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CStorageRestore::Fetch}|Preparing queue: DIRECT=OS:&lt;EV Servername&gt;\Private$\Enterprise Vault Storage Restore|Different queue: True|Init Queue: True
	1589&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
	1590&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
	1591&nbsp;12:53:20.525&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{VaultCoCreateInstanceEx} CLSID [{4EC6FF76-C97A-11D1-90E0-0000F879BE6A}] Server Name [(null)] Used Server Name [(null)] Num of attempts [1] Total elapsed [0.000s] Result [Success&nbsp; (0)]
	1592&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Open} (Entry) Opening queue [DIRECT=OS:&lt;EVServername&gt;\Private$\Enterprise Vault Storage Restore], format name [DIRECT=OS:&lt;EVServername&gt;\Private$\Enterprise Vault Storage Restore].
	1593&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Close} (Entry)
	1594&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Close} (Exit) Status: [Success]
	1595&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::Open} (Exit) Status: [Success]
	1596&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::~CQueue} (Entry)
	1597&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CQueue::~CQueue} (Exit)
	1598&nbsp;12:53:20.541&nbsp; [3660]&nbsp;(StorageRestore)&nbsp;&lt;6340&gt;&nbsp;EV:L&nbsp;{CSavesetRestore::EstablishJournalRestore} (Entry)
	1599&nbsp;12:53:20.541&nbsp; [3660]&nbsp;(StorageRestore)&nbsp;&lt;6340&gt;&nbsp;EV:L&nbsp;{CStore::IsOpenVault} (Entry)
	1600&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:L&nbsp;{CStorageRestore::Fetch} (Exit) Status: [One or more of the properties passed resulted in a warning, but the function completed.&nbsp; (0x400e0001)]
	1601&nbsp;12:53:20.541&nbsp; [3660]&nbsp;(StorageRestore)&nbsp;&lt;6340&gt;&nbsp;EV:L&nbsp;{CStore::IsOpenVault}|Requested: 17FA68A681E82564C84C1B84C26EC1FC41110000evserver01 Current: 1A72FA1667E8936479F56AC137F1800561110000evserver01 Open: False
	1602&nbsp;12:53:20.541&nbsp; [3660]&nbsp;(StorageRestore)&nbsp;&lt;6340&gt;&nbsp;EV:L&nbsp;{CStore::IsOpenVault} (Exit)
	1603&nbsp;12:53:20.541&nbsp; [18908]&nbsp;(RetrievalTask)&nbsp;&lt;23212&gt;&nbsp;EV:M&nbsp;{CRestorationAgent::RestoreItemV35:#519} Finished restoring Saveset [201509101912387~201508271244170000~Z~C10CC08984ED6A78A5C1B5BB7A2B2181]: [0x400e0001]
	&nbsp;

Need help to understand what is going on.

gertjana · Answer

Hello Batman :-)

I am not sure this is going to help, but it is worth a try. I experienced the same more or less.

I restored an item back into the 'restored items' folder, so I know where to find it. It restored succesfully. I restored an item from 2013. I could open the item from the search, so I know it is there.

When looking in Outlook, I did not see the item.

After researching wtf went on, I found that a policy had been applied, setting Outlook in cached mode, and only keeping items for up to 12 months. I changed that to be in 'online mode', and then the item showed.

Apparently, when being in cached mode with only 12 months, the older item, even when restored today, was considered to be older, and did not show.

this might or might not be the case in your situation, but it is worth a check. this was Outlook 2013 x86, against Exchange 2010, with EV11.0.1 CHF2.

&nbsp;

the_dark_knight · Answer

Hey GertjanA,

The setting,&nbsp;Outlook in Cached Mode,&nbsp;which is in Outlook 2013 (we are using the same here as well), is a pre-requisite for Vault Cache(VC)/Virtual Vault(VV). And we are using VC/VV.

If I change it, that would nullify the objective of having VC/VV in the environment, would it not? I still have to test the disabling of the Cache Mode in Outlook to see if it matches your experience or not. I did notice that we can set limit of items that will appear should Outlook be in Cached Mode.Will check it out and update this post.

gertjana · Answer

Cached mode is no longer a requirement :-)

On your (top of my head, but here goes) Desktop policy, VaultCache, dropdown advanced (??)&nbsp; you should see somewhere "require OST". When set to N, you set Outlook in online mode, and still get your VC,

&nbsp;

Edit:

Desktop policy, tab Advanced, dropdown Vault Cache, setting Offline store required = Yes/No

From the Help:

Offline store required (Exchange Vault Cache setting)
	Description:&nbsp; Controls whether Vault Cache can be enabled when no offline store is present.
	Users have offline store (OST) files if Outlook Cached Exchange Mode is enabled.
	If a user does not have an OST file, Enterprise Vault cannot perform preemptive caching.

If there is no preemptive caching, there is an increased load on Vault Cache content synchronization
	for newly archived items. The increased load is only a consideration if the Vault Cache content
	strategy is Store all items.
	&nbsp;
	Supported values:
	Yes (default). An offline store is required for Vault Cache to be enabled.
	No. An offline store is not required for Vault Cache to be enabled.
	&nbsp;
	Legacy name:&nbsp; OVRequireOfflineStore
	&nbsp;

the_dark_knight · Answer

Hi,

I stand corrected.

From what you suggest, it appears that if I need pre-emptive caching, only then would setting "OVRequireOfflineStore" to 'Yes' would be logical else I can set it to 'No' and Vault Cache will still be able to store items in the Cache. The impact being on the Content Synchronization. Right?

gertjana · Answer

Correct.

High-level:

Enable Vault Cache. An initial sync is done, header only.

then items (provided you select to do the all items sync) are synced.

when in sync, and having an OST, the EV client puts items which will be archived directy in the VC files = pre-emptive caching. No OST = no pre-emptive caching.

Forum Discussion

Archived Items are not restored in spite of the DTrace saying that it was successful

Related Content

Re: Restore failing with error : Error bptm ... cannot write data to socket, Broken pipe

Kubernetes namespace restore from snapshot copy returned partial success.

NBU restore success but RMAN archive errors occur

BMR restore.

Report Restore

Recent Discussions

Enterprise Vault properties tab "Enterprise Vault is currently unavailable".

How to check Total Number of Mailbox Archived

Can not delete 64bit Index Location after upgrade all index to Elasticsearch

Enterprise Vault MPIP encrypted email decryption is not working

After archiving user mail, Exchange Mailbox size not free-up