From 6eb3eef2c0dbd5b6b22bb4e7fa3910c2fa72bb47 Mon Sep 17 00:00:00 2001 From: mitchellsundt Date: Tue, 24 Jan 2012 15:33:24 -0800 Subject: [PATCH] Add progress logging during exports to hopefully catch failures reported by endk.org --- .../aggregate/task/CsvWorkerImpl.java | 16 +++++++++++++++- .../aggregate/task/KmlWorkerImpl.java | 16 +++++++++++++++- 2 files changed, 30 insertions(+), 2 deletions(-) diff --git a/src/main/java/org/opendatakit/aggregate/task/CsvWorkerImpl.java b/src/main/java/org/opendatakit/aggregate/task/CsvWorkerImpl.java index fb2383599a..f5b57fd740 100644 --- a/src/main/java/org/opendatakit/aggregate/task/CsvWorkerImpl.java +++ b/src/main/java/org/opendatakit/aggregate/task/CsvWorkerImpl.java @@ -48,6 +48,7 @@ */ public class CsvWorkerImpl { + private final Log logger = LogFactory.getLog(CsvWorkerImpl.class); private final IForm form; private final SubmissionKey persistentResultsKey; private final Long attemptCount; @@ -65,7 +66,6 @@ public CsvWorkerImpl(IForm form, SubmissionKey persistentResultsKey, Long attemp } public void generateCsv() { - Log logger = LogFactory.getLog(CsvWorkerImpl.class); logger.info("Beginning CSV generation: " + persistentResultsKey.toString() + " form " + form.getFormId()); @@ -96,13 +96,19 @@ public void generateCsv() { query = new QueryByUIFilterGroup(form, filterGroup, CompletionFlag.ONLY_COMPLETE_SUBMISSIONS, cc); formatter = new CsvFormatterWithFilters(form, cc.getServerURL(), pw, filterGroup); + logger.info("after setup of CSV file generation for " + form.getFormId()); formatter.beforeProcessSubmissions(cc); List submissions; + int count = 0; for (;;) { + count++; + logger.info("iteration " + Integer.toString(count) + " before issuing query for " + form.getFormId()); submissions = query.getResultSubmissions(cc); if ( submissions.isEmpty()) break; + logger.info("iteration " + Integer.toString(count) + " before emitting csv for " + form.getFormId()); formatter.processSubmissionSegment(submissions, cc); } + logger.info("wrapping up csv generation for " + form.getFormId()); formatter.afterProcessSubmissions(cc); // output file @@ -112,6 +118,7 @@ public void generateCsv() { // refetch because this might have taken a while... r = new PersistentResults(persistentResultsKey, cc); if (attemptCount.equals(r.getAttemptCount())) { + logger.info("saving csv into PersistentResults table for " + form.getFormId()); r.setResultFile(outputFile, HtmlConsts.RESP_TYPE_CSV, Long.valueOf(outputFile.length), form.getViewableFormNameSuitableAsFileName() + ServletConsts.CSV_FILENAME_APPEND, cc); r.setStatus(ExportStatus.AVAILABLE); @@ -120,6 +127,8 @@ public void generateCsv() { subFilterGroup.delete(cc); } r.persist(cc); + } else { + logger.warn("stale CSV activity - do not save file in PersistentResults table for " + form.getFormId()); } } catch (Exception e) { failureRecovery(e); @@ -130,17 +139,22 @@ private void failureRecovery(Exception e) { // four possible exceptions: // ODKFormNotFoundException, ODKDatastoreException, // ODKIncompleteSubmissionData, Exception + logger.error("Exception caught: " + e.toString() + " for " + form.getFormId()); e.printStackTrace(); try { PersistentResults r = new PersistentResults(persistentResultsKey, cc); if (attemptCount.equals(r.getAttemptCount())) { + logger.info("Exception recovery during CSV generation - mark as failed for " + form.getFormId()); r.deleteResultFile(cc); r.setStatus(ExportStatus.FAILED); r.persist(cc); + } else { + logger.warn("Exception recovery during CSV generation - skipped - not the active attempt! for " + form.getFormId()); } } catch (Exception ex) { // something is hosed -- don't attempt to continue. // watchdog: find this once lastRetryDate is late + logger.error("Exception during exception recovery: " + ex.toString() + " for " + form.getFormId()); } } } diff --git a/src/main/java/org/opendatakit/aggregate/task/KmlWorkerImpl.java b/src/main/java/org/opendatakit/aggregate/task/KmlWorkerImpl.java index c27f5dbac2..821066ab7d 100644 --- a/src/main/java/org/opendatakit/aggregate/task/KmlWorkerImpl.java +++ b/src/main/java/org/opendatakit/aggregate/task/KmlWorkerImpl.java @@ -49,6 +49,7 @@ */ public class KmlWorkerImpl { + private final Log logger = LogFactory.getLog(KmlWorkerImpl.class); private final IForm form; private final SubmissionKey persistentResultsKey; private final Long attemptCount; @@ -70,7 +71,6 @@ public KmlWorkerImpl(IForm form, SubmissionKey persistentResultsKey, long attemp } public void generateKml() { - Log logger = LogFactory.getLog(KmlWorkerImpl.class); logger.info("Beginning KML generation: " + persistentResultsKey.toString() + " form " + form.getFormId()); @@ -103,13 +103,19 @@ public void generateKml() { formatter = new KmlFormatterWithFilters(form, cc.getServerURL(), geopointField, titleField, imageField, pw, filterGroup, cc); + logger.info("after setup of KML file generation for " + form.getFormId()); formatter.beforeProcessSubmissions(cc); List submissions; + int count = 0; for (;;) { + count++; + logger.info("iteration " + Integer.toString(count) + " before issuing query for " + form.getFormId()); submissions = query.getResultSubmissions(cc); if ( submissions.isEmpty()) break; + logger.info("iteration " + Integer.toString(count) + " before emitting kml for " + form.getFormId()); formatter.processSubmissionSegment(submissions, cc); } + logger.info("wrapping up kml generation for " + form.getFormId()); formatter.afterProcessSubmissions(cc); // output file @@ -119,6 +125,7 @@ public void generateKml() { // refetch because this might have taken a while... r = new PersistentResults(persistentResultsKey, cc); if (attemptCount.equals(r.getAttemptCount())) { + logger.info("saving kml into PersistentResults table for " + form.getFormId()); r.setResultFile(outputFile, HtmlConsts.RESP_TYPE_KML, Long.valueOf(outputFile.length), form.getViewableFormNameSuitableAsFileName() + ServletConsts.KML_FILENAME_APPEND, cc); r.setStatus(ExportStatus.AVAILABLE); @@ -127,6 +134,8 @@ public void generateKml() { subFilterGroup.delete(cc); } r.persist(cc); + } else { + logger.warn("stale KML activity - do not save file in PersistentResults table for " + form.getFormId()); } } catch (Exception e) { failureRecovery(e); @@ -136,17 +145,22 @@ public void generateKml() { private void failureRecovery(Exception e) { // three exceptions possible: // ODKFormNotFoundException, ODKDatastoreException, Exception + logger.error("Exception caught: " + e.toString() + " for " + form.getFormId()); e.printStackTrace(); try { PersistentResults r = new PersistentResults(persistentResultsKey, cc); if (attemptCount.equals(r.getAttemptCount())) { + logger.info("Exception recovery during KML generation - mark as failed for " + form.getFormId()); r.deleteResultFile(cc); r.setStatus(ExportStatus.FAILED); r.persist(cc); + } else { + logger.warn("Exception recovery during KML generation - skipped - not the active attempt! for " + form.getFormId()); } } catch (Exception ex) { // something is hosed -- don't attempt to continue. // TODO: watchdog: find this once lastRetryDate is way late? + logger.error("Exception during exception recovery: " + ex.toString() + " for " + form.getFormId()); } }