Adding more logs

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/controller/RedactionController.java

@@ -51,6 +51,9 @@ public class RedactionController implements RedactionResource {
     @Override
     public AnalyzeResult analyze(@RequestBody AnalyzeRequest analyzeRequest) {
 
+        log.info("Starting redaction analysis...");
+        long startTime = System.currentTimeMillis();
+
         try (PDDocument pdDocument = PDDocument.load(new ByteArrayInputStream(analyzeRequest.getDocument()))) {
             pdDocument.setAllSecurityToBeRemoved(true);
 
@@ -63,6 +66,8 @@ public class RedactionController implements RedactionResource {
                     .getRuleSetId());
 
             log.info("Redaction analysis successful...");
+            log.debug("Finishing redaction analysis took: {}.", System.currentTimeMillis() - startTime);
+
 
             return AnalyzeResult.builder()
                     .sectionGrid(classifiedDoc.getSectionGrid())
@@ -80,12 +85,17 @@ public class RedactionController implements RedactionResource {
 
     public AnnotateResponse annotate(@RequestBody AnnotateRequest annotateRequest) {
 
+        log.info("Starting redaction annotation...");
+        long startTime = System.currentTimeMillis();
+
         try (PDDocument pdDocument = PDDocument.load(new ByteArrayInputStream(annotateRequest.getDocument()))) {
 
             pdDocument.setAllSecurityToBeRemoved(true);
             dictionaryService.updateDictionary(annotateRequest.getRedactionLog().getRuleSetId());
             annotationService.annotate(pdDocument, annotateRequest.getRedactionLog(), annotateRequest.getSectionGrid());
 
+            log.debug("Finishing redaction annotation took: {}.", System.currentTimeMillis() - startTime);
+
             try (ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream()) {
                 pdDocument.save(byteArrayOutputStream);
                 return AnnotateResponse.builder().document(byteArrayOutputStream.toByteArray()).build();
@@ -100,12 +110,17 @@ public class RedactionController implements RedactionResource {
     @Override
     public RedactionResult classify(@RequestBody RedactionRequest pdfSegmentationRequest) {
 
+        log.info("Starting redaction classification...");
+        long startTime = System.currentTimeMillis();
+
         try (PDDocument pdDocument = PDDocument.load(new ByteArrayInputStream(pdfSegmentationRequest.getDocument()))) {
             pdDocument.setAllSecurityToBeRemoved(true);
 
             Document classifiedDoc = pdfSegmentationService.parseDocument(pdDocument);
             pdfVisualisationService.visualizeClassifications(classifiedDoc, pdDocument);
 
+            log.info("Finishing redaction classification took: {}.", System.currentTimeMillis() - startTime);
+
             return convert(pdDocument, classifiedDoc.getPages().size(), pdfSegmentationRequest.getRuleSetId());
 
         } catch (IOException e) {

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/redaction/service/AnnotationService.java

@@ -29,8 +29,10 @@ import com.iqser.red.service.redaction.v1.model.RedactionLogEntry;
 import com.iqser.red.service.redaction.v1.model.SectionGrid;
 import com.iqser.red.service.redaction.v1.model.SectionRectangle;
 
+import lombok.extern.slf4j.Slf4j;
 import lombok.RequiredArgsConstructor;
 
+@Slf4j
 @Service
 @RequiredArgsConstructor
 public class AnnotationService {
@@ -40,6 +42,9 @@ public class AnnotationService {
 
     public void annotate(PDDocument document, RedactionLog redactionLog, SectionGrid sectionGrid) throws IOException {
 
+        log.info("Annotating document...");
+        long startTime = System.currentTimeMillis();
+
         Map<Integer, List<RedactionLogEntry>> redactionLogPerPage = convertRedactionLog(redactionLog);
 
         for (int page = 1; page <= document.getNumberOfPages(); page++) {
@@ -56,6 +61,8 @@ public class AnnotationService {
                 addAnnotations(logEntries, pdPage, page);
             }
         }
+
+        log.info("Finishing document annotation took: {}.", System.currentTimeMillis() - startTime);
     }
 
 

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/redaction/service/DictionaryService.java

@@ -38,6 +38,9 @@ public class DictionaryService {
 
     public void updateDictionary(String ruleSetId) {
 
+        log.info("Updating dictionary...");
+        long startTime = System.currentTimeMillis();
+
         long version = dictionaryClient.getVersion(ruleSetId);
 
         var foundDictionary = dictionariesByRuleSets.get(ruleSetId);
@@ -45,11 +48,16 @@ public class DictionaryService {
         if (foundDictionary == null || version > foundDictionary.getDictionaryVersion()) {
             updateDictionaryEntry(ruleSetId, version);
         }
+
+        log.info("Finishing dictionary update took: {}.", System.currentTimeMillis() - startTime);
     }
 
 
     private void updateDictionaryEntry(String ruleSetId, long version) {
 
+        log.info("Updating dictionary entries...");
+        long startTime = System.currentTimeMillis();
+
         try {
             DictionaryRepresentation dictionaryRepresentation = new DictionaryRepresentation();
 
@@ -82,10 +90,17 @@ public class DictionaryService {
             log.warn("Got some unknown feignException", e);
             throw e;
         }
+
+        log.info("Finishing dictionary entries update took: {}.", System.currentTimeMillis() - startTime);
+
     }
 
 
     public void updateExternalDictionary(Dictionary dictionary, String ruleSetId) {
+
+        log.info("Updating external dictionary...");
+        long startTime = System.currentTimeMillis();
+
         dictionary.getDictionaryModels().forEach(dm -> {
             if (dm.isRecommendation() && !dm.getLocalEntries().isEmpty()) {
                 dictionaryClient.addEntries(dm.getType(), ruleSetId, new ArrayList<>(dm.getLocalEntries()), false);
@@ -95,6 +110,9 @@ public class DictionaryService {
                 }
             }
         });
+
+        log.info("Finishing external dictionary update took: {}.", System.currentTimeMillis() - startTime);
+
     }
 
 

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/redaction/service/EntityRedactionService.java

@@ -51,14 +51,23 @@ public class EntityRedactionService {
 
     public void processDocument(Document classifiedDoc, String ruleSetId, ManualRedactions manualRedactions) {
 
+        log.info("Processing document...");
+        long startTime = System.currentTimeMillis();
+
         dictionaryService.updateDictionary(ruleSetId);
         KieContainer container = droolsExecutionService.updateRules(ruleSetId);
         long rulesVersion = droolsExecutionService.getRulesVersion(ruleSetId);
 
         Dictionary dictionary = dictionaryService.getDeepCopyDictionary(ruleSetId);
 
+        long current = System.currentTimeMillis() - startTime;
+        log.info("Preparing took: {}.", current);
+
         Set<Entity> documentEntities = new HashSet<>(findEntities(classifiedDoc, container, manualRedactions, dictionary, false, null));
 
+        current = System.currentTimeMillis() - startTime - current;
+        log.info("Finding entries took: {}.", current);
+
         if (dictionary.hasLocalEntries()) {
 
             Map<Integer, Set<Entity>> hintsPerSectionNumber = new HashMap<>();
@@ -72,6 +81,9 @@ public class EntityRedactionService {
             Set<Entity> foundByLocal = findEntities(classifiedDoc, container, manualRedactions, dictionary, true, hintsPerSectionNumber);
             EntitySearchUtils.addEntitiesWithHigherRank(documentEntities, foundByLocal, dictionary);
             EntitySearchUtils.removeEntitiesContainedInLarger(documentEntities);
+
+            current = System.currentTimeMillis() - startTime - current;
+            log.info("Adding local dictionary annotations took: {}.", current);
         }
 
         for (Entity entity : documentEntities) {
@@ -90,10 +102,17 @@ public class EntityRedactionService {
             }
         }
 
+        current = System.currentTimeMillis() - startTime - current;
+        log.info("Adding entity position sequence took: {}.", current);
+
         dictionaryService.updateExternalDictionary(dictionary, ruleSetId);
 
         classifiedDoc.setDictionaryVersion(dictionary.getVersion());
         classifiedDoc.setRulesVersion(rulesVersion);
+
+        current = System.currentTimeMillis() - startTime - current;
+        log.info("Adjusting rules set took: {}.", current);
+        log.info("Finishing document processing took: {}.", System.currentTimeMillis() - startTime);
     }
 
 

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/redaction/service/RedactionLogCreatorService.java

@@ -35,7 +35,9 @@ import com.iqser.red.service.redaction.v1.server.tableextraction.model.Cell;
 import com.iqser.red.service.redaction.v1.server.tableextraction.model.Table;
 
 import lombok.RequiredArgsConstructor;
+import lombok.extern.slf4j.Slf4j;
 
+@Slf4j
 @Service
 @RequiredArgsConstructor
 public class RedactionLogCreatorService {
@@ -48,6 +50,9 @@ public class RedactionLogCreatorService {
     public void createRedactionLog(Document classifiedDoc, int numberOfPages, ManualRedactions manualRedactions,
                                    String ruleSetId) {
 
+        log.info("Creating redaction log...");
+        long startTime = System.currentTimeMillis();
+
         Set<Integer> manualRedactionPages = getManualRedactionPages(manualRedactions);
 
         for (int page = 1; page <= numberOfPages; page++) {
@@ -58,14 +63,26 @@ public class RedactionLogCreatorService {
                 addEntries(classifiedDoc, manualRedactions, page, ruleSetId);
             }
 
+            long current = System.currentTimeMillis() - startTime;
+            log.info("Adding entries took: {}.", current);
+
             if (manualRedactionPages.contains(page)) {
                 addManualEntries(classifiedDoc, manualRedactions, page, ruleSetId);
             }
 
+            current = System.currentTimeMillis() - startTime - current;
+            log.info("Adding manual entries took: {}.", current);
+
             if (!classifiedDoc.getPages().get(page - 1).getImageBounds().isEmpty()) {
                 addImageEntries(classifiedDoc, page, ruleSetId);
             }
+
+            current = System.currentTimeMillis() - startTime - current;
+            log.info("Adding image entries took: {}.", current);
         }
+
+        log.info("Finishing redaction log creation took: {}.", System.currentTimeMillis() - startTime);
+
     }
 
 

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/segmentation/PdfSegmentationService.java

@@ -39,6 +39,9 @@ public class PdfSegmentationService {
 
     public Document parseDocument(PDDocument pdDocument) throws IOException {
 
+        log.info("Parsing document...");
+        long startTime = System.currentTimeMillis();
+
         Document document = new Document();
 
         List<Page> pages = new ArrayList<>();
@@ -91,6 +94,8 @@ public class PdfSegmentationService {
 
         sectionsBuilderService.buildSections(document);
 
+        log.info("Finishing document parsing took: {}.", System.currentTimeMillis() - startTime);
+
         return document;
     }
 

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/segmentation/SectionsBuilderService.java

@@ -20,11 +20,17 @@ import com.iqser.red.service.redaction.v1.server.tableextraction.model.AbstractT
 import com.iqser.red.service.redaction.v1.server.tableextraction.model.Cell;
 import com.iqser.red.service.redaction.v1.server.tableextraction.model.Table;
 
+import lombok.extern.slf4j.Slf4j;
+
+@Slf4j
 @Service
 public class SectionsBuilderService {
 
     public void buildSections(Document document) {
 
+        log.debug("Building sections...");
+        long startTime = System.currentTimeMillis();
+
         List<AbstractTextContainer> chunkWords = new ArrayList<>();
         List<Paragraph> chunkBlockList = new ArrayList<>();
         List<Header> headers = new ArrayList<>();
@@ -97,6 +103,9 @@ public class SectionsBuilderService {
         document.setHeaders(headers);
         document.setFooters(footers);
         document.setUnclassifiedTexts(unclassifiedTexts);
+
+        log.debug("Finishing section building took: {}.", System.currentTimeMillis() - startTime);
+
     }
 
 

redaction-service-v1/redaction-service-server-v1/src/main/java/com/iqser/red/service/redaction/v1/server/tableextraction/service/TableExtractionService.java

@@ -23,11 +23,17 @@ import com.iqser.red.service.redaction.v1.server.tableextraction.model.Ruling;
 import com.iqser.red.service.redaction.v1.server.tableextraction.model.Table;
 import com.iqser.red.service.redaction.v1.server.tableextraction.utils.Utils;
 
+import lombok.extern.slf4j.Slf4j;
+
+@Slf4j
 @Service
 public class TableExtractionService {
 
     public void extractTables(CleanRulings cleanRulings, Page page) {
 
+        log.debug("Extracting tables...");
+        long startTime = System.currentTimeMillis();
+
         List<Cell> cells = findCells(cleanRulings.getHorizontal(), cleanRulings.getVertical());
 
         List<TextBlock> toBeRemoved = new ArrayList<>();
@@ -78,6 +84,9 @@ public class TableExtractionService {
         }
 
         page.getTextBlocks().removeAll(toBeRemoved);
+
+        log.debug("Finishing table extraction took: {}.", System.currentTimeMillis() - startTime);
+
     }