Environment
Retain 3.x
Situation
Why do I get different results when I run a deletion job right after getting the deletion report email?
Resolution
Receiving the Deletion Report email is not the same as the deletion job being complete. It is actually sent near the beginning of the deletion job, when the job has finished assembling the list of messages to be deleted. Then it takes some time as all those messages are processed from the indexes, database and disk. If you try running another deletion report while a deletion job is running, the results may be unpredictable.
The Deletion Job begins with these statements in the RetainServer log file:
2015-06-24 15:45:00,847 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.DeletionTaskHelper - Manual trigger of deletion job requested. Not checking schedule
2015-06-24 15:45:00,847 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - DeletionTaskExecutor begins
2015-06-24 15:45:00,847 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - Running deletion job.
2015-06-24 15:45:00,847 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - Normal deletion mode
2015-06-24 15:45:00,847 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - autoApprove:true
2015-06-24 15:45:00,865 [DeletionJobTask-1-thread-1] DEBUG com.gwava.deletion.DJDeletionOperation - Deletion report stored at /var/opt/beginfinite/retain/archive/Deletion127328742880685752EYSZTWSUTFUWYFMRMHWHU.html
Then the job builds a list from the indexes of messages that are eligible for deletion:
2015-06-24 15:45:00,867 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.DJDeletionOperation - On Page #0
2015-06-24 15:45:01,472 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.DJDeletionOperation - Result page TotalHits: 2566 500 in result set
2015-06-24 15:45:01,472 [DeletionJobTask-1-thread-1] TRACE com.gwava.hibernate.HibernateStringUtil - inSet: 264761,264762,264763,264764,264765,264766,264767,264768,264769,264770,720716,729602,729603,729604,729605,729606,729607,729608,729609,729610,729611,729612,729613,729614,729615,729616,729617,729618,729619,729620,729621,729622,729623,729624,729585,729586,729587,729588,729589,729590,729591,729592,729593,729594,729595,729596,729597,729598,729599,729600,729601,734621,734622,734623,734624,734625,734626,734627,734628,734629,734630,734631,734632,734633,734634,734635,734636,734637,734638,734639,734640,734641,734642,734643,734644,734645,734646,734647,734648,734649,734650,734651,734652,734653,734654,734655,734656,734657,734658,734659,734660,734661,734662,734682,734683,734684,734685,734686,734687,734688,734689,734690,734691,734692,734693,734694,734695,734696,734697,734698,734699,734700,734701,734702,734703,734704,734705,734706,734707,734708,734709,734710,734711,734712,734713,734714,734715,734716,734717,734663,734664,734665,734666,734667,734668,734669,734670,734671,734672,734673,734674,734675,734676,734677,734678,734679,734680,734681,731841,731840,734813,734814,734815,734816,734817,734818,734819,734820,734821,734822,734823,734824,734825,734826,734827,734828,734829,734830,734831,734832,734833,734834,734835,734836,734837,734838,734839,734840,734841,734842,734843,734844,734845,734846,734847,734848,734849,734850,734851,734852,734853,734854,734855,734856,734857,734858,734859,734860,734861,734883,734884,734885,734886,734887,734888,734889,734890,734891,734892,734893,734894,734895,734896,734897,734898,734899,734900,734901,734902,734903,734904,734905,734906,734907,734908,734862,734863,734864,734865,734866,734867,734868,734869,734870,734871,734872,734873,734874,734875,734876,734877,734878,734879,734880,734881,734882,731720,731721,731722,731723,731724,731725,731726,731727,731728,731729,731730,731731,731732,731733,731734,731735,731736,731737,731738,731739,731740,731741,731742,731743,731744,731745,731746,731747,731748,731749,731750,731751,731752,731753,731754,731755,731756,731757,731758,731759,731760,731761,731762,731763,731764,731765,731766,731767,731768,731769,731797,731798,731799,731800,731801,731802,731803,731804,731805,731806,731807,731808,731809,731810,731811,731812,731813,731814,731815,731816,731817,731818,731819,731820,731821,731822,731823,731824,731825,731826,731827,731828,731770,731771,731772,731773,731774,731775,731776,731777,731778,731779,731780,731781,731782,731783,731784,731785,731786,731787,731829,731830,731831,731832,731833,731834,731835,731836,731837,731788,731789,731790,731791,731792,731793,731794,731795,731838,731839,731719,731796,731682,731683,731684,731685,731686,731687,731688,731689,731690,731691,731692,731693,731694,731695,731696,731697,731698,731699,731700,731701,731702,731703,731704,731705,731706,731707,731708,731709,731710,731711,731712,731713,731714,731715,731716,731717,731718,729544,729545,729546,729547,729548,729549,729550,729551,729552,729553,729554,729555,729556,729557,729558,729559,729560,729561,729562,729563,729564,729565,729566,729567,729568,729569,729570,729571,729572,729573,729574,729575,729576,729577,729578,729579,729580,729581,729582,729583,729584,729498,729499,729500,729501,729502,729503,729504,729505,729506,729507,729508,729509,729510,729511,729512,729513,729514,729515,729516,729517,729518,729519,729520,729521,729522,729523,729524,729525,729526,729527,729528,729529,729530,729531,729532,729533,729534,729535,729536,729540,729541,729542,729543,729537,729538,729539,734736,734737,734738,734739,734740,734741,734742,734743,734744
2015-06-24 15:45:01,486 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - List<EMail>: 264761,264762,264763,264764,264765,264766,264767,264768,264769,264770,720716,729602,729603,729604,729605,729606,729607,729608,729609,729610,729611,729612,729613,729614,729615,729616,729617,729618,729619,729620,729621,729622,729623,729624,729585,729586,729587,729588,729589,729590,729591,729592,729593,729594,729595,729596,729597,729598,729599,729600,729601,734621,734622,734623,734624,734625,734626,734627,734628,734629,734630,734631,734632,734633,734634,734635,734636,734637,734638,734639,734640,734641,734642,734643,734644,734645,734646,734647,734648,734649,734650,734651,734652,734653,734654,734655,734656,734657,734658,734659,734660,734661,734662,734682,734683,734684,734685,734686,734687,734688,734689,734690,734691,734692,734693,734694,734695,734696,734697,734698,734699,734700,734701,734702,734703,734704,734705,734706,734707,734708,734709,734710,734711,734712,734713,734714,734715,734716,734717,734663,734664,734665,734666,734667,734668,734669,734670,734671,734672,734673,734674,734675,734676,734677,734678,734679,734680,734681,731841,731840,734813,734814,734815,734816,734817,734818,734819,734820,734821,734822,734823,734824,734825,734826,734827,734828,734829,734830,734831,734832,734833,734834,734835,734836,734837,734838,734839,734840,734841,734842,734843,734844,734845,734846,734847,734848,734849,734850,734851,734852,734853,734854,734855,734856,734857,734858,734859,734860,734861,734883,734884,734885,734886,734887,734888,734889,734890,734891,734892,734893,734894,734895,734896,734897,734898,734899,734900,734901,734902,734903,734904,734905,734906,734907,734908,734862,734863,734864,734865,734866,734867,734868,734869,734870,734871,734872,734873,734874,734875,734876,734877,734878,734879,734880,734881,734882,731720,731721,731722,731723,731724,731725,731726,731727,731728,731729,731730,731731,731732,731733,731734,731735,731736,731737,731738,731739,731740,731741,731742,731743,731744,731745,731746,731747,731748,731749,731750,731751,731752,731753,731754,731755,731756,731757,731758,731759,731760,731761,731762,731763,731764,731765,731766,731767,731768,731769,731797,731798,731799,731800,731801,731802,731803,731804,731805,731806,731807,731808,731809,731810,731811,731812,731813,731814,731815,731816,731817,731818,731819,731820,731821,731822,731823,731824,731825,731826,731827,731828,731770,731771,731772,731773,731774,731775,731776,731777,731778,731779,731780,731781,731782,731783,731784,731785,731786,731787,731829,731830,731831,731832,731833,731834,731835,731836,731837,731788,731789,731790,731791,731792,731793,731794,731795,731838,731839,731719,731796,731682,731683,731684,731685,731686,731687,731688,731689,731690,731691,731692,731693,731694,731695,731696,731697,731698,731699,731700,731701,731702,731703,731704,731705,731706,731707,731708,731709,731710,731711,731712,731713,731714,731715,731716,731717,731718,729544,729545,729546,729547,729548,729549,729550,729551,729552,729553,729554,729555,729556,729557,729558,729559,729560,729561,729562,729563,729564,729565,729566,729567,729568,729569,729570,729571,729572,729573,729574,729575,729576,729577,729578,729579,729580,729581,729582,729583,729584,729498,729499,729500,729501,729502,729503,729504,729505,729506,729507,729508,729509,729510,729511,729512,729513,729514,729515,729516,729517,729518,729519,729520,729521,729522,729523,729524,729525,729526,729527,729528,729529,729530,729531,729532,729533,729534,729535,729536,729540,729541,729542,729543,729537,729538,729539,734736,734737,734738,734739,734740,734741,734742,734743,734744
2015-06-24 15:45:01,490 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - fromIndex=0,toIndex=100
2015-06-24 15:45:02,469 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - fromIndex=100,toIndex=200
2015-06-24 15:45:02,943 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - fromIndex=200,toIndex=300
2015-06-24 15:45:03,545 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - fromIndex=300,toIndex=400
2015-06-24 15:45:04,294 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.AbstractDeletionTaskExecutor - fromIndex=400,toIndex=500
2015-06-24 15:45:05,135 [DeletionJobTask-1-thread-1] DEBUG com.gwava.deletion.AbstractDeletionTaskExecutor - deleteIndexDocs
2015-06-24 15:45:05,135 [DeletionJobTask-1-thread-1] DEBUG com.gwava.deletion.AbstractDeletionTaskExecutor - deleteIndexDocs, tl.size: 500
This is just a sample, there can be many more than this.
Then the deletion task saves and emails the deletion report: (Yes, we know that this is the wrong time to send the email. Yes, it is being worked on. It also only sends the first 10,000 messages it finds, and that is why the report is being moved to Reporting and Monitoring)
2015-06-24 15:45:23,881 [DeletionJobTask-1-thread-1] INFO com.gwava.deletion.DeletionTaskHelper - Sending mail after deletion job...
2015-06-24 15:45:23,881 [DeletionJobTask-1-thread-1] DEBUG com.gwava.deletion.AbstractDeletionTaskExecutor - Deletion report stored at /var/opt/beginfinite/retain/archive/Deletion2244725399666793727EYSZTWSUTFUWYFMRMHWHU.html
The job will check messages are under litigation hold at this point. If the message is under hold then a message "[emailID] is under litigation hold and cannot be deleted" would appear here.
Then the DumpsterThread begins as it goes into the indexes:
2015-06-24 15:45:23,996 [DumpsterThread] INFO com.gwava.deletion.DumpsterDiver - Dumpster dive begins
2015-06-24 15:45:24,039 [DumpsterThread] INFO com.gwava.deletion.DumpsterDiver - Got these many children of dumpster500
2015-06-24 15:45:24,039 [DumpsterThread] TRACE com.gwava.deletion.DumpsterDiver - Delete 264761
2015-06-24 15:45:24,041 [DumpsterThread] INFO com.gwava.deletion.DumpsterDiver - Deleting node 264761
Then the DumpsterThread deletes the files from database and gathers the hashes of files on disk that need to be deleted:
2015-06-24 15:46:27,633 [DumpsterThread] TRACE com.gwava.message.dao.DeleteDao - Deleting com.gwava.dao.social.Document id=741396, hash=ED0911600088F1648670368D48AB45D1FC34CCC40CFDB255AD2EDA97776294EC
2015-06-24 15:46:27,679 [DumpsterThread] TRACE com.gwava.message.dao.DeleteDao - Deleting com.gwava.dao.social.Document id=741397, hash=2BAF642F5C404DE8CC1A34A7BB6570AF2311DE52BCB9EB67EC8D93B2C2EFF8A3
Then finally the DumpsterThread tells the OS to delete the files from disk:
2015-06-24 15:46:39,757 [DumpsterThread] INFO com.gwava.deletion.ng.DeleteDocuments - Executed query in 12198
2015-06-24 15:46:39,763 [DumpsterThread] INFO com.gwava.deletion.ng.DeleteDocuments - deleteDocumentList:ED0911600088F1648670368D48AB45D1FC34CCC40CFDB255AD2EDA97776294EC 0 741396
2015-06-24 15:46:39,763 [DumpsterThread] INFO com.gwava.deletion.ng.DeleteDocuments - deleteDocumentList:2BAF642F5C404DE8CC1A34A7BB6570AF2311DE52BCB9EB67EC8D93B2C2EFF8A3 0 741397
The deletion job will be over when we see the end statements in the log:
2015-06-24 15:46:55,461 [DumpsterThread] INFO com.gwava.deletion.DumpsterDiver - Dumpster dive completed
2015-06-24 15:46:55,461 [DumpsterThread] DEBUG com.gwava.deletion.DeletionJobFactory - Dumpster Thread ending
At this point the Deletion Management Job is done.
See Also:
Disk Space Not Decreasing Much After Running a Large-Scope Deletion Job
Additional Information
This article was originally published in the GWAVA knowledgebase as article ID 2571.