From 4e30cd7849b9bdef12c8b3369c11a6396f083643 Mon Sep 17 00:00:00 2001
From: Grahame Grieve <grahameg@gmail.com>
Date: Sun, 16 Aug 2020 06:48:33 +1000
Subject: [PATCH] Add logging for value set validation performance

---
 .../instance/InstanceValidator.java           |  2 +-
 .../instance/type/ValueSetValidator.java      | 23 ++++++++++++++-----
 2 files changed, 18 insertions(+), 7 deletions(-)

diff --git a/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/InstanceValidator.java b/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/InstanceValidator.java
index 2469011ad..93de432bc 100644
--- a/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/InstanceValidator.java
+++ b/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/InstanceValidator.java
@@ -3645,7 +3645,7 @@ public class InstanceValidator extends BaseValidator implements IResourceValidat
     } else if (element.getType().equals("StructureDefinition")) {
       new StructureDefinitionValidator(context, timeTracker, fpe).validateStructureDefinition(errors, element, stack);
     } else if (element.getType().equals("ValueSet")) {
-      new ValueSetValidator(context, timeTracker).validateValueSet(errors, element, stack);
+      new ValueSetValidator(context, timeTracker, this).validateValueSet(errors, element, stack);
     }
   }
 
diff --git a/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/type/ValueSetValidator.java b/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/type/ValueSetValidator.java
index 8e284a902..354de77e1 100644
--- a/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/type/ValueSetValidator.java
+++ b/org.hl7.fhir.validation/src/main/java/org/hl7/fhir/validation/instance/type/ValueSetValidator.java
@@ -21,6 +21,7 @@ import org.hl7.fhir.utilities.validation.ValidationMessage.Source;
 import org.hl7.fhir.utilities.validation.ValidationOptions;
 import org.hl7.fhir.validation.BaseValidator;
 import org.hl7.fhir.validation.TimeTracker;
+import org.hl7.fhir.validation.instance.InstanceValidator;
 import org.hl7.fhir.validation.instance.type.ValueSetValidator.VSCodingValidationRequest;
 import org.hl7.fhir.validation.instance.utils.NodeStack;
 
@@ -41,10 +42,13 @@ public class ValueSetValidator extends BaseValidator {
     
   }
 
-  public ValueSetValidator(IWorkerContext context, TimeTracker timeTracker) {
+  private InstanceValidator parent;
+
+  public ValueSetValidator(IWorkerContext context, TimeTracker timeTracker, InstanceValidator parent) {
     super(context);
     source = Source.InstanceValidator;
     this.timeTracker = timeTracker;
+    this.parent = parent;
   }
   
   public void validateValueSet(List<ValidationMessage> errors, Element vs, NodeStack stack) {
@@ -52,28 +56,28 @@ public class ValueSetValidator extends BaseValidator {
       List<Element> composes = vs.getChildrenByName("compose");
       int cc = 0;
       for (Element compose : composes) {
-        validateValueSetCompose(errors, compose, stack.push(compose, cc, null, null));
+        validateValueSetCompose(errors, compose, stack.push(compose, cc, null, null), vs.getNamedChildValue("url"));
         cc++;
       }
     }
   }
 
-  private void validateValueSetCompose(List<ValidationMessage> errors, Element compose, NodeStack stack) {
+  private void validateValueSetCompose(List<ValidationMessage> errors, Element compose, NodeStack stack, String vsid) {
     List<Element> includes = compose.getChildrenByName("include");
     int ci = 0;
     for (Element include : includes) {
-      validateValueSetInclude(errors, include, stack.push(include, ci, null, null));
+      validateValueSetInclude(errors, include, stack.push(include, ci, null, null), vsid);
       ci++;
     }    
     List<Element> excludes = compose.getChildrenByName("exclude");
     int ce = 0;
     for (Element exclude : excludes) {
-      validateValueSetInclude(errors, exclude, stack.push(exclude, ce, null, null));
+      validateValueSetInclude(errors, exclude, stack.push(exclude, ce, null, null), vsid);
       ce++;
     }    
   }
   
-  private void validateValueSetInclude(List<ValidationMessage> errors, Element include, NodeStack stack) {
+  private void validateValueSetInclude(List<ValidationMessage> errors, Element include, NodeStack stack, String vsid) {
     String system = include.getChildValue("system");
     String version = include.getChildValue("version");
     List<Element> valuesets = include.getChildrenByName("valueSet");
@@ -111,7 +115,14 @@ public class ValueSetValidator extends BaseValidator {
         cc++;
       }    
       if (batch.size() > 0) {
+        long t = System.currentTimeMillis();
+        if (parent.isDebug()) {
+          System.out.println("  : Validate "+batch.size()+" codes from "+system+" for "+vsid);
+        }
         context.validateCodeBatch(ValidationOptions.defaults(), batch, null);
+        if (parent.isDebug()) {
+          System.out.println("  :   .. "+(System.currentTimeMillis()-t)+"ms");
+        }
         for (VSCodingValidationRequest cv : batch) {
           if (version == null) {
             warning(errors, IssueType.BUSINESSRULE, cv.getStack().getLiteralPath(), cv.getResult().isOk(), I18nConstants.VALUESET_INCLUDE_INVALID_CONCEPT_CODE, system, cv.getCoding().getCode());