Video Screencast Help
Protect Your POS Environment Against Retail Data Breaches. Learn More.

41022 Deleted items waiting to be deleted from indexes; EV 10.0.1

Created: 07 Mar 2013 • Updated: 03 Apr 2013 | 25 comments
This issue has been solved. See solution.

For several weeks now, we've been getting a 41022 alert in the status console, saying that, "There are 31394 items that have been deleted from the Vault Store 'EVMBXVS01' but have not yet been deleted from the indexes."

No stores are in backup mode, the database compatibility level is correct, the storage service is running, and there are no failed index volumes. A review of the event log returned no indexing errors or failures of any type. In fact, the only index events I see are the normal start/stop/summary events.

That item count, 31394, never changes. It's like something is stuck. I've got a case open with support, but so far they've come up with nothing.

Any ideas? Since there are no errors in the event logs, I'm not too concerned yet, but I'd like to know where this alert is coming from. Where does that item count come from? Is this the result of a database query, or something in MSMQ? The server is rebooted monthly, or more often if I'm troubleshooting an issue.

Thanks,
Mike

 

Operating Systems:

Comments 25 CommentsJump to latest comment

JesusWept3's picture

What happens if you synchronize the index? does it seem to move?
Also is it a journal mailbox thats behind? or a regular user mailbox?
are you pretty aggressive on your Storage Expiry?
do you have anti-virus excluded from the indexing directories?
Also are you doing regular SQL maintance, especially regarding SQL Index rebuilds?

Another thing, can you go to your vault store and do a query such as

SELECT COUNT(*) FROM JournalDelete WHERE IndexCommited = 0

just wondering if maybe the statistics are off and there is genuinely that amount to delete or not
And another thing, what kind of storage do you use? NTFS? iSCSI, NAS, SAN, Centera? NetApp? etc?

MikeAtGamestop's picture

The vault in the alert is the mailbox store, but how can I tell which index is affected?

What constitutes agressive storage expiry? Retention categories are 1, 3, and 7 years, and expiry runs once a day for four hours, if I recall correctly.

The index volumes are excluded from AV scanning.

I'm not certain about the SQL maintenance.

TonySterling's picture

Hi Mike,

Every vault store has a table called JournalDelete, it isn't referring to Exchange Journaling so you should runt the query, SELECT COUNT(*) FROM JournalDelete WHERE IndexCommited = 0, against the mailbox vault store and share the results.

Thanks,

JesusWept3's picture

OK so try this query attached
It will give you results as to the users, the number of items awaiting index deletion, archive ID, vault stores etc

 

AttachmentSize
Items Awaiting Journal Delete.txt 2.74 KB
MikeAtGamestop's picture

OK, that returns a list of 5 mailboxes. What is my next step?

 

BTW, I really appreciate the help.

Mike

 

 

 

JesusWept3's picture

Ok so first of all, are any of the indexes set to rebuilding failed or offline?

If they're rebuilding it would be natural for this accumulation to occur until the index has completed

But next steps would be to run a synchronize against the index

Ill post the steps in a few minutes

MikeAtGamestop's picture

No, the Index Failed, Index Rebuilding, and Index Offline values for all five are false.

I just checked those archives, and found that all five users no longer exist in AD - the Bill Usage To and Permissions contain unresolved SIDs.

I doubt that those are the only ones, but it's something they all have in common.

 

 

JesusWept3's picture

OK so the following steps should be performed for each index

1. Open the Vault Admin Console
2. Expand out Archives -> Exchange Mailbox (or whatever kind of archive they are)
3. Find the Archive and double click the archive to go the Properties
4. Go to the Index Volumes tab and click "Manage Indexes" button
5. Click "Synchronize" and then press Next and then Next again
6. In the task name put in "Synchronize <username>" and press Next
7. Press Create Task and then press Close
8. repeat stesp 3-7 for each archive its suggested
8. Then in the Vault Admin Console, expand out Enterprise Vault Servers
9. Go to the EV Server that was returned in the query (under Index Server)
10. Go to "Tasks"
11. Right click "Index Administration Task" and select "Run Now"
12. Press Yes that you wish to run the task and then OK
13. Then right click "Indexes" and select "Monitor Indexing Tasks"

From the monitor indexing tasks pane you can see all the tasks that are created and what its currently doing, if you click the task name, you will then see the archive name, how many items were added, deleted, where there were errors, and what the progress is

If you then click the archive name, you have an option to open the Report File, and it will give you a low level view of what the task did, and whether there were errors and what those errors were
 

MikeAtGamestop's picture

Well, although the synchronize task completes successfully for each of the five archives, the query still returns the same results, and re-running the Status checks still returns the 41022 alert. Here's a sample report from one of the synchronization tasks.

Synchronize index volume started at 07/03/2013 13:44:44

 Archive Name: <REMOVED>
 Archive Id: 12E36D9FE3859034FA0114D94F52D54151110000evserver1
 Index Volume Identity: 6054
 Index Volume Range: 2348-
 Root Path Id: 17348CEF265ECEE47AE7F58039AE831CD1810000evserver1
 Folder: 12E36D9FE3859034FA0114D94F52D5415_6054
 Root Path: I:\Indexes\index3
 Index Server: evserver1.domain.local
 Volume Type: 64-bit

07/03/2013 13:44:44 Checking index volume for failed state.
07/03/2013 13:44:44 The index volume is not marked as failed.

07/03/2013 13:44:45 Performing initial verification for the index volume.
07/03/2013 13:44:45 Completed initial verification for the index volume.

07/03/2013 13:44:45 Retrying failed items.
07/03/2013 13:44:45 Retry of failed items has completed.

07/03/2013 13:44:45 Retrying failed deletions.
07/03/2013 13:44:45 Retry of failed deletions has completed.

07/03/2013 13:44:45 Performing final verification for the index volume.
07/03/2013 13:44:45 The index volume appears to be empty or missing; queueing a full synchronization of the index volume.
07/03/2013 13:44:45 Full synchronization has been queued.

07/03/2013 13:44:45 Synchronize summary:
07/03/2013 13:44:45  Total items repaired: 0
07/03/2013 13:44:45  Total items failed repair: 0
07/03/2013 13:44:45  Total items deleted: 0
07/03/2013 13:44:45  Total items failed delete: 0
07/03/2013 13:44:45  Total items processed: 0
07/03/2013 13:44:45  Total failed items remaining after synchronization: 0
07/03/2013 13:44:45  Total failed deletions remaining after synchronization: 0

07/03/2013 13:44:45 The synchronize has completed successfully and reported no issues.

For more information, see the online index troubleshooting technical note at:

 http://www.symantec.com/docs/TECH160420

 

JesusWept3's picture

OK so lets do the following

1. Open up a SQL Management Studio and run the following query, change 'yourVaultStore' to the Database name of your vault store

SELECT TOP 100 A.ArchiveName, 
       JD.IndexSeqNo,
       JD.IndexCommitted
FROM   yourVaultstoreDB.dbo.JournalDelete JD,
       yourVaultStoreDB.dbo.ArchivePoint AP,
       EnterpriseVaultDirectory.dbo.Root R,
       EnterpriseVaultDirectory.dbo.Archive A
WHERE  JD.ArchivePointIdentity = AP.ArchivePointIdentity
  AND  AP.ArchivePointId = R.VaultEntryId
  AND  R.RootIdentity = A.RootIdentity
  AND  JD.IndexCommitted = 0

2. Open the Vault Admin Console, expand out Archivees -> Exchange Archives
3. Find the user returned in the query and go to the properties
4. Go to the permissions tab and then add the EVAdmin with Read rights to the archive and press OK
5. Then go to http://yourEVServer/EnterpriseVault/Search.asp?advanced
6. In the Vaults drop down, select the user who we gave ourselves permission to
7. In "Sequence Number" enter the indexSeqNo returned from the query above
8. Press Search

Do any items get returned?
Try that for a few items

What could have happened is that the index genuinely has been updated but for whatever reason the JournalDelete table was never updated

you could try rebuilding the index if the archives are small enough
I would NOT recommend just setting IndexCommitted to True as that is a shotgun effort at its worst and could cause serious headaches
For instance lets say the items are not removed from the index, you then run in to trouble when you do a search against them, you find the item
but when you try and open the item, it says that the item cannot be retrieved, and now you are left trying to troubleshoot how that was possible etc

Plus this could happen again and you can't be doing those update queries each and every time.

Really what needs to happen is a synchronization again with a dtrace of the indexing agents and tasks to see why its skipping those items

MikeAtGamestop's picture

Search of the user's archive for those sequence numbers comes up emtpy. I gave it the whole range of the 100 returned by the query, and it found nothing. I'll look into collecting a dtrace.

I've tried rebuilding a couple of these indexes, but they always fail. Here's the report from the most recent:

Rebuild archive started at 07/03/2013 14:32:10

 Archive Name: <REMOVED>
 Archive Id: 12BC515B0B743C244884DE2FA30B2010B1110000evserver1
 Rebuild Scope: Archive

07/03/2013 14:32:10 Preparing to remove the live index volume as it's empty. Setting current live index volume to read only.
07/03/2013 14:32:10 Setting current live index volume to read only completed.

07/03/2013 14:32:10 The rebuild subtask has failed.
Error Code: 57
Description:Unable to find index volume for the archive [12BC515B0B743C244884DE2FA30B2010B1110000evserver1] with a highest index sequence number of [2931] or below

For more information, see the online index troubleshooting technical note at:

 http://www.symantec.com/docs/TECH160420

07/03/2013 14:32:10 The rebuild subtask has failed.
Error Code: 57
Description:Unable to find index volume for the archive [12BC515B0B743C244884DE2FA30B2010B1110000evserver1] with a highest index sequence number of [2931] or below

For more information, see the online index troubleshooting technical note at:

 http://www.symantec.com/docs/TECH160420
07/03/2013 14:32:15 The rebuild has resumed its processing.

07/03/2013 14:32:15 Preparing to remove the live index volume as it's empty. Setting current live index volume to read only.
07/03/2013 14:32:15 Setting current live index volume to read only completed.

07/03/2013 14:32:15 The rebuild subtask has failed.
Error Code: 57
Description:Unable to find index volume for the archive [12BC515B0B743C244884DE2FA30B2010B1110000evserver1] with a highest index sequence number of [2931] or below

For more information, see the online index troubleshooting technical note at:

 http://www.symantec.com/docs/TECH160420

07/03/2013 14:32:15 The rebuild subtask has failed.
Error Code: 57
Description:Unable to find index volume for the archive [12BC515B0B743C244884DE2FA30B2010B1110000evserver1] with a highest index sequence number of [2931] or below

For more information, see the online index troubleshooting technical note at:

 http://www.symantec.com/docs/TECH160420
07/03/2013 14:32:20 The rebuild has resumed its processing.

07/03/2013 14:32:20 Preparing to remove the live index volume as it's empty. Setting current live index volume to read only.
07/03/2013 14:32:20 Setting current live index volume to read only completed.

07/03/2013 14:32:20 The rebuild subtask has failed.
Error Code: 57
Description:Unable to find index volume for the archive [12BC515B0B743C244884DE2FA30B2010B1110000evserver1] with a highest index sequence number of [2931] or below

For more information, see the online index troubleshooting technical note at:

 http://www.symantec.com/docs/TECH160420

JesusWept3's picture

huh so this is pretty weird!
So lets run this query

USE EnterpriseVaultDirectory
SELECT A.ArchiveName "Archive Name",
       R.VaultEntryId "Archive ID",
       CE.ComputerName "Index Server",
       (IRP.IndexRootPath + '\' + IV.FolderName) "Index Folder",
       IV.FirstItemSequenceNumber "First ISN",
       IV.HighestItemSequenceNumber "Highest ISN",
       IV.IndexedItems "No. Items Indexed",
       IV.WorkPending "Work Pending",
       IV.IndexVolumeType "Index Type"
FROM   Archive A,
       Root R,
       IndexVolume IV,
       IndexRootPathEntry IRP,
       IndexingServiceEntry ISE,
       ComputerEntry CE
WHERE  A.rootIdentity = R.RootIdentity
  AND  R.RootIdentity = IV.RootIdentity
  AND  IV.IndexrootPathEntryId = IRP.IndexRootPathEntryId
  AND  IRP.IndexServiceEntryId = ISE.ServiceEntryId
  AND  ISE.ComputerEntryId = CE.ComputerEntryId
  AND  R.VaultEntryId = '12BC515B0B743C244884DE2FA30B2010B1110000evserver1'

With the following query, what do you get as the results?
And if you go to that index server, and look in the path, does that path actually exist?

MikeAtGamestop's picture

Yes, the folder does exist.

Query result: "K:\Indexes\index7\12BC515B0B743C244884DE2FA30B2010B_4498"

File system: "K:\Indexes\index7\12BC515B0B743C244884DE2FA30B2010B_4498"

Contents include a state.dat file and "live" and "cache" folders.

 

JesusWept3's picture

can you post the rest of the results minus the archive name?

MikeAtGamestop's picture

I think I found something, but I'm not sure what it means or how to fix it.

When viewing the Details of any archive's index volumes, the Range field usually consists of a set of numbers starting with 1. If there's only one entry, it usually says "1 - Not Set", and if there are multiple entries, the first one starts with 1.

With the five that we're having problems with, the range of index volumes starts with a number higher than 1, and the dtrace indicates an error locating an index volume that starts with a number just below or lower. For example, if one index range starts at 2345, then the error say sit can't find an index starting with 2344 or lower. It would appear that the earlier indexes are missing, and EV can't resolve this problem. All five of the affected archives have index ranges that start at a number higher than 1.

 

JesusWept3's picture

Well really what this is is because you're doing Storage Expiry

So if i have say 5000 items, and i archive them
it has a range of 1-5000
then if i archive more, it becomes 1-6000
however if i run storage expiry and delete items so that theres no longer anything left, the index effectively gets reset

Then when i start archiving again and i archive 1000 items after my archive was effectively empty
i now have a range of 6001-7001, so its a bit of a red herring

1 to Not Set means thats no items have ever been archived or index for that particular user
 

MikeAtGamestop's picture

From the dtrace:

24664 14:48:42.503  [19752] (EVIndexVolumesProcessor) <Agent Thread for 1D84CA02442414837AE4736EF7B1640691013b00evserver1_1164C18A91F3B044981996D6369D527501013a00evserver1_12E36D9FE3859034FA0114D94F52D54151110000evserver1_0:13548> EV-H {EVRebuildSubTask} Subtask error:|Error Code:DV_DS_E_FLD_IDXSUBTASK_FAILED|Description:Unable to find index volume for the archive [12E36D9FE3859034FA0114D94F52D54151110000evserver1] with a highest index sequence number of [2347] or below
 

24665 14:48:42.503  [19752] (EVIndexVolumesProcessor) <Agent Thread for 1D84CA02442414837AE4736EF7B1640691013b00evserver1_1164C18A91F3B044981996D6369D527501013a00evserver1_12E36D9FE3859034FA0114D94F52D54151110000evserver1_0:13548> EV-L {IndexingSubTaskReport.LogMessage} 07/03/2013 14:48:42 The rebuild subtask has failed. |Error Code: 57|Description:Unable to find index volume for the archive [12E36D9FE3859034FA0114D94F52D54151110000evserver1] with a highest index sequence number of [2347] or below
 

That error code 57 is what shows up in the console after attempting to rebuild the index, and the index range for this archive starts at 2348.

JesusWept3's picture

OK this may be a bit obscure but....
Can you delete C:\Program Files (x86)\EnterpriseVault\MRIndexServer.dat
Restart the Enterprise Vault Indexing Service and try the rebuild of the index again?

Otherwise what i would suggest is tell support about this thread and have them advance it to ADV support or Backline support, though be aware they may suggest doing an upgrade to EV10 SP3, not that I can see this has been a known issue or fixed in future releases, but lets say it is a bug and you wanted a hotfix and not a work around, they could only give it for EV10 SP3 and not below

JesusWept3's picture

Actually thinking about this more
Did you at ever point restore that database per chance?
I'm wondering that maybe items were purged for the user and the directory database got rid of the older indexes and then a vault store was restored which put back items records that were previously deleted but because the index volume was removed from directory, it can't find the volume anymore to reindex those items

JesusWept3's picture

To determine this, run this query first , and see if the database was ever restored at any point, this may give a false positive though if you restored the database if you migrated from one SQL Server to another....

SELECT [rs].[destination_database_name], 
[rs].[restore_date], 
[bs].[backup_start_date], 
[bs].[backup_finish_date], 
[bs].[database_name] as [source_database_name], 
[bmf].[physical_device_name] as [backup_file_used_for_restore]
FROM msdb..restorehistory rs
INNER JOIN msdb..backupset bs
ON [rs].[backup_set_id] = [bs].[backup_set_id]
INNER JOIN msdb..backupmediafamily bmf 
ON [bs].[media_set_id] = [bmf].[media_set_id] 
ORDER BY [rs].[restore_date] DESC

And then run this query to see the date range of items that were deleted
 

SELECT DISTINCT(A.ArchiveName) "Archive Name",
       MIN(JD.DeletionDate) "First Deletion Date",
       MAX(JD.DeletionDate) "Last Deletion Date"
FROM   yourVaultStore.dbo.JournalDelete JD,
       yourVaultStore.dbo.ArchivePoint AP,
       EnterpriseVaultDirectory.dbo.Root R,
       EnterpriseVaultdirectory.dbo.Archive A
WHERE  JD.ArchivePointIdentity = AP.ArchivePointIdentity
  AND  AP.ArchivePointId = R.VaultEntryId
  AND  R.RootIdentity = A.RootIdentity
  AND  JD.IndexCommitted = 0
GROUP BY A.ArchiveName
ORDER BY A.ArchiveName
MikeAtGamestop's picture

We've never done any SQL restore that involved the EV databases that I'm aware of, but we have a separate team that handles the SQL servers.

The first query returned several records for the DAConfiguration database, but nothing for the mailbox store.

The second query returned:

Archive Name  First Deletion Date  Last Deletion Date
User1 2012-12-07 02:22:55.037 2012-12-07 02:24:31.090
User2 2012-12-10 04:50:51.883 2012-12-10 04:51:12.377
User3 2012-10-25 04:07:51.170 2012-10-25 04:15:34.860
User4 2012-12-15 04:59:43.553 2012-12-15 05:05:36.397
User5 2013-02-10 04:33:04.797 2013-02-10 04:39:28.890

I do have a case open with support to work on several alerts in the console, but we haven't focused on this particular one so far. I'll refer them to this thread when I get back from vacation at the end of the month. smiley

 

Thank you very much for your help and advice. I appreciate it very much.

Mike

 

MikeAtGamestop's picture

Interesting. I see that Symantec just posted a new Technote, which sounds very similar to this problem.

http://www.symantec.com/docs/TECH203681

Same error code and message that I saw in the dtrace.

 

JesusWept3's picture

and it was created today!!!!
good job :)

so best thing to do, tell the symc person about that technote, quote the etrack, ask them to put you on the etrack as well, they will give you the work around and then you can consider it closed.

 

SOLUTION