Description

Here is a filtered extract from the DTrace showing the processing of an item by the EVIndexVolumesProcessor process.

1)    The index volume is added to the ‘work item’ queue:
12:59:34.246     [6048]    (EVIndexVolumesProcessor)    <2404>    EV-L    {IVPWEBSERVICEPROCESSING.EN_US} Request to synchronise Index volumes received: XML:

12:59:34.293     [6048]    (EVIndexVolumesProcessor)    <2404>    EV-M    {INDEXVOLUMESMANAGER.EN_US} Weight ==> The synchronisation requested for '1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702' of type 9 will be enqueued with a weight of Normal
12:59:34.309     [6048]    (EVIndexVolumesProcessor)    <2404>    EV-L    {IVPWEBSERVICEPROCESSING.EN_US} Request to synchronise Index volumes done  return XML:


The ‘ContentSourceID’ detailed above refers to the ArchiveID.

2)    The index volume is taken from the queue for processing and checked to ensure the index volume is able to be updated:
12:59:40.871     [6048]    (EVIndexVolumesProcessor)        EV-M    {INDEXVOLUMEOPERATIONS.EN_US} PrepareIndexVolumeForProcessing: CheckForRollOver: True, Ignore Failed Flag: False for 1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702.
12:59:40.949     [6048]    (EVIndexVolumesProcessor)        EV-L    {LOG.EN_US} The Archive type DV_DS_VT_MB_ARCHIVE (9) will be using Small collection template
12:59:40.981     [6048]    (EVIndexVolumesProcessor)        EV-L    {EVCONTENTSOURCEACCESSOR.EN_US} Index volume [1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702] is valid for processing. Failed False, Offline False, BeingDeleted False, ReadOnly False, BackupMode False, IndexItemsMode 0
12:59:40.981     [6048]    (EVIndexVolumesProcessor)        EV-L    {INDEXVOLUMEOPERATIONS.EN_US} Check the internal state for 1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702
12:59:45.012     [6048]    (EVIndexVolumesProcessor)        EV-L    {VELOCITYPROXY.EN_US} Collection [1AEF95A72294C8847B21C5E7AEDAFA048_69702] exists.
12:59:45.418     [6048]    (EVIndexVolumesProcessor)        EV-M    {VELOCITYINDEXINGENGINE.EN_US} Index volume [1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702] is ready for processing

3)    The ‘HighestIndexSeqNo’ is obtained for the index volume which details the last archived item that has been indexed:
12:59:45.762     [6048]    (EVIndexVolumesProcessor)        EV-L    {TRACEDBCOMMAND.EN_US} Executed usps_HighestIndexSeqNo in 6 ms after 0 retries. @ArchivePointID=1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow
12:59:45.762     [6048]    (EVIndexVolumesProcessor)        EV-M    {STATEINITIALVERIFICATION.EN_US} Sequence Number stored stored in the Content Source: 51 - in the state XML: 25
12:59:45.778     [6048]    (EVIndexVolumesProcessor)        EV-L    {CONTENTSOURCEINITIALISER.EN_US}  Resetting pending work for [125 cc]:
 Any Addition work higher than 26 will be reset
 Any Deletion work higher than 51 will be reset
 Any Updates work higher than 1 will be reset

4)    The unindexed items are then requested (from Storage) by the ‘Fetcher’ thread:
12:59:46.356     [6048]    (EVIndexVolumesProcessor)        EV-L    {FETCHER.EN_US} Fetcher Thread for 1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702 Starting Worker thread ...
12:59:46.371     [6048]    (EVIndexVolumesProcessor)        EV-H    {ITEMADDITIONSALLOCATOR.EN_US} Will start from action addition 25 to action addition 18446744073709551615

5)    Storage Crawler then retrieves the archived item(s), extracts the indexable data and passes the information back to indexing:
12:59:46.996     [2548]    (StorageCrawler)    <6088>    EV:L    CItemFetcher::RequestItem New fetch request NextISN:26 ItemISN:51 SSID:201107080126366~201107080842350000~Z~7165BE9BCACD6C7962E21E23BE44F941 (hr=Success  (0))
…
12:59:47.653     [2548]    (StorageCrawler)    <6088>    EV:L    CItemFetcher::WaitForItem NextISN:26 Timeout:30 (secs) SSID:201107080126366~201107080842350000~Z~7165BE9BCACD6C7962E21E23BE44F941 ItemISN:51 (hr=Success  (0))

6)    The index ‘fetcher’ thread keeps requesting and receiving items from Storage (Crawler) until there are no more items to fetch (or errors encountered)
12:59:47.621     [6048]    (EVIndexVolumesProcessor)        EV-L    {CLASSICEVINDEXABLEITEMTRAVERSER.EN_US} Loaded classic indexable item.  Size = 259510 bytes
12:59:47.637     [6048]    (EVIndexVolumesProcessor)        EV-M    {ITEMADDITIONSALLOCATOR.EN_US} There are some additions to do...
12:59:47.700     [6048]    (EVIndexVolumesProcessor)        EV-H    {FETCHER.EN_US} NO MORE ITEMS TO FETCH - Processed 1 items in all. WILL STOP NOW.

7)    ‘Indexer’ thread then packages the data and sends it to the indexing engine:
12:59:47.715     [6048]    (EVIndexVolumesProcessor)        EV-L    {EVADDITIONDATAREADER.EN_US} Traversing EV item. SavesetID=[201107080126366~201107080842350000~Z~7165BE9BCACD6C7962E21E23BE44F941], ItemSequenceNum=[51]
12:59:48.434     [6048]    (EVIndexVolumesProcessor)    <6116>    EV-M    {VELOCITYINDEX.EN_US} DoFlush is called by Indexer (1) Thread for 1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702
12:59:48.450     [6048]    (EVIndexVolumesProcessor)    <6116>    EV-L    {VELOCITYINDEX.EN_US} Enqueuing a batch of 1 actions to Velocity. IndexVolumeID=[1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702]
12:59:51.903     [6048]    (EVIndexVolumesProcessor)    <6116>    EV-L    {VELOCITYINDEX.EN_US} Batch has been enqueued successfully to offline collection......

8)    The indexing engine is then checked for confirmation of indexed items (on this index volume) and the item status is updated:
12:59:57.934     [6048]    (EVIndexVolumesProcessor)    <6116>    EV-L    {VELOCITYPROXY.EN_US} Enumerating Log Entries for 1AEF95A72294C8847B21C5E7AEDAFA048_69702 - Veritas.EnterpriseVault.Indexing.IndexingEngineService.VelocitySrvRef.SearchCollectionAuditLogRetrieve
12:59:58.028     [6048]    (EVIndexVolumesProcessor)    <6116>    EV-L    {VELOCITYINDEX.EN_US} [99ms] DoEnumerateAcknowledgements  - IndexVolumeID=1AEF95A72294C8847B21C5E7AEDAFA0481110000evshadow_69702
12:59:58.028     [6048]    (EVIndexVolumesProcessor)    <6116>    EV-M    {VELOCITYINDEX.EN_US} Process Acknowledgment Enumeration Response. Number of Entries:[1] Token:[0::0]
12:59:58.028     [6048]    (EVIndexVolumesProcessor)        EV-L    {VELOCITYINDEX.EN_US} Received 1 acknowledgements from velocity
12:59:58.044     [6048]    (EVIndexVolumesProcessor)        EV-L    {STATUSLIST.EN_US} All 1 item actions have been acknowledged
12:59:58.044     [6048]    (EVIndexVolumesProcessor)        EV-L    {STATUSCHECKER.EN_US} Received [1] acknowledgments - Processed 1
12:59:58.044     [6048]    (EVIndexVolumesProcessor)        EV-L    {STATUSCHECKER.EN_US} Purging acknowledgments...

9)    Finally the ‘HighestIndexSeqNo’ for the index volume is increased accordingly:
12:59:59.372     [6048]    (EVIndexVolumesProcessor)        EV-M    {STATUSLIST.EN_US} Returning ALL item actions: 1 items with Item SN:'51' - Action SN:'51' - Status:'Success' - DataReader:'' as the last Acknowledged Before First Pending
12:59:59.403     [6048]    (EVIndexVolumesProcessor)        EV-H    {AUDITOR.EN_US} Auditing [1] actions in content source - HighestActionSequenceNumberToCommit [51]
12:59:59.544     [6048]    (EVIndexVolumesProcessor)        EV-M    {ADDITIONSMETADATAUPDATER.EN_US} Updating metadata values: HISN[25 -> 51] IndexedItems[0 -> 1] FailedItems[0 -> 0]
 

IMPORTANT: Do not edit this content in Information Manager