Retain Logs
From GWAVA Technologies Training
When attempting to troubleshoot Retain the logs will be the greatest help to you.
Contents |
Monitoring and Reading Log FIles
RetainWorker
This log is against an Exchange 2013 system, but the principles apply to each email system even if the details may differ. The Worker log contains what happens as the worker connects to the email system and gets messages. You want to have the logs run in Diagnostic mode which is set in the Logging tab of the Worker web object in the Retain admin console.
Job Start
When a job begins there will be a header that looks something like this:
2016-07-05 16:30:00,022 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.quartz.QuartzTriggerListener: FIRED: This trigger is a recurring friendly job name = Daily EX Trigger 'ECD7EFFD600E95C66902048EE9A47EB5_triggerGroup.ECD7EFFD600E95C66902048EE9A47EB5_triggerName': triggerClass: 'org.quartz.CronTrigger isVolatile: false calendar: 'null' misfireInstruction: 0 nextFireTime: Wed Jul 06 16:30:00 MDT 2016 2016-07-05 16:30:00,054 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.RetainArchiveJob: Add Daily EX (ECD7EFFD600E95C66902048EE9A47EB5) to queue [] 2016-07-05 16:30:00,054 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.RetainArchiveJob: Job Daily EX (ECD7EFFD600E95C66902048EE9A47EB5) is in a RUNNING state 2016-07-05 16:30:00,054 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.RetainArchiveJob: Job memory: (free/max/total): (2996635/7459840/7459840) 2016-07-05 16:30:00,054 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.RetainArchiveJob: Starting scheduled Archive job ECD7EFFD600E95C66902048EE9A47EB5 @ Tue Jul 05 16:30:00 MDT 2016 2016-07-05 16:30:00,084 TRACE [Stubber-1467757800054] com.gwava.jobs.stubbing.BGStubber: Background Stubbing thread coming to life ... 2016-07-05 16:30:00,537 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.job.stats.RQStatsUpdater: Creating new stat tracker for thread: RTWQuartzScheduler_Archive_Worker-9 2016-07-05 16:30:00,537 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Job starting Daily EX 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Mail System : exchange 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Profile Settings applied to this job : 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Profile Name : Item Store Flag 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Mailbox Type : Users 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Item Type : Mail, Appointment, Note, Task 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Item Source : All 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Message Status : Opened Doesn't Matter|Read Doesn't Matter|Private Doesn't Matter|Personal Doesn't Matter|Confidential Doesn't Matter 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Scope 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Date Range to Scan : All Messages (ignore date) 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Duplicate Check : Ignore all messages older than item store flag 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Set Storage Flags : Don't set Purge flag, Don't set Retention flag, Set Item Store flag 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Miscellaneous 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Store Attachments : Store all attachments 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Store/index Internet Headers : true 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Include Routing Properties : true 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Include Shared Folders : all 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Advanced 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Advanced Criteria : 0 2016-07-05 16:30:00,537 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Folder Scope : all
There will be a section of getting the user list just after this.
Logging in as a User
Then Retain begins the data dredge by entering user mailboxes:
2016-07-05 16:31:51,522 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: ============================================================================================= 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Logging in as : test19@gwava.net to dredge their mailbox. 2016-07-05 16:31:51,522 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.jobs.ProcessExchFilters: profile.getDateType(): 1 2016-07-05 16:31:51,522 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.jobs.ProcessExchFilters: profile.getDateType(): All Messages (ignore date) 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: - Query Range Used: 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: - GTE:1970-01-01 00:00:00 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: - LTE:2016-07-05 22:31:51 2016-07-05 16:31:51,522 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.archive.process.RetainUser: Begin login of test19@gwava.net 2016-07-05 16:31:51,522 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: RetainServerCommunication.obtainHTTPResponseCodeAndData() - About to post to : http://10.1.4.52:48080/RetainServer/Server/ServerController2.jsp Params:{emailSystem=exchange, password=WVVTSUJURE5OQU9ORFVaTVRHVA==, mailbox=test19@gwava.net, method=checkIfUserExists, abSystem=exchange, domain=sf.gwava.net, display=test19, uuid=779d94ef38f5164f97cc4b38ed03299e, archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F, email=test19@sf.gwava.net, po=SFEX13SRV} 2016-07-05 16:31:51,538 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HttpUIDResolver: checkIfUserExists response: OK: USER EXISTS ::: 66cd42a7-1e0c-4c76-a461-e4c81726dbfb 2016-07-05 16:31:51,538 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.archive.process.RetainUser: End login of test19@gwava.net 2016-07-05 16:31:51,538 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.stats.StatsUpdater: updating job status information name: lastmailboxnumber 2016-07-05 16:31:51,538 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: RetainServerCommunication.obtainHTTPResponseCodeAndData() - About to post to : http://10.1.4.52:48080/RetainServer/Server/ServerController2.jsp Params:{emailSystem=exchange, jobid=ECD7EFFD600E95C66902048EE9A47EB5, password=WVVTSUJURE5OQU9ORFVaTVRHVA==, method=svStatus, proc_id=null, f_order=1, lastmailboxnumber=2, archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F} 2016-07-05 16:31:51,803 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.stats.StatsUpdater: updating job status information name: lastmailbox 2016-07-05 16:31:51,803 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: RetainServerCommunication.obtainHTTPResponseCodeAndData() - About to post to : http://10.1.4.52:48080/RetainServer/Server/ServerController2.jsp Params:{emailSystem=exchange, jobid=ECD7EFFD600E95C66902048EE9A47EB5, password=WVVTSUJURE5OQU9ORFVaTVRHVA==, lastmailbox=test19@gwava.net, method=svStatus, proc_id=null, f_order=1, archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F} 2016-07-05 16:31:52,102 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.stats.StatsUpdater: updating job status information name: lastpo 2016-07-05 16:31:52,102 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: RetainServerCommunication.obtainHTTPResponseCodeAndData() - About to post to : http://10.1.4.52:48080/RetainServer/Server/ServerController2.jsp Params:{emailSystem=exchange, jobid=ECD7EFFD600E95C66902048EE9A47EB5, password=WVVTSUJURE5OQU9ORFVaTVRHVA==, method=svStatus, proc_id=null, f_order=1, lastpo=SFEX13SRV, archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F} 2016-07-05 16:31:52,116 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.retain.worker.rest.client.JobStatusTracker: Starting the stat mailbox run update for user: 66cd42a7-1e0c-4c76-a461-e4c81726dbfb 2016-07-05 16:31:52,288 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.MailboxArchivingStats: enterMailbox: test19@gwava.net
Search for "Logging in as :" to find the next user.
This is followed by a list of the user's folders.
Getting a message
2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: ============================================================= 2016-07-05 16:32:20,256 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Processing ID: 6820dc7924bd77479af526bf5cb3282c00009dd6e626 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Archive Message: 6820dc7924bd77479af526bf5cb3282c00000000010d#6820dc7924bd77479af526bf5cb3282c00009dd6e626 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Location:\test19\Inbox 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Subject:UTF8_HTML Go-Postal 06/16/2016 16:17:59 882533431 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Date:2016-06-16 22:18:00 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Sender:script@sf.gwava.net 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Recipient(s):test19@sf.gwava.net 2016-07-05 16:32:20,256 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Number of attachments: 2 2016-07-05 16:32:20,256 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveMailboxBase: Reset LastArchivedItemRetentionDate to 1. New folder: \test19\Inbox, old: 2016-07-05 16:32:20,256 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: itemType: EXCH.MessageType 2016-07-05 16:32:20,397 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveMetaData: hashMapToQueryString: emailSystem=exchange&archiver=Worker1+%28Exchange%29&senderUUID=script%40sf.gwava.net&exchange.m.Sender-Name=script%40sf.gwava.net&subject=UTF8_HTML+Go-Postal+06%2F16%2F2016+16%3A17%3A59+882533431&senderDisplay=script%40sf.gwava.net&delivered=1466115480&uuid=66cd42a7-1e0c-4c76-a461-e4c81726dbfb&userid=test19%40gwava.net&dirPathIDStr=%5CRoot%5CMailbox&folderID=AAMkAGI3OGE2Mjk5LWMxZWMtNDRlNy1iOWFhLWJhNjdhZjEyYjkzYgAuAAAAAADpCgDO8OTCS66scINjm1RaAQBoINx5JL13R5r1Jr9csygsAAAAAAENAAA%3D&archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F&itemTypeString=EXCH.MessageType&jobid=ECD7EFFD600E95C66902048EE9A47EB5&exchange.m.ci=AQHRyBzxhSAUfxouD06WRPHaOVMDcQ%3D%3D&exchange.m.dateReceived=2016-06-16T22%3A18%3A00Z&password=WVVTSUJURE5OQU9ORFVaTVRHVA%3D%3D&dirPath=%5Ctest19%5CInbox&from=script%40sf.gwava.net&categories=&exchange.m.ct=UTF8_HTML+Go-Postal+06%2F16%2F2016+16%3A17%3A59+882533431&exchange.m.foldertype=inbox&exchange.m.Sender-Routing-Type=SMTP&personalSubject=&friendlyname=Daily+EX&expireDays=0&exchange.m.Sender-Email=script%40sf.gwava.net&parentFolderID=6820dc7924bd77479af526bf5cb3282c00000000010d&created=1466115480&msgid=6820dc7924bd77479af526bf5cb3282c00000000010d%236820dc7924bd77479af526bf5cb3282c00009dd6e626&priority=Standard&exchange.m.sensitivity=Normal&isSubmail=false&boxTypeString=received&recipients=0%3Atest19%3Atest19%40sf.gwava.net%3A%3B&exchange.m.itemClass=IPM.Note&item.class=com.microsoft.schemas.exchange.services._2006.types.MessageType&attachmentCount=2&exchange.m.dateSent=2016-06-16T22%3A17%3A59Z&internet=false&status= 2016-07-05 16:32:20,428 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveMetaData: hashMapToQueryString: emailSystem=exchange&archiver=Worker1+%28Exchange%29&senderUUID=script%40sf.gwava.net&exchange.m.Sender-Name=script%40sf.gwava.net&subject=UTF8_HTML+Go-Postal+06%2F16%2F2016+16%3A17%3A59+882533431&senderDisplay=script%40sf.gwava.net&delivered=1466115480&filesize=594&uuid=66cd42a7-1e0c-4c76-a461-e4c81726dbfb&userid=test19%40gwava.net&dirPathIDStr=%5CRoot%5CMailbox&folderID=AAMkAGI3OGE2Mjk5LWMxZWMtNDRlNy1iOWFhLWJhNjdhZjEyYjkzYgAuAAAAAADpCgDO8OTCS66scINjm1RaAQBoINx5JL13R5r1Jr9csygsAAAAAAENAAA%3D&archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F&itemTypeString=EXCH.MessageType&finalpart=no&jobid=ECD7EFFD600E95C66902048EE9A47EB5&exchange.m.ci=AQHRyBzxhSAUfxouD06WRPHaOVMDcQ%3D%3D&exchange.m.dateReceived=2016-06-16T22%3A18%3A00Z&password=WVVTSUJURE5OQU9ORFVaTVRHVA%3D%3D&dirPath=%5Ctest19%5CInbox&from=script%40sf.gwava.net&categories=&contentType=bodytext%2Fplain&exchange.m.ct=UTF8_HTML+Go-Postal+06%2F16%2F2016+16%3A17%3A59+882533431&exchange.m.foldertype=inbox&exchange.m.Sender-Routing-Type=SMTP&personalSubject=&friendlyname=Daily+EX&expireDays=0&exchange.m.Sender-Email=script%40sf.gwava.net&parentFolderID=6820dc7924bd77479af526bf5cb3282c00000000010d&created=1466115480&msgid=6820dc7924bd77479af526bf5cb3282c00000000010d%236820dc7924bd77479af526bf5cb3282c00009dd6e626&priority=Standard&exchange.m.sensitivity=Normal&isSubmail=false&boxTypeString=received&compressedSize=408&filename=UTF8_HTML+Go-Postal+06%2F16%2F2016+16%3A17%3A59+882533431.txt&recipients=0%3Atest19%3Atest19%40sf.gwava.net%3A%3B&exchange.m.itemClass=IPM.Note&item.class=com.microsoft.schemas.exchange.services._2006.types.MessageType&attachmentCount=2&exchange.m.dateSent=2016-06-16T22%3A17%3A59Z&hash=5C18EC008BB67D988F3DDFC5868790AF6C963EF2CAD7DF0FF5A594949C93533F&internet=false&status= 2016-07-05 16:32:20,428 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: Sending data and waiting for response. 2016-07-05 16:32:20,428 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: using ApacheClient with TimedHttpMethodRetryHandler... 2016-07-05 16:32:20,428 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: headerstream.length: 1764 dataStream: 408 2016-07-05 16:32:21,913 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: getRequestServerVersion - 1467757941913 2016-07-05 16:32:21,913 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: getItem - 1467757941913 2016-07-05 16:32:22,413 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@414631c) 2016-07-05 16:32:22,413 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@73a84e0f) 2016-07-05 16:32:22,413 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@137cfa5a) 2016-07-05 16:32:22,413 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@1cb72b46) 2016-07-05 16:32:22,413 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@3b9ca74f) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@af54e05) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@7e2fdb2b) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@5b6732b3) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@51f404f) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@25bab38f) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@25ccd290) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@475c8e30) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@383ea3ac) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@486849ef) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@b734a20) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@28fd6870) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@65139d00) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@6f3e877c) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@7e8de2f1) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@3d70abb8) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@4472da8b) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@5fecb01e) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@4ee75b78) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@76f21477) 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.archiveimpl.process.ExchangeArchiveFactory: createMailboxItem: com.microsoft.schemas.exchange.services._2006.types.MessageType@24863ea0) 2016-07-05 16:32:22,444 DEBUG [Thread-6944266] com.gwava.ews.archiveimpl.process.CursorFetchThread: Fetching attachments...:100(totalsize:310453), total to fetch: 50 2016-07-05 16:32:22,444 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: getRequestServerVersion - 1467757942444 2016-07-05 16:32:22,506 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: getStreamedDirectory - 1467757942506 2016-07-05 16:32:22,506 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: getRawPort - 1467757942506 2016-07-05 16:32:23,523 TRACE [Thread-6944271] com.gwava.ews.HttpPostThreadThread: thread exits: 7434939 2016-07-05 16:32:24,335 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveEmail: sent mail textbody with subject: UTF8_HTML Go-Postal 06/16/2016 16:17:59 882533431, server-response: Archive: OK: All is well. Result=AddedEMails: 0, emailID=3294374, parentID=13 2016-07-05 16:32:24,335 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveEmail: archiveEmail: processing binary attachment, subject: UTF8_HTML Go-Postal 06/16/2016 16:17:59 882533431, att-name: shuffled.csv, isItem: false, size: 598... 2016-07-05 16:32:24,335 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveAttachment: Skipping check for whether the instance exists 2016-07-05 16:32:24,335 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: Sending data and waiting for response. 2016-07-05 16:32:24,335 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: using ApacheClient with TimedHttpMethodRetryHandler... 2016-07-05 16:32:24,335 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: headerstream.length: 1862 dataStream: 256 2016-07-05 16:32:25,069 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveAttachment: Send a nice healthy blob:Archive: OK: All is well. Result=AddedEMails: 0, emailID=3294374, parentID=13 2016-07-05 16:32:25,069 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveEmail: archiveEmail: processing binary attachment, subject: UTF8_HTML Go-Postal 06/16/2016 16:17:59 882533431, att-name: utf.txt, isItem: false, size: 2050... 2016-07-05 16:32:25,069 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveAttachment: Skipping check for whether the instance exists 2016-07-05 16:32:25,069 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: Sending data and waiting for response. 2016-07-05 16:32:25,069 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: using ApacheClient with TimedHttpMethodRetryHandler... 2016-07-05 16:32:25,069 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: headerstream.length: 1858 dataStream: 922 2016-07-05 16:32:25,288 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: getRequestServerVersion - 1467757945288 2016-07-05 16:32:25,288 TRACE [Thread-6944266] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: findItem - 1467757945288 2016-07-05 16:32:25,867 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveAttachment: Send a nice healthy blob:Archive: OK: All is well. Result=AddedEMails: 0, emailID=3294374, parentID=13 2016-07-05 16:32:25,867 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveEmail: archiveEmail: processing binary attachment, subject: UTF8_HTML Go-Postal 06/16/2016 16:17:59 882533431, att-name: headers.822, isItem: false, size: 884... 2016-07-05 16:32:25,867 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveAttachment: Skipping check for whether the instance exists 2016-07-05 16:32:25,867 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: Sending data and waiting for response. 2016-07-05 16:32:25,867 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: using ApacheClient with TimedHttpMethodRetryHandler... 2016-07-05 16:32:25,897 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.HTTPWrapper2: headerstream.length: 1808 dataStream: 349 2016-07-05 16:32:26,238 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveAttachment: Send a nice healthy blob:Archive: OK: All is well. Result=AddedEMails: 0, emailID=3294374, parentID=13 2016-07-05 16:32:26,238 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.ArchiveEmail: EmailID: 3294374, parentID: 13, stubbingStage: 0 2016-07-05 16:32:26,238 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Message was previously archived so skipped! 2016-07-05 16:32:26,238 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: lastArchivedMailDeliveredDate vs. mail.deliveredDate (using delivered-date): Wed Dec 31 17:00:00 MST 1969 vs: Thu Jun 16 16:18:00 MDT 2016 2016-07-05 16:32:26,238 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.archiveimpl.process.CursorFetchThread: totalCount/totalItemsInCursor : 2/ 50 2016-07-05 16:32:26,238 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.jobs.ExchangeDredger: nextItem: ExchangeMessage [bodyHash=0, boxType=null, cachedOriginalSize=-1, compressedBodySize=-1, entrySourceKey=6820dc7924bd77479af526bf5cb3282c00009dd6e627, folderType=inbox, isSubmail=false, itemType=EXCH.MessageType, myItem=com.microsoft.schemas.exchange.services._2006.types.MessageType@5ba0ac5d, parentIDsAsString=null, parents=null, statusWordList=, submailLevel=0] 2016-07-05 16:32:26,238 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.jobs.ExchangeDredger: subject: UTF8_HTML Go-Postal 06/16/2016 16:18:01 439814630, boxtype: received
If the message already exists in the Retain archive you'll see a message like this:
2016-07-05 16:31:49,803 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.Archiver: Message was previously archived so skipped!
Leaving a Mailbox
2016-07-05 16:31:51,303 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.archive.process.DateFlagManager: Using MaxItemRetention-Date 2016-07-05 16:31:51,303 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.archive.process.DateFlagManager: Last archived mail Retention date=Thu Oct 22 10:49:58 MDT 2015 Last mail before first error mail Retention date=Wed Dec 31 17:00:00 MST 1969 Max mail Retention date=Thu Oct 22 10:49:58 MDT 2015 Mailbox login time=Tue Jul 05 16:30:13 MDT 2016 Date Chosen:Thu Oct 22 10:48:58 MDT 2015 2016-07-05 16:31:51,303 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.MailboxArchivingStats: Calculated date-flag TimeStamp: (Thu Oct 22 10:48:58 MDT 2015) 2016-07-05 16:31:51,303 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: RetainServerCommunication.obtainHTTPResponseCodeAndData() - About to post to : http://10.1.4.52:48080/RetainServer/Server/ServerController2.jsp Params:{emailSystem=exchange, 4112started=1467757897334, method=svStatus, 4112earlyexited=false, proc_id=null, 4112mailboxerrortotal=0, archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F, jobid=ECD7EFFD600E95C66902048EE9A47EB5, 4112mailboxprocessed=1, password=WVVTSUJURE5OQU9ORFVaTVRHVA==, 4112mailboxwarntotal=0, 4112useraborted=false, 4112ended=1467757911303, 4112mailboxmessagetotal=0, 4112dateflags=, 4112mailboxintuuid=533e8805-1c3f-49eb-b597-350d3ab1b7b9} 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Cumulative mails processed for this job: 0 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Cumulative mails archived for this job: 0 2016-07-05 16:31:51,522 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Cumulative errors for this job: 0 2016-07-05 16:31:51,522 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Logging out... 2016-07-05 16:31:51,522 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: deleteStreamedDirectory - 1467757911522
End of the Job
2016-07-05 23:55:08,494 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.archive.process.DateFlagManager: Using MaxItemRetention-Date 2016-07-05 23:55:08,494 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.archive.process.DateFlagManager: Last archived mail Retention date=Fri May 27 14:18:52 MDT 2016 Last mail before first error mail Retention date=Wed Dec 31 17:00:00 MST 1969 Max mail Retention date=Fri May 27 14:18:52 MDT 2016 Mailbox login time=Tue Jul 05 16:30:13 MDT 2016 Date Chosen:Fri May 27 14:17:52 MDT 2016 2016-07-05 23:55:08,494 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.MailboxArchivingStats: Calculated date-flag TimeStamp: (Fri May 27 14:17:52 MDT 2016) 2016-07-05 23:55:08,494 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.http.RetainServerCommunication: RetainServerCommunication.obtainHTTPResponseCodeAndData() - About to post to : http://10.1.4.52:48080/RetainServer/Server/ServerController2.jsp Params:{emailSystem=exchange, 4112started=1467784457771, method=svStatus, 4112earlyexited=false, proc_id=null, 4112mailboxerrortotal=0, archiverID=DDB2E4039E3B4C6AFF18ECD1FD30A29F, jobid=ECD7EFFD600E95C66902048EE9A47EB5, 4112mailboxprocessed=1, password=WVVTSUJURE5OQU9ORFVaTVRHVA==, 4112mailboxwarntotal=0, 4112useraborted=false, 4112ended=1467784508494, 4112mailboxmessagetotal=0, 4112dateflags=, 4112mailboxintuuid=ca727e52-c039-4e2e-bb2e-be57851e2ae8} 2016-07-05 23:55:08,593 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Cumulative mails processed for this job: 0 2016-07-05 23:55:08,593 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Cumulative mails archived for this job: 0 2016-07-05 23:55:08,593 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Cumulative errors for this job: 0 2016-07-05 23:55:08,593 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Logging out... 2016-07-05 23:55:08,593 TRACE [RTWQuartzScheduler_Archive_Worker-9] com.gwava.ews.RetainExchangeWebserviceFactory: invoking retainews method: deleteStreamedDirectory - 1467784508593 2016-07-05 23:55:08,618 INFO [RTWQuartzScheduler_Archive_Worker-9] com.gwava.caapi.process.RetainDredger: Job ending : Daily EX 2016-07-05 23:55:08,618 DEBUG [RTWQuartzScheduler_Archive_Worker-9] com.gwava.jobs.stats.StatsUpdater: archived 10031 msgs for this job. Job total Errors: 0
Error Messages
There are many error codes, so this is just a single sample.
2016-07-05 23:55:15,491 ERROR [RTWQuartzScheduler_Archive_Worker-1] com.gwava.workerutils.DefaultCAAPIErrorHandleStrategy: reportError: Process Archive Job :: com.gwava.workerutils.DefaultCAAPIErrorHandleStrategy.returnCaller:55 :: com.gwava.archive.exceptions.RetainWorkerFatalException: com.gwava.archive.exceptions.RetainWorkerException: com.gwava.archive.exceptions.RetainWorkerFatalException: at com.gwava.caapi.process.RetainDredger.processNormalJob(RetainDredger.java:272) at com.gwava.ews.jobs.ExchangeDredger.executeWork(ExchangeDredger.java:509) at com.gwava.jobs.RetainArchiveJob.performDredge(RetainArchiveJob.java:567) at com.gwava.jobs.RetainArchiveJob.execute(RetainArchiveJob.java:235) at com.gwava.jobs.RetainArchiveJob.execute(RetainArchiveJob.java:448) at org.quartz.core.JobRunShell.run(JobRunShell.java:216) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549) Caused by: com.gwava.archive.exceptions.RetainWorkerFatalException: at com.gwava.ews.jobs.selection.LiveEWSUserSelection.resolveArchiveSource(LiveEWSUserSelection.java:91) at com.gwava.ews.jobs.selection.EWSUserSelection.getListOfUsers(EWSUserSelection.java:112) at com.gwava.ews.jobs.ExchangeDredger.getListOfUsers(ExchangeDredger.java:142) at com.gwava.ews.jobs.ExchangeDredger.getListOfUsers(ExchangeDredger.java:48) at com.gwava.caapi.process.RetainDredger.processNormalJob(RetainDredger.java:270) ... 6 more Caused by: javax.naming.NameNotFoundException: [LDAP: error code 32 - 0000208D: NameErr: DSID-03100213, problem 2001 (NO_OBJECT), data 0, best match of: ]; remaining name '<GUID=e3d02cb7937f7f4e957efe9218b19193>' at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3160) at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3081) at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2888) at com.sun.jndi.ldap.LdapCtx.c_getAttributes(LdapCtx.java:1329) at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_getAttributes(ComponentDirContext.java:235) at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:141) at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.getAttributes(PartialCompositeDirContext.java:129) at javax.naming.directory.InitialDirContext.getAttributes(InitialDirContext.java:142) at com.gwava.address.exchange.impl.UserViaGUIDLDAP.getUserForDN(UserViaGUIDLDAP.java:60) at com.gwava.address.exchange.impl.UserViaGUIDLDAP.getUser(UserViaGUIDLDAP.java:47) at com.gwava.address.exchange.impl.UserViaGUIDLDAP.performOperation(UserViaGUIDLDAP.java:99) at com.gwava.ews.jobs.selection.LiveEWSUserSelection.processIncludeUserSource(LiveEWSUserSelection.java:151) at com.gwava.ews.jobs.selection.LiveEWSUserSelection.resolveArchiveSource(LiveEWSUserSelection.java:80) ... 10 more
An LDAP 32 is one that is in the knowledgebase [1].
Most errors have been documented now. Often you just have to find the first error after the beginning of the job and you have the issue that needs to be fixed. Error stacks can be quite long and you'll need to find the top, there may be warnings above it that have some details as well.
How to get meaning from the logs
When troubleshooting a particular error is not fixing things you may have to change how you see what is happening in the logs.
There is a lot more information in the logs then is useful sometimes. So you have to find a way to pull signal from all the noise. One way of doing that is to extract lines that are more useful than others.
Using an advanced text editor like TextPad is handy.
- Search for "Job starting" to find the beginning of the job and mark all instances.
- Search for "Logging in as :" to find each user and mark all.
- Search for "ERROR" and mark all. Since errors come in multi-line stacks this will only show you where they are in relation to everything else.
- Search for "Job ending :" and mark all.
- Search for "&hash=" this marks the line with all the header data being sent to the server, this line is unique for each message.
Copy all bookmarked lines and paste into a new document. Now you can see the essential information of the job with much less noise and you can see patterns better.
If there are lots of errors with a particular mailbox then it is likely that the mailbox needs to be repaired by the email system.
If you note the time it takes for each message to be archived you can see if there are any gaps that show places where a job is being slowed down. For example, if there are hundreds of recipients it will take a long time for the database to store them all and you can limit the number stored with the rest being placed in an XML file.
Return to Retain Training
