10-30-2017 02:49 AM
Hi, it is since October 2nd that Storage Expiry job no longer delete items. I don't understand the reason. Every day the eventlog reports 0 items deleted. Also ran it in report mode and I get the same result.
I ran the query suggested in this technote (https://www.veritas.com/support/en_US/article.100018928.html) against my db and actually the returned recordsets show thousands of items expired.
Maybe is there something that could prevent Storage Expiry from deleting stuff, ie disk free space, or other constraints ? Or some checkbox to doublecheck?
PS: EV server restarted tonight.
Thank you,
Francesco B.
10-30-2017 05:45 AM
Hello Francesco,
There might be several reasons, but the most usual one is that the items you find have a different retention category. Are you sure that the items have the retention category you expect them to have? I have seen some cases where a customer changed the retention category from 10 to 7 years for the same archive. Any item archived before that was changed will have 10 year retention. I assume you do not have other 'strange' errors in the eventlog related to expiry?
Top check, you might be able to run a dtrace against the StorageDelete process, and see if that gives a hint.
10-30-2017 07:20 AM
Hello, the retention category wasn't modified in any part since the storage expiry activation. No errors in my eventlog related to the storage delete process. There is something that I'm missing for sure but I don't know what.
In any way, I ran the DTrace. I paste here the section related to a user that is in the provisionin group belonging to the retention category with ID 1 (that is the "Default retention category" to which I applied 6 years retention moths ago). The query I linked in the post above, for this user, returns 4156 expired items. The DTrace extract:
17145 14:33:34.347 [3996] (StorageDelete) <7472> EV:M {CExpireVaultStore::ExpireVaultUseDB}|False expired item(s)deleted.|Archive EntryID: 157AD044A8B85B84A99A1BC9A0DBC63931110000evsite|Archive Name: ************ 17146 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::~CStore} (Entry) 17147 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::CloseVault} (Entry) 17148 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CVault::~CVault} (Entry) 17149 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CVault::~CVault} (Exit) 17150 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CSavesetXMLBuilder::Unload} Releasing cached XML Indexable Item instance 17151 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CExclusiveUseThread::EndExclusiveUse} (Entry) 17152 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CExclusiveUseThread::EndExclusiveUse} (Exit) 17153 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::CloseVault} (Exit) 17154 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::CloseIndexerNotifier} (Entry) 17155 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::~CIndexerNotifier} (Entry) 17156 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CommitChanges} (Entry) 17157 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CommitChanges:#200} No changes to commit, so doing nothing. 17158 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CommitChanges} (Exit) Status: [Success] 17159 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::~CIndexerNotifier} (Exit) 17160 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::CloseIndexerNotifier} (Exit) 17161 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::CloseDatabase} (Entry) 17162 14:33:34.347 [3996] (StorageDelete) <7472> EV:L SingletonRegistry: US '0X1E6A2E8TransactionContext' 17163 14:33:34.347 [3996] (StorageDelete) <7472> EV:L SingletonRegistry: US '0X1E6A2E81' 17164 14:33:34.347 [3996] (StorageDelete) <7472> EV:L SingletonRegistry: US '0X1E6A2E8' 17165 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::CloseDatabase} (Exit) 17166 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStreamerObjectCache::ReleaseObjectCacheOnThread} (Entry) Thread Id=7472 17167 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStreamerObjectCache::ReleaseObjectCacheOnThread:#277} The streamer and callback object caches for this thread are already empty. 17168 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStreamerObjectCache::ReleaseObjectCacheOnThread} (Exit) 17169 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStore::~CStore} (Exit) 17170 14:33:34.347 [3996] (StorageDelete) <7472> EV:L {CStorageSession::~CStorageSession} (Entry) 17171 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStorageSession::~CStorageSession} (Exit) 17172 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CExpireVaultStore::ExpireVaultUseDB} (Exit) Status: [Success] 17173 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CExpireVaultStore::WaitIfOutOfSchedule} (Entry) 17174 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CExpireVaultStore::WaitIfOutOfSchedule} (Exit) Status: [Success] 17175 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CListVaults::SkipVaultsMarkedNoExpire} (Entry) 17176 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CListVaults::SkipVaultsMarkedNoExpire} (Exit) Status: [Success] 17177 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CExpireVaultStore::ExpireVaultUseDB} (Entry) 17178 14:33:34.348 [3996] (StorageDelete) <7472> EV:M {CExpireVaultStore::ExpireVaultUseDB}|Processing Vault: |EntryID: 18E063F9DAC525A4A8FC962B62B7CA3081110000evsite|Name: Silvia Noris 17179 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStorageSession::CStorageSession} (Entry) 17180 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CPoisonPill::CPPControl::DisableMonitoring} (Entry) 17181 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CPoisonPill::CPPControl::DisableMonitoring} (Exit) Status: [Success] 17182 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStorageSession::CStorageSession} (Exit) 17183 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStorageSession::OpenStore} (Entry) 17184 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStore::CStore} (Entry) 17185 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStore::CStore} (Exit) 17186 14:33:34.348 [3996] (StorageDelete) <7472> EV:L {CStorageSession::OpenStore} (Exit) Status: [Success] 17187 14:33:34.348 [3996] (StorageDelete) <7472> EV:L CADOContext::CreateConnection entry 17188 14:33:34.348 [3996] (StorageDelete) <7472> EV:L CADOContext::CreateConnection exit. source:Provider=SQLOLEDB;Server=bksrv-ev.biokolormakeup.it;Database=EVVSVaultStore_1;Trusted_Connection=yes hr=Success (0) 17190 14:33:34.349 [3996] (StorageDelete) <7472> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40] 17191 14:33:34.350 [3996] (StorageDelete) <7472> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine 17192 14:33:34.388 [3996] (StorageDelete) <7472> EV:L {CVaultStoreDB::ScanExpiryItemsStart:#1416} Expirable retention categories [<ExpirableRetCats><RetCat Identity="1" Period="6" Units="3" ExpiryBasis="0"/><RetCat Identity="2" Period="11" Units="3" ExpiryBasis="1"/></ExpirableRetCats>] 17193 14:33:34.388 [3996] (StorageDelete) <7472> EV:L {CStoreAccessor::SelectStore} (Entry) 17194 14:33:34.388 [3996] (StorageDelete) <7472> EV:M {CStoreAccessor::SelectStore}|EntryId:18E063F9DAC525A4A8FC962B62B7CA3081110000evsite 17195 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CStore::IsOpenVault} (Entry) 17196 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CStore::IsOpenVault}|Requested: 18E063F9DAC525A4A8FC962B62B7CA3081110000evsite Current: Open: False 17197 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CStore::IsOpenVault} (Exit) 17198 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CStore::OpenVault} (Entry) 17199 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CVaultCache::ReadEntry:#65} Successfully read Vault [18E063F9DAC525A4A8FC962B62B7CA3081110000evsite] information from cache. 17200 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CVaultStorePartitionCache::ReadEntry:#135} Successfully read partition info for Vault Store [11C8C450E2A710B40BB586525555802351210000evsite] 17201 14:33:34.389 [3996] (StorageDelete) <7472> EV:L {CStore::OpenDatabase} (Entry) 17202 14:33:34.389 [3996] (StorageDelete) <7472> EV:L SingletonRegistry: RS '0X1E6A2E8TransactionContext' 17203 14:33:34.389 [3996] (StorageDelete) <7472> EV:L SingletonRegistry: RS '0X1E6A2E81' 17204 14:33:34.389 [3996] (StorageDelete) <7472> EV:L SingletonRegistry: RS '0X1E6A2E8' 17205 14:33:34.389 [3996] (StorageDelete) <7472> EV:L CADOContext::CreateConnection entry 17206 14:33:34.389 [3996] (StorageDelete) <7472> EV:L CADOContext::CreateConnection exit. source:EVVSVaultStore_1 hr=Success (0) 17207 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CStore::OpenDatabase} (Exit) 17208 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CStore::OpenIndexerNotifier} (Entry) 17209 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CIndexerNotifier} (Entry) 17210 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CIndexerNotifier:#65} IndexWorkPendingCommitIntervalSeconds: 60. 17211 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CIndexerNotifier:#66} ItemChangesCountForIndexCommit: 500. 17212 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CIndexerNotifier::CIndexerNotifier} (Exit) 17213 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CStore::OpenIndexerNotifier} (Exit) 17214 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVault::CVault} (Entry) 17215 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetArchiveId} (Entry) 17216 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultCache::ReadEntry:#65} Successfully read Vault [18E063F9DAC525A4A8FC962B62B7CA3081110000evsite] information from cache. 17217 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetArchiveId} (Exit) Status: [Success] 17218 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetVaultType} (Entry) 17219 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultCache::ReadEntry:#65} Successfully read Vault [18E063F9DAC525A4A8FC962B62B7CA3081110000evsite] information from cache. 17220 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetVaultType} (Exit) Status: [Success] 17221 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetArchiveExtendedType} (Entry) 17222 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultCache::ReadEntry:#65} Successfully read Vault [18E063F9DAC525A4A8FC962B62B7CA3081110000evsite] information from cache. 17223 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetArchiveExtendedType} (Exit) Status: [Success] 17224 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetVaultName} (Entry) 17225 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetVaultParams} (Entry) 17226 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultCache::ReadEntry:#65} Successfully read Vault [18E063F9DAC525A4A8FC962B62B7CA3081110000evsite] information from cache. 17227 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetVaultParams} (Exit) Status: [Success] 17228 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVaultParameters::GetVaultName} (Exit) Status: [Success] 17229 14:33:34.390 [3996] (StorageDelete) <7472> EV:L {CVault::CVault:#210} Time-out for 'Delete Permitted' cache set to [10] secs. 17230 14:33:34.391 [3996] (StorageDelete) <7472> EV:L {CVault::CVault} (Exit) 17231 14:33:34.391 [3996] (StorageDelete) <7472> EV:L {CStore::OpenVault} (Exit) Status: [Success] 17232 14:33:34.391 [3996] (StorageDelete) <7472> EV:L {CStoreAccessor::SelectStore} (Exit) Status: [Success] 17233 14:33:34.403 [3996] (StorageDelete) <7472> EV:L {CVaultStoreDB::ScanExpiryItemsDoQuery:#1449} Records available [False], Query again [False] 17234 14:33:34.403 [3996] (StorageDelete) <7472> EV:M CVaultStoreDB::ScanExpiryItemsEnd
It simply tells me that there are not items eligible for deletion, but it isn't true!
Thank you.
Francesco Bianchessi B.
10-30-2017 12:08 PM
Hello Francesco,
I'm no expert in reading tracefiles unfortunately. I'm curious about the below entry:
17192 14:33:34.388 [3996] (StorageDelete) <7472> EV:L {CVaultStoreDB:Man FrustratedcanExpiryItemsStart:#1416}
Expirable retention categories
[<ExpirableRetCats><RetCat Identity="1" Period="6" Units="3" ExpiryBasis="0"/>
<RetCat Identity="2" Period="11" Units="3" ExpiryBasis="1"/></ExpirableRetCats>]
You have 2 retention categories? 1 for 6 years, 1 for 11 years? The question is, what is ExpiryBasis? 1 is 0, 1 = 1
Are other archives having items expire?
In general, check: Site settings, is expiry enabled, and is it scheduled? Retention Category: does it allow automatic deletion? Does it allow deletion? Archive: Does it allow deletions? Is the archive perhaps part of a Discovery Accelerator search which has a hold on the items?
I'm unfortunately not able to assist deeply, as I am not running mbx archiving at the moment.
10-31-2017 02:08 AM
Hello,
For the first question: 0 means expiry delete is "Archive date based", 1 means "Modified date based". Yes I have two retention categories. One is the default, the other is for accounting department. The one that currently must delete stuff is the default retention category. The other one will start deleting items in a few years.
Regarding the checks, It seems all ok.. You find atteched stamps of the various settings. I don't have Discovery Accelerator implemented.
I was wondering if ther is something wrong with the EV cache.. In the DTrace I see it recall many information from it.
Thank you,
Francesco Bianchessi B
10-31-2017 02:39 AM
Hello Francesco,
Can it be that the default retention policy has been changed to a lower value? If you have WORM storage, it might very well be that (although you changed the policy) the storage device itself does not allow deletions. That should however show in the eventlog I believe. You settings indeed do look correct.
What is your EV server cache setting? Is the location perhaps full? You might want to consider a reboot of the EV server, to free resources and retry.
10-31-2017 03:03 AM - edited 10-31-2017 03:04 AM
No no, no WORM storage. The volume on which there are cache and vault store has 13% of free space. Cache folder is 0 bytes size. Limit 20GB.
I restarted EV server yesterday night. I will restart EV again.
Thank you,
Francesco Bianchessi B.