Log form processing timings; Improve related code quality (getodk#1529)

eganjm · Oct 19, 2017 · d73d536 · d73d536
1 parent cddd425
commit d73d536
Show file tree

Hide file tree

Showing 4 changed files with 224 additions and 206 deletions.
diff --git a/collect_app/src/main/java/org/odk/collect/android/activities/FormEntryActivity.java b/collect_app/src/main/java/org/odk/collect/android/activities/FormEntryActivity.java
@@ -2603,13 +2603,16 @@ public void loadingComplete(FormLoaderTask task) {
                 }
             }
 
-            // if somehow we end up with a bad language, set it to the default
+            long start = System.currentTimeMillis();
+            Timber.i("calling formController.setLanguage");
             try {
                 formController.setLanguage(newLanguage);
             } catch (Exception e) {
+                // if somehow we end up with a bad language, set it to the default
                 Timber.e("Ended up with a bad language. %s", newLanguage);
                 formController.setLanguage(defaultLanguage);
             }
+            Timber.i("Done in %.3f seconds.", (System.currentTimeMillis() - start) / 1000F);
         }
 
         boolean pendingActivityResult = task.hasPendingActivityResult();

diff --git a/collect_app/src/main/java/org/odk/collect/android/tasks/DownloadFormsTask.java b/collect_app/src/main/java/org/odk/collect/android/tasks/DownloadFormsTask.java
@@ -52,6 +52,7 @@
 import java.util.ArrayList;
 import java.util.HashMap;
 import java.util.List;
+import java.util.Map;
 import java.util.zip.GZIPInputStream;
 
 import timber.log.Timber;
@@ -93,7 +94,7 @@ protected HashMap<FormDetails, String> doInBackground(ArrayList<FormDetails>...
         Collect.getInstance().getActivityLogger().logAction(this, "downloadForms",
                 String.valueOf(total));
 
-        HashMap<FormDetails, String> result = new HashMap<FormDetails, String>();
+        final HashMap<FormDetails, String> result = new HashMap<>();
 
         for (FormDetails fd : toDownload) {
             publishProgress(fd.formName, String.valueOf(count), String.valueOf(total));
@@ -149,7 +150,15 @@ protected HashMap<FormDetails, String> doInBackground(ArrayList<FormDetails>...
             }
 
             try {
-                checkForBadSubmissionUrl(fileResult);
+                if (fileResult != null) {
+                    final long start = System.currentTimeMillis();
+                    Timber.i("Starting an extra parse to check for a bad submission URL. %s",
+                            fileResult.file.getAbsolutePath());
+                    // todo can we avoid this extra parse? It can run a long time.
+                    checkForBadSubmissionUrl(fileResult);
+                    Timber.i("Parse finished in %.3f seconds.",
+                            (System.currentTimeMillis() - start) / 1000F);
+                }
             } catch (IllegalArgumentException e) {
                 message += e.getMessage();
             }
@@ -272,8 +281,10 @@ private UriResult findExistingOrCreateNewUri(File formFile) throws TaskCancelled
                 v.put(FormsColumns.FORM_MEDIA_PATH, mediaPath);
 
                 Timber.w("Parsing document %s", formFile.getAbsolutePath());
-
-                HashMap<String, String> formInfo = FileUtils.parseXML(formFile);
+                final long start = System.currentTimeMillis();
+                Map<String, String> formInfo = FileUtils.parseXML(formFile);
+                Timber.i("Parse finished in %.3f seconds.",
+                        (System.currentTimeMillis() - start) / 1000F);
 
                 if (isCancelled()) {
                     throw new TaskCancelledException(formFile, "Form " + formFile.getName()