From cc0d1f28b978f5c0e9a5a0f4b6de01c089335880 Mon Sep 17 00:00:00 2001 From: Roman Barannyk <53909129+roman-barannyk@users.noreply.github.com> Date: Mon, 18 Sep 2023 18:42:02 +0300 Subject: [PATCH] CIRC-1809 add logging to circulation rules package (#1325) * CIRC-1809 add logging to circulation rules package * CIRC-1809 fix typo --- .../rules/AppliedRuleConditions.java | 2 +- .../rules/CirculationRuleMatch.java | 2 +- .../rules/CirculationRulesProcessor.java | 27 ++++++++++++++++++- .../org/folio/circulation/rules/Drools.java | 26 ++++++++++++++++++ .../circulation/rules/ExecutableRules.java | 10 +++++++ .../org/folio/circulation/rules/Match.java | 3 +++ .../rules/cache/CirculationRulesCache.java | 12 +++++---- 7 files changed, 74 insertions(+), 8 deletions(-) diff --git a/src/main/java/org/folio/circulation/rules/AppliedRuleConditions.java b/src/main/java/org/folio/circulation/rules/AppliedRuleConditions.java index 074bcf1ed2..5223251b88 100644 --- a/src/main/java/org/folio/circulation/rules/AppliedRuleConditions.java +++ b/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; diff --git a/src/main/java/org/folio/circulation/rules/CirculationRuleMatch.java b/src/main/java/org/folio/circulation/rules/CirculationRuleMatch.java index 7dfd142b66..7206cf9705 100644 --- a/src/main/java/org/folio/circulation/rules/CirculationRuleMatch.java +++ b/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; diff --git a/src/main/java/org/folio/circulation/rules/CirculationRulesProcessor.java b/src/main/java/org/folio/circulation/rules/CirculationRulesProcessor.java index 4889f7a6a3..289263b974 100644 --- a/src/main/java/org/folio/circulation/rules/CirculationRulesProcessor.java +++ b/src/main/java/org/folio/circulation/rules/CirculationRulesProcessor.java @@ -38,10 +38,14 @@ public CirculationRulesProcessor(String tenantId, CollectionResourceClient circu public CompletableFuture> getLoanPolicyAndMatch( RulesExecutionParameters params) { + log.debug("getLoanPolicyAndMatch:: parameters params: {}", params); + return executeRules(params, ExecutableRules::determineLoanPolicy); } public CompletableFuture> getLoanPolicies(RulesExecutionParameters params) { + log.debug("getLoanPolicies:: parameters params: {}", params); + return triggerRules(params, (drools, newParams) -> drools.loanPolicies(newParams.toMap(), newParams.getLocation())); } @@ -49,10 +53,14 @@ public CompletableFuture> getLoanPolicies(RulesExecutionParame public CompletableFuture> getLostItemPolicyAndMatch( RulesExecutionParameters params) { + log.debug("getLostItemPolicyAndMatch:: parameters params: {}", params); + return executeRules(params, ExecutableRules::determineLostItemPolicy); } public CompletableFuture> getLostItemPolicies(RulesExecutionParameters params) { + log.debug("getLostItemPolicies:: parameters params: {}", params); + return triggerRules(params, (drools, newParams) -> drools.lostItemPolicies(newParams.toMap(), newParams.getLocation())); } @@ -60,10 +68,14 @@ public CompletableFuture> getLostItemPolicies(RulesExecutionPa public CompletableFuture> getNoticePolicyAndMatch( RulesExecutionParameters params) { + log.debug("getNoticePolicyAndMatch:: parameters params: {}", params); + return executeRules(params, ExecutableRules::determineNoticePolicy); } public CompletableFuture> getNoticePolicies(RulesExecutionParameters params) { + log.debug("getNoticePolicies:: parameters params: {}", params); + return triggerRules(params, (drools, newParams) -> drools.noticePolicies(newParams.toMap(), newParams.getLocation())); } @@ -71,10 +83,14 @@ public CompletableFuture> getNoticePolicies(RulesExecutionPara public CompletableFuture> getOverduePolicyAndMatch( RulesExecutionParameters params) { + log.debug("getOverduePolicyAndMatch:: parameters params: {}", params); + return executeRules(params, ExecutableRules::determineOverduePolicy); } public CompletableFuture> getOverduePolicies(RulesExecutionParameters params) { + log.debug("getOverduePolicies:: parameters params: {}", params); + return triggerRules(params, (drools, newParams) -> drools.overduePolicies(newParams.toMap(), newParams.getLocation())); } @@ -82,10 +98,14 @@ public CompletableFuture> getOverduePolicies(RulesExecutionPar public CompletableFuture> getRequestPolicyAndMatch( RulesExecutionParameters params) { + log.debug("getRequestPolicyAndMatch:: parameters params: {}", params); + return executeRules(params, ExecutableRules::determineRequestPolicy); } public CompletableFuture> 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 CompletableFuture> executeRules(RulesExecutionParameters p rulesExecutor.apply(rules, parametersWithLocation))); } - private CompletableFuture> fetchLocation(RulesExecutionParameters params) { + private CompletableFuture> fetchLocation( + RulesExecutionParameters params) { + + log.debug("fetchLocation:: parameters params: {}", params); + if (params.getLocation() != null) { + log.info("fetchLocation:: location is not null"); return ofAsync(() -> params); } diff --git a/src/main/java/org/folio/circulation/rules/Drools.java b/src/main/java/org/folio/circulation/rules/Drools.java index 6f27e67192..529ccb9a20 100644 --- a/src/main/java/org/folio/circulation/rules/Drools.java +++ b/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) diff --git a/src/main/java/org/folio/circulation/rules/ExecutableRules.java b/src/main/java/org/folio/circulation/rules/ExecutableRules.java index 3c0e92b593..5809348651 100644 --- a/src/main/java/org/folio/circulation/rules/ExecutableRules.java +++ b/src/main/java/org/folio/circulation/rules/ExecutableRules.java @@ -31,22 +31,32 @@ public ExecutableRules(String text, Drools drools) { } public Result determineLoanPolicy(RulesExecutionParameters parameters) { + log.debug("determineLoanPolicy:: parameters parameters: {}", parameters); + return determinePolicy(parameters, drools::loanPolicy, "loan policy"); } public Result determineRequestPolicy(RulesExecutionParameters parameters) { + log.debug("determineRequestPolicy:: parameters parameters: {}", parameters); + return determinePolicy(parameters, drools::requestPolicy, "request policy"); } public Result determineNoticePolicy(RulesExecutionParameters parameters) { + log.debug("determineNoticePolicy:: parameters parameters: {}", parameters); + return determinePolicy(parameters, drools::noticePolicy, "notice policy"); } public Result determineLostItemPolicy(RulesExecutionParameters parameters) { + log.debug("determineLostItemPolicy:: parameters parameters: {}", parameters); + return determinePolicy(parameters, drools::lostItemPolicy, "lost item policy"); } public Result determineOverduePolicy(RulesExecutionParameters parameters) { + log.debug("determineOverduePolicy:: parameters parameters: {}", parameters); + return determinePolicy(parameters, drools::overduePolicy, "overdude policy"); } diff --git a/src/main/java/org/folio/circulation/rules/Match.java b/src/main/java/org/folio/circulation/rules/Match.java index e91161229e..8ac885c756 100644 --- a/src/main/java/org/folio/circulation/rules/Match.java +++ b/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 diff --git a/src/main/java/org/folio/circulation/rules/cache/CirculationRulesCache.java b/src/main/java/org/folio/circulation/rules/cache/CirculationRulesCache.java index 2188d0f7d6..81060de3ae 100644 --- a/src/main/java/org/folio/circulation/rules/cache/CirculationRulesCache.java +++ b/src/main/java/org/folio/circulation/rules/cache/CirculationRulesCache.java @@ -42,14 +42,16 @@ 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> 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))) @@ -57,11 +59,11 @@ public CompletableFuture> reloadRules(String tenantId, } 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"); }