add more timing logs

TAMULib · Sep 4, 2018 · e4af8ab · e4af8ab
1 parent 6e673f7
commit e4af8ab
Show file tree

Hide file tree

Showing 2 changed files with 22 additions and 1 deletion.
diff --git a/src/main/java/edu/tamu/app/observer/FileObserverRegistry.java b/src/main/java/edu/tamu/app/observer/FileObserverRegistry.java
@@ -45,9 +45,9 @@ public void dismiss(FileListener listener) throws Exception {
         Optional<FileAlterationObserver> observer = fileMonitorManager.getObserver(path);
         if (observer.isPresent()) {
             logger.info("Dismissing listener: " + path);
+            observer.get().destroy();
             beanFactory.destroyBean(listener);
             fileMonitorManager.removeObserver(observer.get());
-            observer.get().destroy();
         } else {
             logger.info("No listener to dismiss: " + path);
         }

diff --git a/src/main/java/edu/tamu/app/service/DocumentFactory.java b/src/main/java/edu/tamu/app/service/DocumentFactory.java
@@ -148,12 +148,29 @@ private Document createStandardDocument(Project project, String documentName) {
         String projectName = project.getName();
         String documentPath = getDocumentPath(projectName, documentName);
         logger.info("Creating standard document at " + documentPath);
+
+        Instant start = Instant.now();
         Document document = documentRepo.create(project, documentName, documentPath, "Open");
+        logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to create new document");
+
+        start = Instant.now();
         document = addMetadataFields(document, project.getName());
+        logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to add metadata to new document");
+
+        start = Instant.now();
         document = applyAuthorities(document, project.getAuthorities());
+        logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to apply authorities to new document");
+
+        start = Instant.now();
         document = documentRepo.update(document);
+        logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to update new document");
+
         project.addDocument(document);
+
+        start = Instant.now();
         projectRepo.update(project);
+        logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to update project");
+
         return document;
     }
 
@@ -164,15 +181,19 @@ private String getDocumentPath(String projectName, String documentName) {
     private Document addMetadataFields(Document document, String projectName) {
         for (MetadataFieldGroup field : projectFactory.getProjectFields(projectName)) {
             logger.info("Adding field " + field.getLabel().getName() + " to document " + document.getName());
+            Instant start = Instant.now();
             document.addField(metadataFieldGroupRepo.create(document, field.getLabel()));
+            logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to create new metadata field group");
         }
         return document;
     }
 
     private Document applyAuthorities(Document document, List<ProjectAuthority> authorities) {
         for (ProjectAuthority authority : authorities) {
             logger.info("Applying authority " + authority.getName() + " to " + document.getName());
+            Instant start = Instant.now();
             document = ((Authority) projectServiceRegistry.getService(authority.getName())).populate(document);
+            logger.info(Duration.between(start, Instant.now()).toMillis() + " milliseconds to apply authority " + authority.getName());
         }
         return document;
     }