Optimize logging by creating a debug flag (#1054)

* Optimize debug to reduce array allocation due to var-args

* Optimize logging by creating a debug flag

README.md

@@ -510,6 +510,7 @@ The following is sample output from the Hierarchical format.
 | `locale`                       | The locale to use for generating messages in the `ValidationMessage`. Note that this value is copied from `SchemaValidatorsConfig` for each execution.                                                                            | `Locale.getDefault()`
 | `failFast`                     | Whether to return failure immediately when an assertion is generated. Note that this value is copied from `SchemaValidatorsConfig` for each execution but is automatically set to `true` for the Boolean and Flag output formats. | `false`
 | `formatAssertionsEnabled`      | The default is to generate format assertions from Draft 4 to Draft 7 and to only generate annotations from Draft 2019-09. Setting to `true` or `false` will override the default behavior.                                        | `null`
+| `debugEnabled`                 | Controls whether debug logging is enabled for logging the node information when processing. Note that this will generate a lot of logs that will affect performance.                                                              | `false`
 
 ### Schema Validators Configuration
 

src/main/java/com/networknt/schema/AdditionalPropertiesValidator.java

@@ -88,7 +88,7 @@ public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNo
 
     protected Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation, boolean walk) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         if (!node.isObject()) {
             // ignore no object
             return Collections.emptySet();

src/main/java/com/networknt/schema/AllOfValidator.java

@@ -56,7 +56,7 @@ public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNo
     }
 
     protected Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation, boolean walk) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         SetView<ValidationMessage> childSchemaErrors = null;
 

src/main/java/com/networknt/schema/AnyOfValidator.java

@@ -60,7 +60,7 @@ public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNo
 
     protected Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation, boolean walk) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (this.validationContext.getConfig().isOpenAPI3StyleDiscriminators()) {
             executionContext.enterDiscriminatorContext(new DiscriminatorContext(), instanceLocation);

src/main/java/com/networknt/schema/BaseJsonValidator.java

@@ -96,8 +96,23 @@ protected static boolean equals(double n1, double n2) {
         return Math.abs(n1 - n2) < 1e-12;
     }
 
-    protected static void debug(Logger logger, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        logger.debug("validate( {}, {}, {})", node, rootNode, instanceLocation);
+    public static void debug(Logger logger, ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
+            JsonNodePath instanceLocation) {
+        //logger.debug("validate( {}, {}, {})", node, rootNode, instanceLocation);
+        // The below is equivalent to the above but as there are more than 2 arguments
+        // the var-arg method is used and an array needs to be allocated even if debug
+        // is not enabled
+        if (executionContext.getExecutionConfig().isDebugEnabled() && logger.isDebugEnabled()) {
+            StringBuilder builder = new StringBuilder();
+            builder.append("validate( ");
+            builder.append(node.toString());
+            builder.append(", ");
+            builder.append(rootNode.toString());
+            builder.append(", ");
+            builder.append(instanceLocation.toString());
+            builder.append(")");
+            logger.debug(builder.toString());
+        }
     }
 
     /**

src/main/java/com/networknt/schema/ConstValidator.java

@@ -34,7 +34,7 @@ public ConstValidator(SchemaLocation schemaLocation, JsonNodePath evaluationPath
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (schemaNode.isNumber() && node.isNumber()) {
             if (schemaNode.decimalValue().compareTo(node.decimalValue()) != 0) {

src/main/java/com/networknt/schema/ContainsValidator.java

@@ -72,7 +72,7 @@ public ContainsValidator(SchemaLocation schemaLocation, JsonNodePath evaluationP
 
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         // ignores non-arrays
         Set<ValidationMessage> results = null;

src/main/java/com/networknt/schema/ContentEncodingValidator.java

@@ -66,7 +66,7 @@ private boolean matches(String value) {
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         // Ignore non-strings
         JsonType nodeType = TypeFactory.getValueNodeType(node, this.validationContext.getConfig());

src/main/java/com/networknt/schema/ContentMediaTypeValidator.java

@@ -90,7 +90,7 @@ else if (!PATTERN.matcher(this.contentMediaType).matches()) {
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         // Ignore non-strings
         JsonType nodeType = TypeFactory.getValueNodeType(node, this.validationContext.getConfig());

src/main/java/com/networknt/schema/DependenciesValidator.java

@@ -63,7 +63,7 @@ public DependenciesValidator(SchemaLocation schemaLocation, JsonNodePath evaluat
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         Set<ValidationMessage> errors = null;
 

src/main/java/com/networknt/schema/DependentRequired.java

@@ -47,7 +47,7 @@ public DependentRequired(SchemaLocation schemaLocation, JsonNodePath evaluationP
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         Set<ValidationMessage> errors = new LinkedHashSet<ValidationMessage>();
 

src/main/java/com/networknt/schema/DependentSchemas.java

@@ -51,7 +51,7 @@ public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNo
 
     protected Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation, boolean walk) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         Set<ValidationMessage> errors = null;
         for (Iterator<String> it = node.fieldNames(); it.hasNext(); ) {

src/main/java/com/networknt/schema/DynamicRefValidator.java

@@ -93,7 +93,7 @@ private static String resolve(JsonSchema parentSchema, String refValue) {
 
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         JsonSchema refSchema = this.schema.getSchema();
         if (refSchema == null) {
             ValidationMessage validationMessage = message().type(ValidatorTypeCode.DYNAMIC_REF.getValue())
@@ -107,7 +107,7 @@ public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNo
 
     @Override
     public Set<ValidationMessage> walk(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation, boolean shouldValidateSchema) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         // This is important because if we use same JsonSchemaFactory for creating multiple JSONSchema instances,
         // these schemas will be cached along with config. We have to replace the config for cached $ref references
         // with the latest config. Reset the config.

src/main/java/com/networknt/schema/EnumValidator.java

@@ -82,7 +82,7 @@ public EnumValidator(SchemaLocation schemaLocation, JsonNodePath evaluationPath,
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (node.isNumber()) {
             node = processNumberNode(node);

src/main/java/com/networknt/schema/ExclusiveMaximumValidator.java

@@ -98,7 +98,7 @@ public String thresholdValue() {
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (!JsonNodeUtil.isNumber(node, validationContext.getConfig())) {
             // maximum only applies to numbers

src/main/java/com/networknt/schema/ExclusiveMinimumValidator.java

@@ -105,7 +105,7 @@ public String thresholdValue() {
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (!JsonNodeUtil.isNumber(node, this.validationContext.getConfig())) {
             // minimum only applies to numbers

src/main/java/com/networknt/schema/ExecutionConfig.java

@@ -54,7 +54,16 @@ public class ExecutionConfig {
      * Determine if the validation execution can fail fast.
      */
     private boolean failFast = false;
-
+
+    /**
+     * Determine if debugging features such that logging are switched on.
+     * <p>
+     * This is turned off by default. This is present because the library attempts
+     * to log debug logs at each validation node and the logger evaluation on
+     * whether the logger is turned on is impacting performance.
+     */
+    private boolean debugEnabled = false;
+
     /**
      * Gets the locale to use for formatting messages.
      * 
@@ -180,4 +189,21 @@ public void setAnnotationCollectionFilter(Predicate<String> annotationCollection
                 "annotationCollectionFilter must not be null");
     }
 
+    /**
+     * Gets if debugging features such as logging is switched on.
+     *
+     * @return true if debug is enabled
+     */
+    public boolean isDebugEnabled() {
+        return debugEnabled;
+    }
+
+    /**
+     * Sets if debugging features such as logging is switched on.
+     *
+     * @param debugEnabled true to enable debug
+     */
+    public void setDebugEnabled(boolean debugEnabled) {
+        this.debugEnabled = debugEnabled;
+    }
 }

src/main/java/com/networknt/schema/FalseValidator.java

@@ -36,7 +36,7 @@ public FalseValidator(SchemaLocation schemaLocation, JsonNodePath evaluationPath
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         // For the false validator, it is always not valid
         return Collections.singleton(message().instanceNode(node).instanceLocation(instanceLocation)
                 .locale(executionContext.getExecutionConfig().getLocale())

src/main/java/com/networknt/schema/FormatValidator.java

@@ -59,7 +59,7 @@ protected Object getAnnotationValue() {
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         /*
          * Annotations must be collected even if the format is unknown according to the specification.
          */

src/main/java/com/networknt/schema/IfValidator.java

@@ -65,7 +65,7 @@ public IfValidator(SchemaLocation schemaLocation, JsonNodePath evaluationPath, J
 
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         boolean ifConditionPassed = false;
 

src/main/java/com/networknt/schema/ItemsValidator.java

@@ -87,7 +87,7 @@ public ItemsValidator(SchemaLocation schemaLocation, JsonNodePath evaluationPath
 
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (!node.isArray() && !this.validationContext.getConfig().isTypeLoose()) {
             // ignores non-arrays

src/main/java/com/networknt/schema/ItemsValidator202012.java

@@ -65,7 +65,7 @@ public ItemsValidator202012(SchemaLocation schemaLocation, JsonNodePath evaluati
     @Override
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         // ignores non-arrays
         if (node.isArray()) {

src/main/java/com/networknt/schema/MaxItemsValidator.java

@@ -40,7 +40,7 @@ public MaxItemsValidator(SchemaLocation schemaLocation, JsonNodePath evaluationP
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (node.isArray()) {
             if (node.size() > max) {

src/main/java/com/networknt/schema/MaxLengthValidator.java

@@ -40,7 +40,7 @@ public MaxLengthValidator(SchemaLocation schemaLocation, JsonNodePath evaluation
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         JsonType nodeType = TypeFactory.getValueNodeType(node, this.validationContext.getConfig());
         if (nodeType != JsonType.STRING) {

src/main/java/com/networknt/schema/MaxPropertiesValidator.java

@@ -42,7 +42,7 @@ public MaxPropertiesValidator(SchemaLocation schemaLocation, JsonNodePath evalua
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (node.isObject()) {
             if (node.size() > max) {

src/main/java/com/networknt/schema/MaximumValidator.java

@@ -108,7 +108,7 @@ public String thresholdValue() {
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (!JsonNodeUtil.isNumber(node, this.validationContext.getConfig())) {
             // maximum only applies to numbers

src/main/java/com/networknt/schema/MinItemsValidator.java

@@ -39,7 +39,7 @@ public MinItemsValidator(SchemaLocation schemaLocation, JsonNodePath evaluationP
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (node.isArray()) {
             if (node.size() < min) {

src/main/java/com/networknt/schema/MinLengthValidator.java

@@ -40,7 +40,7 @@ public MinLengthValidator(SchemaLocation schemaLocation, JsonNodePath evaluation
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         JsonType nodeType = TypeFactory.getValueNodeType(node, this.validationContext.getConfig());
         if (nodeType != JsonType.STRING) {

src/main/java/com/networknt/schema/MinPropertiesValidator.java

@@ -42,7 +42,7 @@ public MinPropertiesValidator(SchemaLocation schemaLocation, JsonNodePath evalua
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (node.isObject()) {
             if (node.size() < min) {

src/main/java/com/networknt/schema/MinimumValidator.java

@@ -115,7 +115,7 @@ public String thresholdValue() {
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         if (!JsonNodeUtil.isNumber(node, this.validationContext.getConfig())) {
             // minimum only applies to numbers

src/main/java/com/networknt/schema/MultipleOfValidator.java

@@ -42,7 +42,7 @@ public MultipleOfValidator(SchemaLocation schemaLocation, JsonNodePath evaluatio
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         if (this.divisor != null) {
             BigDecimal dividend = getDividend(node);
             if (dividend != null) {

src/main/java/com/networknt/schema/NotAllowedValidator.java

@@ -41,7 +41,7 @@ public NotAllowedValidator(SchemaLocation schemaLocation, JsonNodePath evaluatio
     }
 
     public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode, JsonNodePath instanceLocation) {
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         Set<ValidationMessage> errors = null;
 

src/main/java/com/networknt/schema/NotValidator.java

@@ -45,7 +45,7 @@ public Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNo
     protected Set<ValidationMessage> validate(ExecutionContext executionContext, JsonNode node, JsonNode rootNode,
             JsonNodePath instanceLocation, boolean walk) {
         Set<ValidationMessage> errors = null;
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
 
         // Save flag as nested schema evaluation shouldn't trigger fail fast
         boolean failFast = executionContext.isFailFast();

src/main/java/com/networknt/schema/OneOfValidator.java

@@ -61,7 +61,7 @@ protected Set<ValidationMessage> validate(ExecutionContext executionContext, Jso
             JsonNodePath instanceLocation, boolean walk) {
         Set<ValidationMessage> errors = null;
 
-        debug(logger, node, rootNode, instanceLocation);
+        debug(logger, executionContext, node, rootNode, instanceLocation);
         int numberOfValidSchema = 0;
         int index = 0;
         SetView<ValidationMessage> childErrors = null;