Merge branch 'master' into CIRC-1885

src/main/java/org/folio/circulation/CirculationVerticle.java

@@ -73,7 +73,9 @@ public void start(Promise<Void> startFuture) {
 
     this.server = vertx.createHttpServer();
 
-    router.route().handler(rc -> LogHelper.logRequest(rc, log));
+    router.route()
+      .handler(LogHelper::populateLoggingContext)
+      .handler(rc -> LogHelper.logRequest(rc, log));
 
     new HealthResource().register(router);
     new TenantActivationResource().register(router);

src/main/java/org/folio/circulation/rules/AppliedRuleConditions.java

@@ -9,7 +9,7 @@ public class AppliedRuleConditions {
   boolean isPatronGroupPresent;
 
   public AppliedRuleConditions(boolean isItemTypePresent,
-                               boolean isLoanTypePresent, boolean isPatronGroupPresent) {
+    boolean isLoanTypePresent, boolean isPatronGroupPresent) {
 
     this.isItemTypePresent = isItemTypePresent;
     this.isLoanTypePresent = isLoanTypePresent;

src/main/java/org/folio/circulation/rules/CirculationRuleMatch.java

@@ -6,7 +6,7 @@ public class CirculationRuleMatch {
   private final AppliedRuleConditions appliedRuleConditions;
 
   public CirculationRuleMatch(String policyId,
-                              AppliedRuleConditions appliedRuleConditions) {
+    AppliedRuleConditions appliedRuleConditions) {
 
     this.policyId = policyId;
     this.appliedRuleConditions = appliedRuleConditions;

src/main/java/org/folio/circulation/rules/CirculationRulesProcessor.java

@@ -38,54 +38,74 @@ public CirculationRulesProcessor(String tenantId, CollectionResourceClient circu
   public CompletableFuture<Result<CirculationRuleMatch>> getLoanPolicyAndMatch(
     RulesExecutionParameters params) {
 
+    log.debug("getLoanPolicyAndMatch:: parameters params: {}", params);
+
     return executeRules(params, ExecutableRules::determineLoanPolicy);
   }
 
   public CompletableFuture<Result<JsonArray>> getLoanPolicies(RulesExecutionParameters params) {
+    log.debug("getLoanPolicies:: parameters params: {}", params);
+
     return triggerRules(params,
       (drools, newParams) -> drools.loanPolicies(newParams.toMap(), newParams.getLocation()));
   }
 
   public CompletableFuture<Result<CirculationRuleMatch>> getLostItemPolicyAndMatch(
     RulesExecutionParameters params) {
 
+    log.debug("getLostItemPolicyAndMatch:: parameters params: {}", params);
+
     return executeRules(params, ExecutableRules::determineLostItemPolicy);
   }
 
   public CompletableFuture<Result<JsonArray>> getLostItemPolicies(RulesExecutionParameters params) {
+    log.debug("getLostItemPolicies:: parameters params: {}", params);
+
     return triggerRules(params,
       (drools, newParams) -> drools.lostItemPolicies(newParams.toMap(), newParams.getLocation()));
   }
 
   public CompletableFuture<Result<CirculationRuleMatch>> getNoticePolicyAndMatch(
     RulesExecutionParameters params) {
 
+    log.debug("getNoticePolicyAndMatch:: parameters params: {}", params);
+
     return executeRules(params, ExecutableRules::determineNoticePolicy);
   }
 
   public CompletableFuture<Result<JsonArray>> getNoticePolicies(RulesExecutionParameters params) {
+    log.debug("getNoticePolicies:: parameters params: {}", params);
+
     return triggerRules(params,
       (drools, newParams) -> drools.noticePolicies(newParams.toMap(), newParams.getLocation()));
   }
 
   public CompletableFuture<Result<CirculationRuleMatch>> getOverduePolicyAndMatch(
     RulesExecutionParameters params) {
 
+    log.debug("getOverduePolicyAndMatch:: parameters params: {}", params);
+
     return executeRules(params, ExecutableRules::determineOverduePolicy);
   }
 
   public CompletableFuture<Result<JsonArray>> getOverduePolicies(RulesExecutionParameters params) {
+    log.debug("getOverduePolicies:: parameters params: {}", params);
+
     return triggerRules(params,
       (drools, newParams) -> drools.overduePolicies(newParams.toMap(), newParams.getLocation()));
   }
 
   public CompletableFuture<Result<CirculationRuleMatch>> getRequestPolicyAndMatch(
     RulesExecutionParameters params) {
 
+    log.debug("getRequestPolicyAndMatch:: parameters params: {}", params);
+
     return executeRules(params, ExecutableRules::determineRequestPolicy);
   }
 
   public CompletableFuture<Result<JsonArray>> getRequestPolicies(RulesExecutionParameters params) {
+    log.debug("getRequestPolicies:: parameters params: {}", params);
+
     return triggerRules(params,
       (drools, newParams) -> drools.requestPolicies(newParams.toMap(), newParams.getLocation()));
   }
@@ -114,8 +134,13 @@ private <T> CompletableFuture<Result<T>> executeRules(RulesExecutionParameters p
         rulesExecutor.apply(rules, parametersWithLocation)));
   }
 
-  private CompletableFuture<Result<RulesExecutionParameters>> fetchLocation(RulesExecutionParameters params) {
+  private CompletableFuture<Result<RulesExecutionParameters>> fetchLocation(
+    RulesExecutionParameters params) {
+
+    log.debug("fetchLocation:: parameters params: {}", params);
+
     if (params.getLocation() != null) {
+      log.info("fetchLocation:: location is not null");
       return ofAsync(() -> params);
     }
 

src/main/java/org/folio/circulation/rules/Drools.java

@@ -5,11 +5,14 @@
 import static org.folio.circulation.resources.AbstractCirculationRulesEngineResource.LOCATION_ID_NAME;
 import static org.folio.circulation.resources.AbstractCirculationRulesEngineResource.PATRON_TYPE_ID_NAME;
 import static org.folio.circulation.support.json.JsonPropertyWriter.write;
+import static org.folio.circulation.support.utils.LogUtil.asJson;
 
 import java.util.Collections;
 import java.util.Set;
 import java.util.stream.Collectors;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.drools.core.definitions.rule.impl.RuleImpl;
 import org.drools.core.event.DefaultAgendaEventListener;
 import org.folio.circulation.domain.Location;
@@ -33,6 +36,7 @@ public class Drools {
   // https://docs.jboss.org/drools/release/6.2.0.CR1/drools-docs/html/ch19.html
   // http://www.deepakgaikwad.net/index.php/2016/05/16/drools-tutorial-beginners.html
 
+  private static final Logger log = LogManager.getLogger(CirculationRulesProcessor.class);
   private final KieContainer kieContainer;
 
   /**
@@ -59,6 +63,8 @@ public Drools(String tenantId, String drools) {
   }
 
   private KieSession createSession(MultiMap params, Location location, Match match) {
+    log.debug("createSession:: parameters params: {}, location: {}, match: {}", params.size(),
+      location, match);
     String itemTypeId = params.get(ITEM_TYPE_ID_NAME);
     String loanTypeId = params.get(LOAN_TYPE_ID_NAME);
     String patronGroupId = params.get(PATRON_TYPE_ID_NAME);
@@ -71,6 +77,7 @@ private KieSession createSession(MultiMap params, Location location, Match match
     kieSession.insert(new PatronGroup(patronGroupId));
     kieSession.insert(new ItemLocation(locationId));
     if (location != null) {
+      log.info("createSession:: location is not null");
       kieSession.insert(new Institution(location.getInstitutionId()));
       kieSession.insert(new Campus(location.getCampusId()));
       kieSession.insert(new Library(location.getLibraryId()));
@@ -86,6 +93,7 @@ private KieSession createSession(MultiMap params, Location location, Match match
    * @return CirculationRuleMatch object with the name of the loan policy and rule conditions
    */
   public CirculationRuleMatch loanPolicy(MultiMap params, Location location) {
+    log.debug("loanPolicy:: params params: {}, location: {}", params.size(), location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
     final RuleEventListener ruleEventListener = new RuleEventListener();
@@ -110,6 +118,7 @@ public CirculationRuleMatch loanPolicy(MultiMap params, Location location) {
    * @return matches, each match has a loanPolicyId and a circulationRuleLine field
    */
   public JsonArray loanPolicies(MultiMap params, Location location) {
+    log.debug("loanPolicies:: params params: {}, location: {}", params.size(), location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -125,6 +134,7 @@ public JsonArray loanPolicies(MultiMap params, Location location) {
     }
 
     kieSession.dispose();
+    log.info("loanPolicies:: result: {}", () -> asJson(array.stream().toList()));
     return array;
   }
 
@@ -135,6 +145,7 @@ public JsonArray loanPolicies(MultiMap params, Location location) {
    * @return CirculationRuleMatch object with the name of the loan policy and rule conditions
    */
   public CirculationRuleMatch requestPolicy(MultiMap params, Location location) {
+    log.debug("requestPolicy:: parameters params: {}, location: {}", params, location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -153,6 +164,8 @@ public CirculationRuleMatch requestPolicy(MultiMap params, Location location) {
    * @return matches, each match has a requestPolicyId and a circulationRuleLine field
    */
   public JsonArray requestPolicies(MultiMap params, Location location) {
+    log.debug("requestPolicy:: parameters params: {}, location: {}", params, location);
+
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -169,6 +182,7 @@ public JsonArray requestPolicies(MultiMap params, Location location) {
 
     kieSession.dispose();
 
+    log.info("requestPolicies:: result: {}", () -> asJson(array.stream().toList()));
     return array;
   }
 
@@ -179,6 +193,7 @@ public JsonArray requestPolicies(MultiMap params, Location location) {
    * @return CirculationRuleMatch object with the name of the loan policy and rule conditions
    */
   public CirculationRuleMatch noticePolicy(MultiMap params, Location location) {
+    log.debug("noticePolicy:: parameters params: {}, location: {}", params.size(), location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -197,6 +212,7 @@ public CirculationRuleMatch noticePolicy(MultiMap params, Location location) {
    * @return matches, each match has a noticePolicyId and a circulationRuleLine field
    */
   public JsonArray noticePolicies(MultiMap params, Location location) {
+    log.debug("noticePolicies:: parameters params: {}, location: {}", params.size(), location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -212,6 +228,7 @@ public JsonArray noticePolicies(MultiMap params, Location location) {
     }
 
     kieSession.dispose();
+    log.info("noticePolicies:: result: {}", () -> asJson(array.stream().toList()));
 
     return array;
   }
@@ -223,6 +240,7 @@ public JsonArray noticePolicies(MultiMap params, Location location) {
    * @return CirculationRuleMatch object with the name of the loan policy and rule conditions
    */
   public CirculationRuleMatch overduePolicy(MultiMap params, Location location) {
+    log.debug("overduePolicy:: parameters params: {}, location: {}", params, location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -241,6 +259,7 @@ public CirculationRuleMatch overduePolicy(MultiMap params, Location location) {
    * @return matches, each match has a overduePolicyId and a circulationRuleLine field
    */
   public JsonArray overduePolicies(MultiMap params, Location location) {
+    log.debug("overduePolicies:: parameters params: {}, location: {}", params, location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -256,6 +275,8 @@ public JsonArray overduePolicies(MultiMap params, Location location) {
     }
 
     kieSession.dispose();
+    log.info("overduePolicies:: result: {}", () -> asJson(array.stream().toList()));
+
     return array;
   }
 
@@ -266,6 +287,8 @@ public JsonArray overduePolicies(MultiMap params, Location location) {
    * @return CirculationRuleMatch object with the name of the loan policy and rule conditions
    */
   public CirculationRuleMatch lostItemPolicy(MultiMap params, Location location) {
+    log.debug("lostItemPolicy:: parameters params: {}, location: {}", params, location);
+
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -284,6 +307,7 @@ public CirculationRuleMatch lostItemPolicy(MultiMap params, Location location) {
    * @return matches, each match has a lostItemPolicyId and a circulationRuleLine field
    */
   public JsonArray lostItemPolicies(MultiMap params, Location location) {
+    log.debug("lostItemPolicies:: parameters params: {}, location: {}", params, location);
     final var match = new Match();
     final KieSession kieSession = createSession(params, location, match);
 
@@ -299,6 +323,7 @@ public JsonArray lostItemPolicies(MultiMap params, Location location) {
     }
 
     kieSession.dispose();
+    log.info("lostItemPolicies:: result: {}", () -> asJson(array.stream().toList()));
     return array;
   }
 
@@ -346,6 +371,7 @@ public void afterMatchFired(AfterMatchFiredEvent event) {
       RuleImpl rule = (RuleImpl) event.getMatch().getRule();
 
       if (rule.getLhs() != null && rule.getLhs().getChildren() != null) {
+        log.info("afterMatchFired:: getting rule conditions");
         ruleConditionElements = rule.getLhs().getChildren().stream()
           .map(Object::toString)
           .map(this::getRuleConditionFromStringRuleRepresentation)

src/main/java/org/folio/circulation/rules/ExecutableRules.java

@@ -31,22 +31,32 @@ public ExecutableRules(String text, Drools drools) {
   }
 
   public Result<CirculationRuleMatch> determineLoanPolicy(RulesExecutionParameters parameters) {
+    log.debug("determineLoanPolicy:: parameters parameters: {}", parameters);
+
     return determinePolicy(parameters, drools::loanPolicy, "loan policy");
   }
 
   public Result<CirculationRuleMatch> determineRequestPolicy(RulesExecutionParameters parameters) {
+    log.debug("determineRequestPolicy:: parameters parameters: {}", parameters);
+
     return determinePolicy(parameters, drools::requestPolicy, "request policy");
   }
 
   public Result<CirculationRuleMatch> determineNoticePolicy(RulesExecutionParameters parameters) {
+    log.debug("determineNoticePolicy:: parameters parameters: {}", parameters);
+
     return determinePolicy(parameters, drools::noticePolicy, "notice policy");
   }
 
   public Result<CirculationRuleMatch> determineLostItemPolicy(RulesExecutionParameters parameters) {
+    log.debug("determineLostItemPolicy:: parameters parameters: {}", parameters);
+
     return determinePolicy(parameters, drools::lostItemPolicy, "lost item policy");
   }
 
   public Result<CirculationRuleMatch> determineOverduePolicy(RulesExecutionParameters parameters) {
+    log.debug("determineOverduePolicy:: parameters parameters: {}", parameters);
+
     return determinePolicy(parameters, drools::overduePolicy, "overdude policy");
   }
 

src/main/java/org/folio/circulation/rules/Match.java

@@ -1,8 +1,11 @@
 package org.folio.circulation.rules;
 
+import lombok.ToString;
+
 /**
  * Store the result of a rule match.
  */
+@ToString
 public class Match {
   /** loan policy of the matching rule */
   @SuppressWarnings("squid:ClassVariableVisibilityCheck")  // Drools directly uses public fields

src/main/java/org/folio/circulation/rules/cache/CirculationRulesCache.java

@@ -42,26 +42,28 @@ public void dropCache() {
   }
 
   private boolean rulesExist(String tenantId) {
+    log.debug("rulesExist:: parameters tenantId: {}", tenantId);
     Rules rules = rulesMap.get(tenantId);
-
+    log.info("rulesExist:: result: {}", rules != null);
     return rules != null;
   }
 
   public CompletableFuture<Result<Rules>> reloadRules(String tenantId,
     CollectionResourceClient circulationRulesClient) {
-    log.info("Reloading rules for tenant {}", tenantId);
+
+    log.debug("reloadRules:: parameters tenant: {}", tenantId);
 
     return circulationRulesClient.get()
       .thenApply(r -> r.map(response -> getRulesAsText(response, tenantId)))
       .thenApply(r -> r.next(rulesAsText -> reloadRules(tenantId, rulesAsText)));
   }
 
   private static String getRulesAsText(Response response, String tenantId) {
-    log.info("Fetched rules for tenant {}", tenantId);
-    
+    log.debug("getRulesAsText:: parameters tenantId: {}", tenantId);
+
     final var circulationRules = new JsonObject(response.getBody());
     var encodeRules = circulationRules.encodePrettily();
-    log.info("circulationRules = {}", encodeRules);
+    log.info("getRulesAsText:: circulationRules: {}", encodeRules);
 
     return circulationRules.getString("rulesAsText");
   }