Video Screencast Help
Archiving and eDiscovery Community Blog

Odd Journalling Problem

Created: 02 Jul 2012 • Updated: 29 May 2014 • 6 comments
Rob.Wilcox's picture
0 0 Votes
Login to vote

 

A couple of weeks ago I was helping a colleague and friend with an odd journalling issue.  He had a journal mailbox which was being written to by Exchange, but it wasn't being touched by Enterprise Vault.  After much poking around we finally had a look at the DTRACE.

 

Here is the output:

 

4538 20:30:36.243  [5444] (JournalTask) <1856> EV:L {CStorageArchive::GetStorageInfoData:#1225} Vault [195A83B87F5E0B740AB96BBDB2B3B03081110000vaultserver1] status: [DV_DS_AS_AVAILABLE (1)]

4539 20:30:36.243  [5444] (JournalTask) <1856> EV:L {CStorageArchive::GetStorageInfoData} (Exit) Status: [Success]

4540 20:30:36.243  [5444] (JournalTask) <1856> EV:L {CStorageArchive::GetVaultStatusEx:#793} Checked Storage information, and the throttle status for archive [195A83B87F5E0B740AB96BBDB2B3B03081110000vaultserver1] is still [DV_DS_AS_AVAILABLE (1)].

4541 20:30:36.243  [5444] (JournalTask) <1856> EV:L {CStorageArchive::GetVaultStatusEx} (Exit) Status: [Success]

4542 20:30:36.243  [5444] (JournalTask) <1856> EV:H {CArchivingAgent::PF_CheckVaultAvailability:#13966} there is something wrong with the current vault status: [0xC0041B85]

4543 20:30:36.243  [5444] (JournalTask) <1856> EV:L :CArchivingAgent::ProcessFolders() |Exiting routine |

4544 20:30:36.243  [5444] (JournalTask) <1856> EV:M ExMbxArcFolderHelper - Starting EMAF Sync

4545 20:30:36.243  [5444] (JournalTask) <1856> EV:M Updating ExMbxArcFolder records

4547 20:30:36.243  [5444] (JournalTask) <1856> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]

4548 20:30:36.243  [5444] (JournalTask) <1856> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine

4549 20:30:36.274  [5444] (JournalTask) <1856> EV:M Performing post-processing on ExMbxArcFolder Records

4551 20:30:36.274  [5444] (JournalTask) <1856> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]

4552 20:30:36.274  [5444] (JournalTask) <1856> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine

4553 20:30:36.274  [5444] (JournalTask) <1856> EV:M ExMbxArcFolderHelper - Finished EMAF Sync

4554 20:30:36.274  [5444] (JournalTask) <1856> EV:L :CArchivingAgent::ProcessUser() |Return the MAPI session to the session pool |

4555 20:30:36.274  [5444] (JournalTask) <1856> EV:H :CArchivingAgent::ProcessUser() |Exiting routine |

4556 20:30:36.274  [5444] (JournalTask) <1856> EV:H {CArchivingAgent::ProcessUserEx:#19300} It took [0.456444] seconds to process mailbox [/O=FIRST ORGANIZATION/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=JOURNALINGC81].

4557 20:30:36.274  [5444] (JournalTask) <1856> EV:M {CMailboxUsage::RemoveUserFromList:#113} Removed [/O=FIRST ORGANIZATION/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=JOURNALINGC81] from list of mailboxes being processed. List now contains [0] mailboxes.

4558 20:30:36.290  [5444] (JournalTask) <1856> EV:L {AgentMessageDispenser::ActivateObject:#3502} Acquiring mutex for updating message count...

4559 20:30:36.290  [5444] (JournalTask) <1856> EV:L {AgentMessageDispenser::ActivateObject:#3504} Mutex acquired.

4560 20:30:36.290  [5444] (JournalTask) <1856> EV:L {AgentMessageDispenser::ActivateObject:#3512} Using Message count value [3].

4561 20:30:36.290  [5444] (JournalTask) <1856> EV:M {AgentMessageDispenser::ActivateObject:#3808} An error that we don't specifically recognise has occurred, [0xc0041b85], so we'll just increment this messages retry count.

4562 20:30:36.290  [5444] (JournalTask) <1856> EV:L {AgentMessageDispenser::ActivateObject} (Exit) Status: [The dispenser was asked to repost the message to be retried later      (0xc00408e2)]

4563 20:30:36.290  [5444] (JournalTask) <1856> EV:M {AgentMessageDispenser::ProcessNextMessage:#1250} It took [0.467571] seconds to process the [MsgID_ArchiveMailboxEx2 (77)] MSMQ message body (ActivateObject). Processing the message [failed].

4564 20:30:36.290  [5444] (JournalTask) <1856> EV:M {AgentMessageDispenser::ProcessNextMessage:#1266} Processing MSMQ message body (ActivateObject) failed with [0xc00408e2]. The retry count will be incremented, and the message reposted to the end of the queue.

4565 20:30:36.290  [5444] (JournalTask) <1856> EV:H {AgentMessageDispenser::ProcessNextMessage:#1286} The retry count [4] for this MSMQ message has exceeded the maximum retry limit. This MSMQ message will be discarded.

4566 20:30:36.290  [5444] (JournalTask) <1856> EV:L {AgentMessageDispenser::ProcessNextMessage:#1732} Committing MSMQ transaction.

So it was failing, but nothing major appeared to be being output to the log.  

I studied this a bit more .. and wondered what it meant :

4542 20:30:36.243  [5444] (JournalTask) <1856> EV:H {CArchivingAgent::PF_CheckVaultAvailability:#13966} there is something wrong with the current vault status: [0xC0041B85]

Turns out, when we looked, the Vault Store where the journal archive resided was in BACKUP MODE.  D'oh.

Comments 6 CommentsJump to latest comment

cybergirl1987's picture

Hello.. Sorry for commenting on such an old post. I have a customer here whose journal task dtrace log file shows similar output. VS is not in backup mode. Journal mailbox shows 90,000 items pending. We tried changing the remove safety copies setting to after backup(journaling). Please advise.

0
Login to vote
Rob.Wilcox's picture

Post some/all of the trace, and I can take a look at it.

Post the output of :

 

select * from vaultstoreentry

0
Login to vote
cybergirl1987's picture

This is a portion of the trace.

12723 10:14:37.679 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ActivateObject:#3506} Acquiring mutex for updating message count...
12724 10:14:37.679 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ActivateObject:#3508} Mutex acquired.
12725 10:14:37.679 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ActivateObject:#3516} Using Message count value [13].
12726 10:14:37.679 [3092] (JournalTask) <8864> EV:M {AgentMessageDispenser::ActivateObject:#3816} An error that we don't specifically recognise has occurred, [0xc0041b85], so we'll just increment this messages retry count.
12727 10:14:37.679 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ActivateObject} (Exit) Status: [The dispenser was asked to repost the message to be retried later (0xc00408e2)]
12728 10:14:37.679 [3092] (JournalTask) <8864> EV:M {AgentMessageDispenser::ProcessNextMessage:#1251} It took [0.702978] seconds to process the [MsgID_ArchiveMailboxEx2 (77)] MSMQ message body (ActivateObject). Processing the message [failed].
12729 10:14:37.679 [3092] (JournalTask) <8864> EV:M {AgentMessageDispenser::ProcessNextMessage:#1267} Processing MSMQ message body (ActivateObject) failed with [0xc00408e2]. The retry count will be incremented, and the message reposted to the end of the queue.
12730 10:14:37.679 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12731 10:14:37.711 [3092] (JournalTask) <8152> EV:H {AgentMessageDispenser::ProcessNextMessage:#1232} Retrieved a [MsgID_ArchiveMailboxEx2 (77)] MSMQ message and it's retry count [2] is within retry limits.
12732 10:14:37.711 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ActivateObject} (Entry)
12733 10:14:37.711 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ActivateObject:#1802} Actioning [MsgID_ArchiveMailboxEx2 (77)] MSMQ message by calling the appropriate server-side object.
12734 10:14:37.711 [3092] (JournalTask) <8152> EV:M {AgentMessageDispenser::IsMbxStoreMappedToThisServer:#4910} Exchange mbx store [CN=hsd-maildb1,CN=Databases,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=global,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=global,DC=hftrust,DC=com] is mapped to this server: [True]
12735 10:14:37.711 [3092] (JournalTask) <8152> EV:H {AgentMessageDispenser::ActivateObject:#1946} Processing a user mbx. Legacy mbx DN: [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F], AD mbx DN: [CN=vault journal,OU=Hansard Server Service Accounts,DC=hsd,DC=hftrust,DC=com], legacy msg store DN: [MAIL1], AD msg store DN: [CN=hsd-maildb1,CN=Databases,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=global,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=global,DC=hftrust,DC=com].
12736 10:14:37.711 [3092] (JournalTask) <8152> EV:M {AgentMessageDispenser::ActivateObject:#1953} Priority: [True], reporting mode: [False], run now mode: [RN_ARCHIVING (0x1)], continuous mode: [True], msgs to archive per pass: [0], processing disabled and suspended mbxs: [False], rollover log file: [False].
12737 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CArchivingAgent::ProcessUserEx:#17804} Journal target list count is [1].
12738 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CExchangePolicyCache::GetDefaultPolicy:#272} Default policy is [135247C229D335344A115FDCFE4AFA3451012700evserver (Default Exchange Journaling Policy)]
12739 10:14:37.711 [3092] (JournalTask) <8152> EV:H {CArchivingAgent::ProcessUserEx:#17836} Processing mbx [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F], mode [RN_ARCHIVING (0x1)], report mode [False].
12740 10:14:37.711 [3092] (JournalTask) <8152> EV:H {CMailboxUsage::SetMailboxInUse:#196} Added [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F] to list of mailboxes to be processed. List now contains [1] mailboxes.
12741 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CArchivingAgent::Initialise} (Entry)
12742 10:14:37.711 [3092] (JournalTask) <8152> EV:L {MigratedDominoItems::Reset} (Entry)
12743 10:14:37.711 [3092] (JournalTask) <8152> EV:L {MigratedDominoItems::Reset} (Exit)
12744 10:14:37.711 [3092] (JournalTask) <2808> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12745 10:14:37.711 [3092] (JournalTask) <5488> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12746 10:14:37.711 [3092] (JournalTask) <9524> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12747 10:14:37.711 [3092] (JournalTask) <3560> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12748 10:14:37.711 [3092] (JournalTask) <4248> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12749 10:14:37.711 [3092] (JournalTask) <10368> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12750 10:14:37.711 [3092] (JournalTask) <6472> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12751 10:14:37.711 [3092] (JournalTask) <8152> EV:L CPrioritizedItemTable::InitialiseTable(Age) - Setting up the table. Size: [7000]
12752 10:14:37.711 [3092] (JournalTask) <8152> EV:L CPrioritizedItemTable::InitialiseTable(Quota) - Setting up the table. Size: [7000]
12753 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CArchivingAgent::Initialise} (Exit) Status: [Success]
12754 10:14:37.711 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::ProcessUser() |Getting a MAPI session from the session pool |
12755 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CMAPISession::GetMapiSessionFromPoolEx} (Entry) Additional MAPILogonEx flags [0x0]
12756 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CMAPISession::GetMapiSessionFromPoolEx} (Exit) Status: [Success]
12757 10:14:37.711 [3092] (JournalTask) <8152> EV:L {CExchangePolicyCache::GetPolicy:#245} Returning policy: [135247C229D335344A115FDCFE4AFA3451012700evserver (Default Exchange Journaling Policy)]
12758 10:14:37.711 [3092] (JournalTask) <8152> EV:H {CArchivingAgent::SetPolicy:#22358} [CN=vault journal,OU=Hansard Server Service Accounts,DC=hsd,DC=hftrust,DC=com] is using policy [Default Exchange Journaling Policy].
12759 10:14:37.711 [3092] (JournalTask) <8152> EV:M (null) - JournalDelay key not found using default period
12760 10:14:37.711 [3092] (JournalTask) <8152> EV:M {CArchivingAgent::ProcessUserEx:#17960} Journal Advanced Policy Setting ClearTextPrimary [True]
12761 10:14:37.711 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::ProcessUser() |Creating the Entry ID of user mailbox to be processed |
12762 10:14:37.711 [3092] (JournalTask) <8152> EV:M :CArchivingAgent::ProcessUser() |Open users message store |
12763 10:14:37.711 [3092] (JournalTask) <1092> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12764 10:14:37.711 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12765 10:14:37.789 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::ProcessUser() |Getting the entry ID of the mailbox wastebasket or deleted items folder |
12766 10:14:37.789 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetSpecialFolders:#2107} Getting special folder Ids (Wastebasket, Outbox, Sent Items &c.), attempt [1] of [4]
12767 10:14:37.820 [3092] (JournalTask) <8152> EV:M :CArchivingAgent::ProcessUser() |Getting the users mailbox folder and state. |
12768 10:14:37.929 [3092] (JournalTask) <8152> EV:M {CMailboxHelper::GetMailboxState:#443} Mailbox is [Enabled]
12769 10:14:37.929 [3092] (JournalTask) <8152> EV:M {CMailboxHelper::GetMailboxState:#467} The mailbox is a [Journal] mailbox.
12770 10:14:37.929 [3092] (JournalTask) <8152> EV:M {CArchivingAgent::ProcessUserEx:#18244} Checking Mailbox Site [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F]. HR[0x0]
12771 10:14:37.929 [3092] (JournalTask) <8152> EV:M :CArchivingAgent::ProcessUser_EnableHandling() - Entering routine
12772 10:14:37.929 [3092] (JournalTask) <8152> EV:M :CArchivingAgent::ProcessUser_EnableHandling() - Exiting routine successfully
12773 10:14:38.054 [3092] (JournalTask) <8152> EV:L {CFilterHelper::StampDefaults:#1704} Setting EV properties on msg.
12774 10:14:38.054 [3092] (JournalTask) <8152> EV:L {CFilterHelper::StampDefaults:#1707} Saving changes to MAPI msg.
12775 10:14:38.117 [3092] (JournalTask) <8152> EV:M :CArchivingAgent::ProcessUser() |Reading users quota limit and current usage |
12776 10:14:38.133 [3092] (JournalTask) <8152> EV:H A storage limit has been found on mailbox CN=vault journal,OU=Hansard Server Service Accounts,DC=hsd,DC=hftrust,DC=com| Quota Type: QUOTA_NONE| Quota Limit (K): 218319160| Quota Used (K): 8514642| (Note: This is the information store default for all mailboxes) |
12777 10:14:38.133 [3092] (JournalTask) <8152> EV:H :CArchivingAgent::ProcessUser() |We are the Journal agent. Marking the this mailbox as the Journal mailbox |
12779 10:14:38.211 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
12780 10:14:38.211 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
12781 10:14:38.226 [3092] (JournalTask) <8152> EV:H {CArchivingAgent::ProcessUserEx:#18662} Mbx [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F] is enabled and ready for processing.
12782 10:14:38.226 [3092] (JournalTask) <8152> EV:L MAPICommon::GetFixed_PR_FOLDER_PATHNAME() - Reading PR_FOLDER_PATHNAME
12783 10:14:38.226 [3092] (JournalTask) <8152> EV:L MAPICommon::GetFixed_PR_FOLDER_PATHNAME() - The source folder is the root of the information store, returning an empty string
12784 10:14:38.226 [3092] (JournalTask) <8152> EV:L MAPICommon::GetFixed_PR_FOLDER_PATHNAME() - Setting output parameter [ ]
12785 10:14:38.226 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetFolderSettings:#471} Getting folder filter/policy for [ ]
12786 10:14:38.258 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy} (Entry)
12789 10:14:38.273 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy:#241} Filter type: [Using users default policy]
12790 10:14:38.273 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy:#262} Default policy locked: [False], default strategy locked: [True], filter props set by config tool: [False], filter props set because the Vault for this folder deleted: [False].
12791 10:14:38.273 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy} (Exit) Status: [<0x40380>]
12792 10:14:38.273 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetFolderSettings:#724} The archiveVEID has changed from the previous folder [Top of Information Store/(null)]
12794 10:14:38.273 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
12795 10:14:38.273 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
12796 10:14:38.289 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetFolderSettings:#1031} Folder [Top of Information Store] is non-structured archive. Nothing to do
12797 10:14:38.289 [3092] (JournalTask) <8152> EV:M {CArchivingAgent::ProcessUserEx:#18726} Mailbox Folder Policy : Using users default policy
12798 10:14:38.289 [3092] (JournalTask) <8152> EV:M :CArchivingAgent::ProcessUser() |Processing all the sub folders of the current folder |
12799 10:14:38.289 [3092] (JournalTask) <8152> EV:M IsCDOEXMInstalled returning FALSE
12800 10:14:38.289 [3092] (JournalTask) <8152> EV:M Resetting ExMbxArcFolder Records for a synchronization run
12802 10:14:38.289 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
12803 10:14:38.289 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
12804 10:14:38.304 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::ProcessFolders() |Entering routine |
12805 10:14:38.320 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::PF_SetFilterAndRentention() |Entering routine |
12806 10:14:38.320 [3092] (JournalTask) <8152> EV:L MAPICommon::GetFixed_PR_FOLDER_PATHNAME() - Reading PR_FOLDER_PATHNAME
12807 10:14:38.320 [3092] (JournalTask) <8152> EV:L MAPICommon::GetFixed_PR_FOLDER_PATHNAME() - The source folder is the root of the information store, returning an empty string
12808 10:14:38.320 [3092] (JournalTask) <8152> EV:L MAPICommon::GetFixed_PR_FOLDER_PATHNAME() - Setting output parameter [ ]
12809 10:14:38.320 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetFolderSettings:#471} Getting folder filter/policy for [ ]
12810 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy} (Entry)
12811 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy:#241} Filter type: [Using users default policy]
12812 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy:#262} Default policy locked: [False], default strategy locked: [True], filter props set by config tool: [False], filter props set because the Vault for this folder deleted: [False].
12813 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CFilterHelper::GetExchangeFolderPolicy} (Exit) Status: [<0x40380>]
12814 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetFolderSettings:#800} Current folder [Top of Information Store] is using parent folder's archiveVEID
12815 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CFolderHelper::GetFolderSettings:#1031} Folder [Top of Information Store] is non-structured archive. Nothing to do
12816 10:14:38.367 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::PF_SetFilterAndRetention() |Using the filter applied to the current folder Top of Information Store |
12817 10:14:38.367 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::PF_SetFilterAndRetention() |The VaultId value applied to the folder Top of Information Store is 13D65209E3E5EE54AAA5E234EBB8F11A91110000evserver |
12818 10:14:38.367 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::PF_SetFilterAndRetention() |The Retention Category value applied to the folder Top of Information Store is 1E1863FE97640A04A9A604D36261B92171b10000evserver |
12819 10:14:38.367 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::PF_SetFilterAndRentention() |Exiting routine |
12820 10:14:38.367 [3092] (JournalTask) <8152> EV:M EFP - Folder Policy Settings for [Top of Information Store]| Filter Type = Using users default policy| Archive Settings Locked = FALSE| Override Locks = FALSE| Delete Original = TRUE [LOCKED]| Create Shortcut = FALSE [LOCKED]| Archive unread items = TRUE [LOCKED]| Archiving based on : Age [LOCKED]| Age Based Period 0 Days| Not using Size Priority Settings
12821 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CRetentionCategoryCache::ReLoad} (Entry)
12822 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CRetentionCategoryCache::ReLoad:#286} Reload not performed as it's less than [1] mins since the data was refreshed. The cached data is not stale yet.
12823 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CRetentionCategoryCache::ReLoad} (Exit) Status: [Success]
12824 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CRetentionCategoryCache::GetRetentionCategoryData} (Entry) Retention category [1E1863FE97640A04A9A604D36261B92171b10000evserver]
12825 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CRetentionCategoryCache::GetRetentionCategoryData} (Exit) Status: [Success]
12826 10:14:38.367 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::PF_CheckVaultAvailability() |Entering routine. |
12827 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusEx} (Entry)
12828 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusData} (Entry)
12829 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusData}|Vault ID: 13D65209E3E5EE54AAA5E234EBB8F11A91110000evserver|Status: 1|Limit Status: 0|Storage Svc: 1B52A834991EDF649B9D1D63FB19089441e10000evserver|Rollover Vault :|Vault Store Status: 2
12830 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusData} (Exit) Status: [Success]
12831 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultThrottleStatus} (Entry)
12832 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultThrottleStatus:#1146} Storage Service [1B52A834991EDF649B9D1D63FB19089441e10000evserver] throttle status: [DV_DS_AS_AVAILABLE (1)].
12833 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultThrottleStatus} (Exit) Status: [Success]
12834 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusEx:#759} The throttle status for archive [13D65209E3E5EE54AAA5E234EBB8F11A91110000evserver] is unchanged: [DV_DS_AS_AVAILABLE (1)].
12835 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetStorageInfoData} (Entry)
12836 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetStorageInfoData:#1225} Vault [13D65209E3E5EE54AAA5E234EBB8F11A91110000evserver] status: [DV_DS_AS_AVAILABLE (1)]
12837 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetStorageInfoData} (Exit) Status: [Success]
12838 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusEx:#793} Checked Storage information, and the throttle status for archive [13D65209E3E5EE54AAA5E234EBB8F11A91110000evserver] is still [DV_DS_AS_AVAILABLE (1)].
12839 10:14:38.367 [3092] (JournalTask) <8152> EV:L {CStorageArchive::GetVaultStatusEx} (Exit) Status: [Success]
12840 10:14:38.367 [3092] (JournalTask) <8152> EV:H {CArchivingAgent::PF_CheckVaultAvailability:#13616} there is something wrong with the current vault status: [0xC0041B85]
12841 10:14:38.367 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::ProcessFolders() |Exiting routine |
12842 10:14:38.367 [3092] (JournalTask) <8152> EV:M ExMbxArcFolderHelper - Starting EMAF Sync
12843 10:14:38.367 [3092] (JournalTask) <8152> EV:M Updating ExMbxArcFolder records
12845 10:14:38.367 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
12846 10:14:38.367 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
12849 10:14:38.383 [3092] (JournalTask) <8152> EV:M Performing post-processing on ExMbxArcFolder Records
12851 10:14:38.383 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
12852 10:14:38.383 [3092] (JournalTask) <8152> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
12853 10:14:38.398 [3092] (JournalTask) <8152> EV:M ExMbxArcFolderHelper - Finished EMAF Sync
12854 10:14:38.398 [3092] (JournalTask) <8152> EV:L :CArchivingAgent::ProcessUser() |Return the MAPI session to the session pool |
12855 10:14:38.398 [3092] (JournalTask) <8152> EV:H :CArchivingAgent::ProcessUser() |Exiting routine |
12856 10:14:38.398 [3092] (JournalTask) <8152> EV:H {CArchivingAgent::ProcessUserEx:#19019} It took [0.689797] seconds to process mailbox [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F].
12857 10:14:38.398 [3092] (JournalTask) <8152> EV:M {CMailboxUsage::RemoveUserFromList:#113} Removed [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F] from list of mailboxes being processed. List now contains [0] mailboxes.
12858 10:14:38.398 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ActivateObject:#3506} Acquiring mutex for updating message count...
12859 10:14:38.398 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ActivateObject:#3508} Mutex acquired.
12860 10:14:38.398 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ActivateObject:#3516} Using Message count value [14].
12861 10:14:38.398 [3092] (JournalTask) <8152> EV:M {AgentMessageDispenser::ActivateObject:#3816} An error that we don't specifically recognise has occurred, [0xc0041b85], so we'll just increment this messages retry count.
12862 10:14:38.398 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ActivateObject} (Exit) Status: [The dispenser was asked to repost the message to be retried later (0xc00408e2)]
12863 10:14:38.398 [3092] (JournalTask) <8152> EV:M {AgentMessageDispenser::ProcessNextMessage:#1251} It took [0.698389] seconds to process the [MsgID_ArchiveMailboxEx2 (77)] MSMQ message body (ActivateObject). Processing the message [failed].
12864 10:14:38.398 [3092] (JournalTask) <8152> EV:M {AgentMessageDispenser::ProcessNextMessage:#1267} Processing MSMQ message body (ActivateObject) failed with [0xc00408e2]. The retry count will be incremented, and the message reposted to the end of the queue.
12865 10:14:38.398 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12866 10:14:38.429 [3092] (JournalTask) <5488> EV:H {AgentMessageDispenser::ProcessNextMessage:#1232} Retrieved a [MsgID_ArchiveMailboxEx2 (77)] MSMQ message and it's retry count [3] is within retry limits.
12867 10:14:38.429 [3092] (JournalTask) <5488> EV:L {AgentMessageDispenser::ActivateObject} (Entry)
12868 10:14:38.429 [3092] (JournalTask) <5488> EV:L {AgentMessageDispenser::ActivateObject:#1802} Actioning [MsgID_ArchiveMailboxEx2 (77)] MSMQ message by calling the appropriate server-side object.
12869 10:14:38.429 [3092] (JournalTask) <5488> EV:M {AgentMessageDispenser::IsMbxStoreMappedToThisServer:#4910} Exchange mbx store [CN=hsd-maildb1,CN=Databases,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=global,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=global,DC=hftrust,DC=com] is mapped to this server: [True]
12870 10:14:38.429 [3092] (JournalTask) <5488> EV:H {AgentMessageDispenser::ActivateObject:#1946} Processing a user mbx. Legacy mbx DN: [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F], AD mbx DN: [CN=vault journal,OU=Hansard Server Service Accounts,DC=hsd,DC=hftrust,DC=com], legacy msg store DN: [MAIL1], AD msg store DN: [CN=hsd-maildb1,CN=Databases,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=global,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=global,DC=hftrust,DC=com].
12871 10:14:38.429 [3092] (JournalTask) <5488> EV:M {AgentMessageDispenser::ActivateObject:#1953} Priority: [True], reporting mode: [False], run now mode: [RN_ARCHIVING (0x1)], continuous mode: [True], msgs to archive per pass: [0], processing disabled and suspended mbxs: [False], rollover log file: [False].
12872 10:14:38.429 [3092] (JournalTask) <5488> EV:L {CArchivingAgent::ProcessUserEx:#17804} Journal target list count is [1].
12873 10:14:38.429 [3092] (JournalTask) <5488> EV:L {CExchangePolicyCache::GetDefaultPolicy:#272} Default policy is [135247C229D335344A115FDCFE4AFA3451012700evserver (Default Exchange Journaling Policy)]
12874 10:14:38.429 [3092] (JournalTask) <5488> EV:L {CPolicyTargetGroupCache::GetPolicyTargetGroupCache:#125} Returning existing cache.
12875 10:14:38.429 [3092] (JournalTask) <5488> EV:H {CArchivingAgent::ProcessUserEx:#17836} Processing mbx [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F], mode [RN_ARCHIVING (0x1)], report mode [False].
12876 10:14:38.429 [3092] (JournalTask) <5488> EV:H {CMailboxUsage::SetMailboxInUse:#196} Added [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F] to list of mailboxes to be processed. List now contains [1] mailboxes.
12877 10:14:38.429 [3092] (JournalTask) <5488> EV:L {CArchivingAgent::Initialise} (Entry)
12878 10:14:38.429 [3092] (JournalTask) <5488> EV:L {MigratedDominoItems::Reset} (Entry)
12879 10:14:38.429 [3092] (JournalTask) <5488> EV:L {MigratedDominoItems::Reset} (Exit)
12880 10:14:38.429 [3092] (JournalTask) <10368> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12881 10:14:38.429 [3092] (JournalTask) <9524> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12882 10:14:38.429 [3092] (JournalTask) <5488> EV:L CPrioritizedItemTable::InitialiseTable(Age) - Setting up the table. Size: [7000]
12883 10:14:38.429 [3092] (JournalTask) <5488> EV:L CPrioritizedItemTable::DeinitialiseTable - Clearing down the table
12884 10:14:38.429 [3092] (JournalTask) <5488> EV:L CPrioritizedItemTable::InitialiseTable(Quota) - Setting up the table. Size: [7000]
12885 10:14:38.429 [3092] (JournalTask) <5488> EV:L CPrioritizedItemTable::DeinitialiseTable - Clearing down the table
12886 10:14:38.445 [3092] (JournalTask) <5488> EV:L {CArchivingAgent::Initialise} (Exit) Status: [Success]
12887 10:14:38.445 [3092] (JournalTask) <5488> EV:L :CArchivingAgent::ProcessUser() |Getting a MAPI session from the session pool |
12888 10:14:38.445 [3092] (JournalTask) <5488> EV:L {CMAPISession::GetMapiSessionFromPoolEx} (Entry) Additional MAPILogonEx flags [0x0]
12889 10:14:38.445 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession} (Entry)
12890 10:14:38.445 [3092] (JournalTask) <2808> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12891 10:14:38.445 [3092] (JournalTask) <3560> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12892 10:14:38.445 [3092] (JournalTask) <6472> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12893 10:14:38.445 [3092] (JournalTask) <4248> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12894 10:14:38.445 [3092] (JournalTask) <1092> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12895 10:14:38.445 [3092] (JournalTask) <8864> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12896 10:14:38.445 [3092] (JournalTask) <8152> EV:L {AgentMessageDispenser::ProcessNextMessage:#1736} Committing MSMQ transaction.
12897 10:14:38.492 [3092] (JournalTask) <5488> EV:L {CEVMAPIMutex::AcquireMAPIMutex:#88} Try to acquire profile lock.
12898 10:14:38.492 [3092] (JournalTask) <5488> EV:L {CEVMAPIMutex::AcquireMAPIMutex:#137} Acquired exclusive profile lock.
12899 10:14:38.492 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx} (Entry)
12900 10:14:38.492 [3092] (JournalTask) <5488> EV:M {CMailboxHelper::CreateProfileAndSessionEx:#841} Setting up MAPI profile [VaultMbxAgent-MAIL1-5488-1360059278-0-492-0]
12901 10:14:38.492 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx:#844} Creating the MAPI profile...
12902 10:14:38.492 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx:#864} Creating the message service (if it doesn't already exist)...
12903 10:14:38.508 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx:#878} Getting the message service table (GetMsgServiceTable)...
12904 10:14:38.508 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx:#881} Querying the returned message service table...
12905 10:14:38.508 [3092] (JournalTask) <5488> EV:L {ConfigureMsgServiceAttempt} (Entry)
12906 10:14:38.508 [3092] (JournalTask) <5488> EV:L {ConfigureMsgServiceAttempt:#107} Trying ConfigureMsgService using PR_PROFILE_UNRESOLVED_SERVER [MAIL1], attempt [1] of [5]
12907 10:14:38.523 [3092] (JournalTask) <5488> EV:M {ConfigureMsgServiceAttempt:#119} ConfigureMsgService failed: [0x80040115]
12912 10:14:39.023 [3092] (JournalTask) <5488> EV:L {ConfigureMsgServiceAttempt:#82} Using provided Global Catalog Server [hiad1.hsd.hftrust.com]
12913 10:14:39.023 [3092] (JournalTask) <5488> EV:L {ConfigureMsgServiceAttempt:#107} Trying ConfigureMsgService using PR_PROFILE_UNRESOLVED_SERVER [hiad1.hsd.hftrust.com], attempt [2] of [5]
12914 10:14:39.054 [3092] (JournalTask) <5488> EV:L {ConfigureMsgServiceAttempt:#114} ConfigureMsgService successful
12915 10:14:39.054 [3092] (JournalTask) <5488> EV:L {ConfigureMsgServiceAttempt} (Exit) Status: [Success]
12916 10:14:39.054 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx:#997} Attempting MAPI Logon again, using the populated MAPI profile...
12917 10:14:39.133 [3092] (JournalTask) <5488> EV:M {CMailboxHelper::CreateProfileAndSessionEx:#1005} MAPI Profile [VaultMbxAgent-MAIL1-5488-1360059278-0-492-0] successfully created.
12918 10:14:39.133 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::CreateProfileAndSessionEx} (Exit) Status: [Success]
12919 10:14:39.133 [3092] (JournalTask) <5488> EV:M {CEVMAPIMutex::ReleaseMAPIMutex:#147} Releasing exclusive profile lock.
12920 10:14:39.133 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::OpenMailbox:#291} Opening primary mailbox associated with MAPI session. Getting list of message stores.
12921 10:14:39.133 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::OpenMailbox:#299} Reading message store table.
12922 10:14:39.133 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::OpenMailbox:#335} Opening message store...
12923 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMailboxHelper::OpenMailbox:#342} Opened message store.
12924 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession:#354} Getting privileged mbx owner (MAPI property PR_MAILBOX_OWNER_ENTRYID)
12925 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession:#359} Opening privileged mailbox's owner MailUser object
12926 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession:#370} Reading MailUser 'PR_EMAIL_ADDRESS' MAPI property
12927 10:14:39.195 [3092] (JournalTask) <5488> EV:L {UnEncodeCurlyBraces:#5720} String: /o=global/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Recipients/cn=vault house keeper955
12928 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession:#378} MailUser 'PR_EMAIL_ADDRESS' MAPI property = /o=global/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Recipients/cn=vault house keeper955
12929 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession:#384} Getting IExchangeManageStore object from the privileged mbx
12930 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::CreateMapiSession} (Exit) Status: [Success]
12931 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CMAPISession::GetMapiSessionFromPoolEx} (Exit) Status: [Success]
12932 10:14:39.195 [3092] (JournalTask) <5488> EV:L {CExchangePolicyCache::GetPolicy:#245} Returning policy: [135247C229D335344A115FDCFE4AFA3451012700evserver (Default Exchange Journaling Policy)]
12933 10:14:39.195 [3092] (JournalTask) <5488> EV:H {CArchivingAgent::SetPolicy:#22358} [CN=vault journal,OU=Hansard Server Service Accounts,DC=hsd,DC=hftrust,DC=com] is using policy [Default Exchange Journaling Policy].
12934 10:14:39.211 [3092] (JournalTask) <5488> EV:M (null) - JournalDelay key not found using default period
12935 10:14:39.211 [3092] (JournalTask) <5488> EV:M {CArchivingAgent::ProcessUserEx:#17960} Journal Advanced Policy Setting ClearTextPrimary [True]
12936 10:14:39.211 [3092] (JournalTask) <5488> EV:L :CArchivingAgent::ProcessUser() |Creating the Entry ID of user mailbox to be processed |
12937 10:14:39.211 [3092] (JournalTask) <5488> EV:M :CArchivingAgent::ProcessUser() |Open users message store |
12938 10:14:39.289 [3092] (JournalTask) <5488> EV:L :CArchivingAgent::ProcessUser() |Getting the entry ID of the mailbox wastebasket or deleted items folder |
12939 10:14:39.289 [3092] (JournalTask) <5488> EV:L {CFolderHelper::GetSpecialFolders:#2107} Getting special folder Ids (Wastebasket, Outbox, Sent Items &c.), attempt [1] of [4]
12940 10:14:39.304 [3092] (JournalTask) <5488> EV:M :CArchivingAgent::ProcessUser() |Getting the users mailbox folder and state. |
12941 10:14:39.383 [3092] (JournalTask) <5488> EV:M {CMailboxHelper::GetMailboxState:#443} Mailbox is [Enabled]
12942 10:14:39.383 [3092] (JournalTask) <5488> EV:M {CMailboxHelper::GetMailboxState:#467} The mailbox is a [Journal] mailbox.
12943 10:14:39.398 [3092] (JournalTask) <5488> EV:M {CArchivingAgent::ProcessUserEx:#18244} Checking Mailbox Site [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F]. HR[0x0]
12944 10:14:39.398 [3092] (JournalTask) <5488> EV:M :CArchivingAgent::ProcessUser_EnableHandling() - Entering routine
12945 10:14:39.398 [3092] (JournalTask) <5488> EV:M :CArchivingAgent::ProcessUser_EnableHandling() - Getting IMailboxServicesAgent
12946 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CSecurityWrapper::CSecurityWrapper:#119} Creating security wrapper. Role checks required: [True]
12947 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CExchangePolicyCache::GetPolicyCache:#91} Returning existing cache.
12948 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CExchangeDesktopPolicyCache::GetDesktopPolicyCache:#81} Returning existing cache.
12949 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CEVMAPIMutex::CreateMAPIMutex:#57} Create mutex [EVProfileMutex EV_AGENTCLIENTBROKER]
12950 10:14:39.398 [3092] (JournalTask) <5488> EV:M Check vault read rights : True
12951 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CMAPIVersionHelper::IsOutlookInstalledAsDefault:#364} Checking registry for default mail client...
12952 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CMAPIVersionHelper::IsOutlookInstalledAsDefault:#379} Default mail client registry key set to [Microsoft Outlook].
12953 10:14:39.398 [3092] (JournalTask) <5488> EV:L {CMAPIVersionHelper::IsOutlookInstalledAsDefault:#392} Default mail client is Outlook.
12954 10:14:39.398 [3092] (JournalTask) <5488> EV:M :CArchivingAgent::ProcessUser_EnableHandling() - Exiting routine successfully
12955 10:14:39.539 [3092] (JournalTask) <5488> EV:L {CFilterHelper::StampDefaults:#1704} Setting EV properties on msg.
12956 10:14:39.539 [3092] (JournalTask) <5488> EV:L {CFilterHelper::StampDefaults:#1707} Saving changes to MAPI msg.
12957 10:14:39.586 [3092] (JournalTask) <5488> EV:M :CArchivingAgent::ProcessUser() |Reading users quota limit and current usage |
12958 10:14:39.601 [3092] (JournalTask) <5488> EV:H A storage limit has been found on mailbox CN=vault journal,OU=Hansard Server Service Accounts,DC=hsd,DC=hftrust,DC=com| Quota Type: QUOTA_NONE| Quota Limit (K): 0| Quota Used (K): 8514642| (Note: This is the information store default for all mailboxes) |
12959 10:14:39.601 [3092] (JournalTask) <5488> EV:H :CArchivingAgent::ProcessUser() |We are the Journal agent. Marking the this mailbox as the Journal mailbox |
12961 10:14:39.664 [3092] (JournalTask) <5488> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Entry [m_nNumTries = 40]
12962 10:14:39.664 [3092] (JournalTask) <5488> EV:L CBaseDirectoryServiceWrapper::CreateDirectoryService() - Successfully communicated with an EV Directory Service on the local machine
12963 10:14:39.679 [3092] (JournalTask) <5488> EV:H {CArchivingAgent::ProcessUserEx:#18662} Mbx [/O=GLOBAL/OU=EXCHANGE ADMINISTRATIVE GROUP (FYDIBOHF23SPDLT)/CN=RECIPIENTS/CN=VAULT JOURNAL73F] is enabled and ready for processing.

0
Login to vote
Rob.Wilcox's picture

Same as my trace, give or take..

 

And the output from the SQL command?

0
Login to vote
cybergirl1987's picture

Hello, the customer has not provided with the output yet. I shall give it to you as soon as I receive it.

0
Login to vote
cybergirl1987's picture

Hello, I provided the customer with this link http://www.symantec.com/docs/TECH50945 and it has seemed to help. Earlier the pending items in journal mailbox were 90,000 and now it has reduced to 100 after running the task in report mode and then switching it back to normal, turning off "pending shortcut timeout" and resynching the journal. Problem is that these remaining 100 items show the archived icon, but still they are lying in the mailbox, they are not getting cleared like they should. I've advised the customer to try restoring few items to see if they get processed. What else can we try?

0
Login to vote