From 233f5052d87b2d2d37605b222101180673779352 Mon Sep 17 00:00:00 2001 From: Roman Barannyk <53909129+roman-barannyk@users.noreply.github.com> Date: Fri, 20 Oct 2023 16:14:54 +0300 Subject: [PATCH] [CIRC-1909] Logging - circulation domain (D - L) (#1348) * CIRC-1909 improve logging * CIRC-1909 fix code smell issue * CIRC-1909 incorporating review comments * CIRC-1909 fix code smells * CIRC-1909 fix code smells * CIRC-1909 fix typo --- .../domain/InstanceRequestItemsComparer.java | 37 +++++++++-- .../org/folio/circulation/domain/Loan.java | 64 +++++++++++++++---- .../domain/LoanCheckInService.java | 8 +++ .../domain/LoanRepresentation.java | 27 ++++++-- .../folio/circulation/domain/LoanService.java | 9 +++ 5 files changed, 119 insertions(+), 26 deletions(-) diff --git a/src/main/java/org/folio/circulation/domain/InstanceRequestItemsComparer.java b/src/main/java/org/folio/circulation/domain/InstanceRequestItemsComparer.java index 26adc2d285..ff3540cbcb 100644 --- a/src/main/java/org/folio/circulation/domain/InstanceRequestItemsComparer.java +++ b/src/main/java/org/folio/circulation/domain/InstanceRequestItemsComparer.java @@ -1,5 +1,8 @@ package org.folio.circulation.domain; +import static org.folio.circulation.support.utils.LogUtil.mapAsString; + +import java.lang.invoke.MethodHandles; import java.time.ZonedDateTime; import java.util.Comparator; import java.util.LinkedHashMap; @@ -7,13 +10,23 @@ import java.util.UUID; import java.util.stream.Collectors; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; + public class InstanceRequestItemsComparer { private InstanceRequestItemsComparer() {} + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); + public static Map sortRequestQueues(Map itemsQueueLengthUnsortedMap, - Map itemDueDateMap, - UUID destinationServicePointId) { + Map itemDueDateMap, UUID destinationServicePointId) { + + log.debug("sortRequestQueues:: parameters itemsQueueLengthUnsortedMap: {}, " + + "itemDueDateMap: {}, destinationServicePointId: {}", () -> mapAsString( + itemsQueueLengthUnsortedMap), () -> mapAsString(itemDueDateMap), + () -> destinationServicePointId); + return itemsQueueLengthUnsortedMap .entrySet() .stream() @@ -22,8 +35,11 @@ public static Map sortRequestQueues(Map itemsQueue (oldValue, newValue) -> oldValue, (LinkedHashMap::new))); } - private static Comparator> compareQueueLengths(Map itemDueDateMap, - UUID destinationServicePointId) { + private static Comparator> compareQueueLengths( + Map itemDueDateMap, UUID destinationServicePointId) { + + log.debug("compareQueueLengths:: parameters itemDueDateMap: {}, destinationServicePointId: {}", + () -> mapAsString(itemDueDateMap), () -> destinationServicePointId); // Sort the map return (q1Size, q2Size) -> { int result = compareQueueSize(q1Size.getValue(), q2Size.getValue()); @@ -37,15 +53,20 @@ private static Comparator> compareQueueLengths(Map itemDueDateMap) { + log.debug("compareDueDate:: parameters item1: {}, item2: {}, itemDueDateMap: {}", + () -> item1, () -> item2, () -> mapAsString(itemDueDateMap)); ZonedDateTime q1ItemDueDate = itemDueDateMap.get(item1); ZonedDateTime q2ItemDueDate = itemDueDateMap.get(item2); @@ -61,9 +82,13 @@ private static int compareDueDate(Item item1, Item item2, Map newDueDate); write(representation, DUE_DATE, newDueDate.withZoneSameInstant(UTC)); return this; @@ -170,18 +175,22 @@ public Loan setDueDateChangedByNearExpireUser() { } private void changeReturnDate(ZonedDateTime returnDate) { + log.debug("changeReturnDate:: parameters returnDate: {}", () -> returnDate); write(representation, RETURN_DATE, returnDate); } private void changeSystemReturnDate(ZonedDateTime systemReturnDate) { + log.debug("changeSystemReturnDate:: parameters systemReturnDate: {}", () -> systemReturnDate); write(representation, SYSTEM_RETURN_DATE, systemReturnDate); } public void changeAction(LoanAction action) { + log.debug("changeAction:: parameters action: {}", action); changeAction(action.getValue()); } public void changeAction(String action) { + log.debug("changeAction:: parameters action: {}", action); write(representation, LoanProperties.ACTION, action); } @@ -190,10 +199,12 @@ public String getAction() { } private void changeCheckInServicePointId(UUID servicePointId) { + log.debug("changeCheckInServicePointId:: parameters servicePointId: {}", servicePointId); write(representation, "checkinServicePointId", servicePointId); } public Loan changeItemStatusForItemAndLoan(ItemStatus itemStatus) { + log.debug("changeItemStatusForItemAndLoan:: parameters itemStatus: {}", itemStatus); Item itemToChange = getItem(); executeIfNotNull(itemToChange, f -> f.changeStatus(itemStatus)); @@ -204,19 +215,23 @@ public Loan changeItemStatusForItemAndLoan(ItemStatus itemStatus) { } private void changeStatus(LoanStatus status) { + log.debug("changeStatus:: parameters status: {}", status); representation.put(STATUS, new JsonObject().put("name", status.getValue())); } public Loan changeItemEffectiveLocationIdAtCheckOut(String locationId) { + log.debug("changeItemEffectiveLocationIdAtCheckOut:: parameters locationId: {}", locationId); representation.put(ITEM_LOCATION_ID_AT_CHECKOUT, locationId); return this; } public void changeActionComment(String comment) { + log.debug("changeActionComment:: parameters comment: {}", comment); representation.put(ACTION_COMMENT, comment); } public void removeActionComment() { + log.debug("removeActionComment:: "); representation.remove(ACTION_COMMENT); } @@ -226,13 +241,16 @@ public String getActionComment() { public Result isValidStatus() { if (!representation.containsKey(STATUS)) { - return failedDueToServerError("Loan does not have a status"); + String errorMessage = "Loan does not have a status"; + log.warn("isValidStatus:: {}", errorMessage); + return failedDueToServerError(errorMessage); } // Provided status name is not present in the enum if (getStatus() == null) { - return failedValidation("Loan status must be \"Open\" or \"Closed\"", - STATUS, getStatusName()); + String errorMessage = "Loan status must be \"Open\" or \"Closed\""; + log.warn("isValidStatus:: {}", errorMessage); + return failedValidation(errorMessage, STATUS, getStatusName()); } return succeeded(null); @@ -240,8 +258,9 @@ public Result isValidStatus() { public Result openLoanHasUserId() { if (isOpen() && getUserId() == null) { - return failedValidation("Open loan must have a user ID", - USER_ID, getUserId()); + String errorMessage = "Open loan must have a user ID"; + log.warn("openLoanHasUserId::{}", errorMessage); + return failedValidation(errorMessage, USER_ID, getUserId()); } else { return succeeded(null); } @@ -249,8 +268,9 @@ public Result openLoanHasUserId() { public Result closedLoanHasCheckInServicePointId() { if (isClosed() && getCheckInServicePointId() == null) { - return failedValidation("A Closed loan must have a Checkin Service Point", - CHECKIN_SERVICE_POINT_ID, getCheckInServicePointId()); + String errorMessage = "A Closed loan must have a Checkin Service Point"; + log.warn("closedLoanHasCheckInServicePointId:: {}", errorMessage); + return failedValidation(errorMessage, CHECKIN_SERVICE_POINT_ID, getCheckInServicePointId()); } else { return succeeded(null); } @@ -454,6 +474,8 @@ public String getPatronGroupIdAtCheckout() { } public Loan renew(ZonedDateTime dueDate, String basedUponLoanPolicyId) { + log.debug("renew:: parameters dueDate: {}, basedUponLoanPolicyId: {}", + () -> dueDate, () -> basedUponLoanPolicyId); changeAction(RENEWED); removeActionComment(); setLoanPolicyId(basedUponLoanPolicyId); @@ -463,10 +485,11 @@ public Loan renew(ZonedDateTime dueDate, String basedUponLoanPolicyId) { return this; } - public Loan overrideRenewal(ZonedDateTime dueDate, - String basedUponLoanPolicyId, + public Loan overrideRenewal(ZonedDateTime dueDate, String basedUponLoanPolicyId, String actionComment) { + log.debug("overrideRenewal:: parameters dueDate: {}, basedUponLoanPolicyId: {}, " + + "actionComment: {}", () -> dueDate, () -> basedUponLoanPolicyId, () -> actionComment); changeAction(RENEWED_THROUGH_OVERRIDE); setLoanPolicyId(basedUponLoanPolicyId); changeDueDate(dueDate); @@ -479,6 +502,9 @@ public Loan overrideRenewal(ZonedDateTime dueDate, private Loan checkIn(LoanAction action, ZonedDateTime returnDateTime, ZonedDateTime systemReturnDateTime, UUID servicePointId) { + log.debug("checkIn:: parameters action: {}, returnDateTime: {}, " + + "systemReturnDateTime: {}, servicePointId: {}", () -> action, () -> returnDateTime, + () -> systemReturnDateTime, () -> servicePointId); closeLoan(action); changeReturnDate(returnDateTime); changeSystemReturnDate(systemReturnDateTime); @@ -500,6 +526,7 @@ Loan resolveClaimedReturned(LoanAction resolveAction, public Loan declareItemLost(String comment, ZonedDateTime dateTime) { + log.debug("declareItemLost:: parameters comment: {}, dateTime: {}", () -> comment, () -> dateTime); changeAction(DECLARED_LOST); changeActionComment(comment); changeItemStatusForItemAndLoan(ItemStatus.DECLARED_LOST); @@ -583,10 +610,12 @@ public ZonedDateTime getReturnDate() { } public void changeItemStatus(String itemStatus) { + log.debug("changeItemStatus:: parameters itemStatus: {}", itemStatus); representation.put(LoanProperties.ITEM_STATUS, itemStatus); } public void changeDeclaredLostDateTime(ZonedDateTime dateTime) { + log.debug("changeDeclaredLostDateTime:: parameters dateTime: {}", () -> dateTime); write(representation, DECLARED_LOST_DATE, dateTime); } @@ -646,6 +675,8 @@ public OverdueFinePolicyRemindersPolicy.ReminderSequenceEntry getNextReminder() } public Loan claimItemReturned(String comment, ZonedDateTime claimedReturnedDate) { + log.debug("claimItemReturned:: parameters comment: {}, claimedReturnedDate: {}", + () -> comment, () -> claimedReturnedDate); changeAction(CLAIMED_RETURNED); if (StringUtils.isNotBlank(comment)) { changeActionComment(comment); @@ -662,6 +693,7 @@ private void changeClaimedReturnedDate(ZonedDateTime claimedReturnedDate) { } public Loan closeLoan(LoanAction action) { + log.debug("closeLoan:: parameters action: {}", action); changeStatus(LoanStatus.CLOSED); changeAction(action); @@ -671,6 +703,7 @@ public Loan closeLoan(LoanAction action) { } public Loan closeLoan(LoanAction action, String comment) { + log.debug("closeLoan:: parameters action: {}, comment: {}", action, comment); changeStatus(LoanStatus.CLOSED); changeAction(action); @@ -680,6 +713,7 @@ public Loan closeLoan(LoanAction action, String comment) { } public Loan markItemMissing(String comment) { + log.debug("markItemMissing:: parameters comment: {}", comment); changeItemStatusForItemAndLoan(ItemStatus.MISSING); return closeLoan(MISSING, comment); @@ -698,6 +732,7 @@ public FeeAmount getRemainingFeeFineAmount() { } public void closeLoanAsLostAndPaid() { + log.debug("closeLoanAsLostAndPaid:: "); closeLoan(CLOSED_LOAN); changeItemStatusForItemAndLoan(ItemStatus.LOST_AND_PAID); } @@ -709,6 +744,7 @@ public Loan copy() { } public Loan ageOverdueItemToLost(ZonedDateTime ageToLostDate) { + log.debug("ageOverdueItemToLost:: parameters ageToLostDate: {}", () -> ageToLostDate); changeAction(ITEM_AGED_TO_LOST); removeActionComment(); changeItemStatusForItemAndLoan(ItemStatus.AGED_TO_LOST); diff --git a/src/main/java/org/folio/circulation/domain/LoanCheckInService.java b/src/main/java/org/folio/circulation/domain/LoanCheckInService.java index 5450a2583a..78bf759466 100644 --- a/src/main/java/org/folio/circulation/domain/LoanCheckInService.java +++ b/src/main/java/org/folio/circulation/domain/LoanCheckInService.java @@ -6,18 +6,25 @@ import static org.folio.circulation.support.results.Result.of; import static org.folio.circulation.support.results.Result.succeeded; +import java.lang.invoke.MethodHandles; import java.time.ZonedDateTime; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.representations.CheckInByBarcodeRequest; import org.folio.circulation.support.ServerErrorFailure; import org.folio.circulation.support.results.Result; public class LoanCheckInService { + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); public Result checkIn(Loan loan, ZonedDateTime systemDateTime, CheckInByBarcodeRequest request) { + log.debug("checkIn:: parameters loan: {}, systemDateTime: {}, request: {}", + () -> loan, () -> systemDateTime, () -> request); if (loan == null) { + log.debug("checkIn:: loan is null"); return of(() -> null); } @@ -28,6 +35,7 @@ public Result checkIn(Loan loan, ZonedDateTime systemDateTime, } if (loan.isAgedToLost()) { + log.info("checkIn:: loan is agedToLost, removing aged to lost billing info"); loan.removeAgedToLostBillingInfo(); } diff --git a/src/main/java/org/folio/circulation/domain/LoanRepresentation.java b/src/main/java/org/folio/circulation/domain/LoanRepresentation.java index 89a2b5ea11..a1cd823d34 100644 --- a/src/main/java/org/folio/circulation/domain/LoanRepresentation.java +++ b/src/main/java/org/folio/circulation/domain/LoanRepresentation.java @@ -23,32 +23,39 @@ public class LoanRepresentation { private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); public JsonObject extendedLoan(Loan loan) { - if(loan == null) { + if (loan == null) { + log.warn("extendedLoan:: loan is null"); return null; } JsonObject extendedRepresentation = extendedLoan(loan.asJson(), loan.getItem()); if(loan.isDueDateChangedByNearExpireUser()) { - extendedRepresentation.put("dueDateChangedByNearExpireUser",loan.isDueDateChangedByNearExpireUser()); + log.info("extendedLoan:: due date changed by near expire user"); + extendedRepresentation.put("dueDateChangedByNearExpireUser", loan.isDueDateChangedByNearExpireUser()); } if(loan.isDueDateChangedByHold()) { + log.info("extendedLoan:: due date changed by hold"); extendedRepresentation.put("dueDateChangedByHold",loan.isDueDateChangedByHold()); } if(loan.getCheckinServicePoint() != null) { + log.info("extendedLoan:: checkinServicePoint is not null"); addAdditionalServicePointProperties(extendedRepresentation, loan.getCheckinServicePoint(), "checkinServicePoint"); } if(loan.getCheckoutServicePoint() != null) { + log.info("extendedLoan:: checkoutServicePoint is not null"); addAdditionalServicePointProperties(extendedRepresentation, loan.getCheckoutServicePoint(), "checkoutServicePoint"); } if (loan.getUser() != null) { + log.info("extendedLoan:: user is not null"); additionalBorrowerProperties(extendedRepresentation, loan.getUser()); - }else{ + } else { //When there is no user, it means that the loan has been anonymized + log.info("extendedLoan:: there is no user, removing borrower"); extendedRepresentation.remove(BORROWER); } @@ -64,6 +71,7 @@ public JsonObject extendedLoan(Loan loan) { private void addPolicy(JsonObject extendedRepresentation, Policy policy, String policyName) { + if (policy != null) { additionalPolicyProperties(extendedRepresentation, policy, policyName); } else { @@ -82,7 +90,7 @@ private JsonObject extendedLoan(JsonObject loan, Item item) { //and could be confused with aggregation of current status loan.remove("itemStatus"); - if(item != null && item.isFound()) { + if (item != null && item.isFound()) { loan.put("item", new ItemSummaryRepresentation() .createItemSummary(item)); } @@ -93,7 +101,10 @@ private JsonObject extendedLoan(JsonObject loan, Item item) { } private void additionalAccountProperties(JsonObject loanRepresentation, Loan loan) { + log.debug("additionalAccountProperties:: parameters loanRepresentation: {}, loan: {}", + () -> loanRepresentation, () -> loan); if (loan.getAccounts() == null) { + log.info("additionalAccountProperties:: accounts is null"); return; } @@ -108,6 +119,7 @@ private void additionalAccountProperties(JsonObject loanRepresentation, Loan loa private void additionalPolicyProperties(JsonObject representation, Policy policy, String policyName) { + JsonObject summary = representation.containsKey(policyName) ? representation.getJsonObject(policyName) : new JsonObject(); @@ -121,7 +133,7 @@ private void addAdditionalServicePointProperties( ServicePoint servicePoint, String fieldName) { - if(servicePoint == null) { + if (servicePoint == null) { log.info("Unable to add servicepoint properties to loan {}," + " servicepoint is null", loanRepresentation.getString("id")); return; @@ -160,8 +172,11 @@ private void additionalBorrowerProperties(JsonObject loanRepresentation, User bo additionalPatronGroupProperties(loanRepresentation, borrower.getPatronGroup()); } - private void additionalPatronGroupProperties(JsonObject loanRepresentation, PatronGroup patronGroupAtCheckout) { + private void additionalPatronGroupProperties(JsonObject loanRepresentation, + PatronGroup patronGroupAtCheckout) { + if (isNull(patronGroupAtCheckout)) { + log.info("additionalPatronGroupProperties:: patronGroupAtCheckout is null"); return; } diff --git a/src/main/java/org/folio/circulation/domain/LoanService.java b/src/main/java/org/folio/circulation/domain/LoanService.java index 5a57e640ae..52434879f3 100644 --- a/src/main/java/org/folio/circulation/domain/LoanService.java +++ b/src/main/java/org/folio/circulation/domain/LoanService.java @@ -3,9 +3,12 @@ import static java.util.concurrent.CompletableFuture.completedFuture; import static org.folio.circulation.support.results.Result.succeeded; +import java.lang.invoke.MethodHandles; import java.util.Collection; import java.util.concurrent.CompletableFuture; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.policy.LoanPolicy; import org.folio.circulation.domain.policy.library.ClosedLibraryStrategyService; import org.folio.circulation.support.Clients; @@ -14,6 +17,7 @@ public class LoanService { + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); private final ClosedLibraryStrategyService closedLibraryStrategyService; public LoanService(Clients clients) { @@ -23,14 +27,18 @@ public LoanService(Clients clients) { public CompletableFuture> truncateLoanWhenItemRecalled( LoanAndRelatedRecords records) { + + log.debug("truncateLoanWhenItemRecalled:: parameters records: {}", () -> records); RequestQueue requestQueue = records.getRequestQueue(); Collection requests = requestQueue.getRequests(); if(requests.isEmpty()) { + log.info("truncateLoanWhenItemRecalled:: requests is empty"); return completedFuture(succeeded(records)); } if (!requestQueue.containsRequestOfTypeForItem(RequestType.RECALL, records.getItem())) { + log.info("truncateLoanWhenItemRecalled:: request queue does not contain recall type"); return completedFuture(succeeded(records)); } @@ -38,6 +46,7 @@ public CompletableFuture> truncateLoanWhenItemReca final LoanPolicy loanPolicy = loanToRecall.getLoanPolicy(); if (loanToRecall.wasDueDateChangedByRecall()) { + log.info("truncateLoanWhenItemRecalled:: due date was changed by recall"); return completedFuture(succeeded(records)); }