From a27ef5d60426c644fd82a0ec130a3c6bf6cddd60 Mon Sep 17 00:00:00 2001 From: Roman Barannyk <53909129+roman-barannyk@users.noreply.github.com> Date: Fri, 20 Oct 2023 16:27:07 +0300 Subject: [PATCH] [CIRC-1896] Logging - circulation resources: O - T (#1346) * CIRC-1896 improve logging * CIRC-1896 fix code smell * CIRC-1896 fix vulnerability issue * CIRC-1896 update logging * CIRC-1896 fix code smell * CIRC-1896 add logging to RequestByInstanceIdResource * CIRC-1896 add suppliers for info logging * CIRC-1896 incorporating review comments * CIRC-1896 fix code smell * CIRC-1896 fix code smell --- .../resources/PickSlipsResource.java | 32 ++++++++++--- .../resources/RenewalValidator.java | 12 +++++ .../RequestByInstanceIdResource.java | 41 +++++++++++++---- .../RequestFromRepresentationService.java | 7 +++ .../RequestHoldShelfClearanceResource.java | 46 ++++++++++++++----- .../resources/RequestNoticeSender.java | 23 ++++++++++ .../resources/RequestQueueResource.java | 13 +++++- ...uestScheduledNoticeProcessingResource.java | 8 ++++ 8 files changed, 153 insertions(+), 29 deletions(-) diff --git a/src/main/java/org/folio/circulation/resources/PickSlipsResource.java b/src/main/java/org/folio/circulation/resources/PickSlipsResource.java index ace01099d2..8c2cbafaf4 100644 --- a/src/main/java/org/folio/circulation/resources/PickSlipsResource.java +++ b/src/main/java/org/folio/circulation/resources/PickSlipsResource.java @@ -9,19 +9,23 @@ import static org.folio.circulation.support.fetching.RecordFetching.findWithCqlQuery; import static org.folio.circulation.support.fetching.RecordFetching.findWithMultipleCqlIndexValues; import static org.folio.circulation.support.http.client.CqlQuery.exactMatch; - import static org.folio.circulation.support.results.Result.succeeded; import static org.folio.circulation.support.results.ResultBinding.flatMapResult; +import static org.folio.circulation.support.utils.LogUtil.collectionAsString; +import static org.folio.circulation.support.utils.LogUtil.multipleRecordsAsString; +import java.lang.invoke.MethodHandles; +import java.util.Collection; +import java.util.List; import java.util.Map; import java.util.Set; import java.util.UUID; -import java.util.Collection; -import java.util.List; import java.util.concurrent.CompletableFuture; +import java.util.stream.Collectors; import org.apache.commons.lang3.StringUtils; -import java.util.stream.Collectors; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.Item; import org.folio.circulation.domain.ItemStatus; import org.folio.circulation.domain.Location; @@ -65,6 +69,7 @@ public class PickSlipsResource extends Resource { private static final String PRIMARY_SERVICE_POINT_KEY = "primaryServicePoint"; private static final PageLimit LOCATIONS_LIMIT = PageLimit.oneThousand(); + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); private final String rootPath; @@ -113,6 +118,8 @@ private void getMany(RoutingContext routingContext) { private CompletableFuture>> fetchLocationsForServicePoint( UUID servicePointId, Clients clients) { + log.debug("fetchLocationsForServicePoint:: parameters servicePointId: {}", servicePointId); + return findWithCqlQuery(clients.locationsStorage(), LOCATIONS_KEY, new LocationMapper()::toDomain) .findByQuery(exactMatch(PRIMARY_SERVICE_POINT_KEY, servicePointId.toString()), LOCATIONS_LIMIT); } @@ -121,6 +128,8 @@ private CompletableFuture>> fetchPagedItemsForLocations( MultipleRecords multipleLocations, ItemRepository itemRepository, LocationRepository locationRepository) { + log.debug("fetchPagedItemsForLocations:: parameters multipleLocations: {}", + () -> multipleRecordsAsString(multipleLocations)); Collection locations = multipleLocations.getRecords(); Set locationIds = locations.stream() @@ -129,6 +138,8 @@ private CompletableFuture>> fetchPagedItemsForLocations( .collect(toSet()); if (locationIds.isEmpty()) { + log.info("fetchPagedItemsForLocations:: locationIds is empty"); + return completedFuture(succeeded(emptyList())); } @@ -143,6 +154,9 @@ private CompletableFuture>> fetchLocationDetailsForItems MultipleRecords items, Collection locationsForServicePoint, LocationRepository locationRepository) { + log.debug("fetchLocationDetailsForItems:: parameters items: {}", + () -> multipleRecordsAsString(items)); + Set locationIdsFromItems = items.toKeys(Item::getEffectiveLocationId); Set locationsForItems = locationsForServicePoint.stream() @@ -150,6 +164,8 @@ private CompletableFuture>> fetchLocationDetailsForItems .collect(toSet()); if (locationsForItems.isEmpty()) { + log.info("fetchLocationDetailsForItems:: locationsForItems is empty"); + return completedFuture(succeeded(emptyList())); } @@ -163,6 +179,9 @@ private CompletableFuture>> fetchLocationDetailsForItems private Result> matchLocationsToItems( MultipleRecords items, Collection locations) { + log.debug("matchLocationsToItems:: parameters items: {}, locations: {}", + () -> multipleRecordsAsString(items), () -> collectionAsString(locations)); + Map locationsMap = locations.stream() .collect(toMap(Location::getId, identity())); @@ -182,6 +201,8 @@ private CompletableFuture>> fetchOpenPageRequest .collect(toSet()); if(itemIds.isEmpty()) { + log.info("fetchOpenPageRequestsForItems:: itemIds is empty"); + return completedFuture(succeeded(MultipleRecords.empty())); } @@ -207,6 +228,7 @@ private Result> matchItemsToRequests( } private Result mapResultToJson(MultipleRecords requests) { + log.debug("mapResultToJson:: parameters requests: {}", () -> multipleRecordsAsString(requests)); List representations = requests.getRecords().stream() .map(TemplateContextUtil::createStaffSlipContext) .collect(Collectors.toList()); @@ -216,6 +238,4 @@ private Result mapResultToJson(MultipleRecords requests) { return succeeded(jsonRepresentations); } - - } diff --git a/src/main/java/org/folio/circulation/resources/RenewalValidator.java b/src/main/java/org/folio/circulation/resources/RenewalValidator.java index bfed3e4fd4..6b4e583f88 100644 --- a/src/main/java/org/folio/circulation/resources/RenewalValidator.java +++ b/src/main/java/org/folio/circulation/resources/RenewalValidator.java @@ -4,13 +4,17 @@ import static org.folio.circulation.support.results.Result.succeeded; import static org.folio.circulation.support.utils.DateTimeUtil.isBeforeMillis; import static org.folio.circulation.support.utils.DateTimeUtil.isSameMillis; +import static org.folio.circulation.support.utils.LogUtil.mapAsString; +import java.lang.invoke.MethodHandles; import java.time.ZonedDateTime; import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.Loan; import org.folio.circulation.domain.policy.LoanPolicy; import org.folio.circulation.support.ErrorCode; @@ -30,6 +34,7 @@ public final class RenewalValidator { public static final String DECLARED_LOST_ITEM_RENEWED_ERROR = "item is Declared lost"; public static final String CLAIMED_RETURNED_RENEWED_ERROR = "item is Claimed returned"; + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); private RenewalValidator() { } @@ -37,12 +42,17 @@ public static void errorWhenEarlierOrSameDueDate(Loan loan, ZonedDateTime proposedDueDate, List errors) { if (isSameOrBefore(loan, proposedDueDate)) { + log.info("errorWhenEarlierOrSameDueDate:: due date from loan: {}, proposedDueDate: {}", + loan::getDueDate, () -> proposedDueDate); errors.add(loanPolicyValidationError(loan.getLoanPolicy(), RENEWAL_WOULD_NOT_CHANGE_THE_DUE_DATE)); } } public static Result errorWhenEarlierOrSameDueDate(Loan loan, ZonedDateTime proposedDueDate) { if (isSameOrBefore(loan, proposedDueDate)) { + log.info("errorWhenEarlierOrSameDueDate:: due date from loan: {}, proposedDueDate: {}", + loan::getDueDate, () -> proposedDueDate); + return failedValidation(loanPolicyValidationError(loan.getLoanPolicy(), RENEWAL_WOULD_NOT_CHANGE_THE_DUE_DATE)); } @@ -77,6 +87,8 @@ public static ValidationError loanPolicyValidationError(LoanPolicy loanPolicy, private static Map buildLoanPolicyParameters( Map additionalParameters, LoanPolicy loanPolicy) { + log.debug("buildLoanPolicyParameters:: parameters additionalParameters: {}, loanPolicy: {}", + () -> mapAsString(additionalParameters), () -> loanPolicy); Map result = new HashMap<>(additionalParameters); result.put("loanPolicyId", loanPolicy.getId()); result.put("loanPolicyName", loanPolicy.getName()); diff --git a/src/main/java/org/folio/circulation/resources/RequestByInstanceIdResource.java b/src/main/java/org/folio/circulation/resources/RequestByInstanceIdResource.java index 1df9575fb5..43e78519e1 100644 --- a/src/main/java/org/folio/circulation/resources/RequestByInstanceIdResource.java +++ b/src/main/java/org/folio/circulation/resources/RequestByInstanceIdResource.java @@ -20,6 +20,9 @@ import static org.folio.circulation.support.results.Result.of; import static org.folio.circulation.support.results.Result.ofAsync; import static org.folio.circulation.support.results.Result.succeeded; +import static org.folio.circulation.support.utils.LogUtil.collectionAsString; +import static org.folio.circulation.support.utils.LogUtil.listAsString; +import static org.folio.circulation.support.utils.LogUtil.mapAsString; import java.lang.invoke.MethodHandles; import java.time.ZonedDateTime; @@ -86,14 +89,13 @@ public class RequestByInstanceIdResource extends Resource { + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); private static final List ORDERED_REQUEST_TYPES = List.of(PAGE, RECALL, HOLD); private static final RequestFulfillmentPreference DEFAULT_FULFILLMENT_PREFERENCE = HOLD_SHELF; - private final Logger log; public RequestByInstanceIdResource(HttpClient client) { super(client); - log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); } @Override @@ -154,8 +156,9 @@ private CompletableFuture>> getLoanItems( InstanceRequestRelatedRecords instanceRequestPackage, LoanRepository loanRepository) { final List unsortedUnavailableItems = instanceRequestPackage.getUnsortedUnavailableItems(); - if (unsortedUnavailableItems == null || - unsortedUnavailableItems.isEmpty()) { + if (unsortedUnavailableItems == null || unsortedUnavailableItems.isEmpty()) { + log.info("getLoanItems:: unsortedUnavailableItems is null or empty"); + return CompletableFuture.completedFuture(succeeded(null)); } @@ -182,6 +185,8 @@ private CompletableFuture>> getLoanItems( } } instanceRequestPackage.setItemsWithoutLoans(itemsWithoutLoansList); + log.debug("getLoanItems:: result: {}", () -> mapAsString(itemDueDateMap)); + return succeeded(itemDueDateMap); }); } @@ -223,6 +228,8 @@ private CompletableFuture>> getRequestQueues( } instanceRequestPackage.setItemsWithoutRequests(itemsWithoutRequestQueues); instanceRequestPackage.setItemRequestQueueMap(itemQueueMap); + log.debug("getRequestQueues:: result: {}", () -> mapAsString(itemQueueMap)); + return succeeded(itemQueueMap); }); } @@ -248,6 +255,9 @@ private CompletableFuture>> buildRequests( private CompletableFuture>> buildTitleLevelRequests( JsonObject requestRepresentation) { + log.debug("buildTitleLevelRequests:: parameters requestRepresentation: {}", + () -> requestRepresentation); + return ofAsync(() -> ORDERED_REQUEST_TYPES.stream() .map(requestType -> requestRepresentation.copy() .put(REQUEST_TYPE, requestType.getValue()) @@ -261,6 +271,8 @@ private CompletableFuture>> buildItemLevelRequests( JsonObject requestBody, ItemByInstanceIdFinder itemFinder, RequestRelatedRepositories repositories) { + log.debug("buildItemLevelRequests:: parameters requestBody: {}", () -> requestBody); + return RequestByInstanceIdRequest.from(requestBody.put(REQUEST_LEVEL, RequestLevel.ITEM.getValue())) .map(InstanceRequestRelatedRecords::new) .after(instanceRequest -> getPotentialItems(itemFinder, instanceRequest, repositories)) @@ -301,6 +313,8 @@ private CompletableFuture> placeRequest( if (startIndex >= itemRequests.size()) { String aggregateFailures = String.format("%n%s", String.join("%n", errors)); + log.warn("placeRequest:: Failed to place a request for the instance. Reasons: {}", + aggregateFailures); return CompletableFuture.completedFuture(failedDueToServerError( "Failed to place a request for the instance. Reasons: " + aggregateFailures)); @@ -338,6 +352,8 @@ public static Result rankItemsByMatchingServicePo InstanceRequestRelatedRecords records) { final Collection unsortedAvailableItems = records.getUnsortedAvailableItems(); + log.debug("rankItemsByMatchingServicePoint:: unsortedAvailableItems: {}", + () -> collectionAsString(unsortedAvailableItems)); final UUID pickupServicePointId = records.getInstanceLevelRequest().getPickupServicePointId(); return of(() -> { @@ -363,6 +379,8 @@ static Result> instanceToItemRequests( InstanceRequestRelatedRecords requestRecords) { final RequestByInstanceIdRequest requestByInstanceIdRequest = requestRecords.getInstanceLevelRequest(); + log.debug("instanceToItemRequests:: requestByInstanceIdRequest: {}", + () -> requestByInstanceIdRequest); final List combinedItems = requestRecords.getCombinedSortedItemsList(); if (combinedItems == null || combinedItems.isEmpty()) { @@ -397,7 +415,7 @@ static Result> instanceToItemRequests( } private Result segregateItemsList( - InstanceRequestRelatedRecords requestRelatedRecords ){ + InstanceRequestRelatedRecords requestRelatedRecords) { Collection items = requestRelatedRecords.getAllUnsortedItems(); @@ -413,13 +431,16 @@ private Result segregateItemsList( } private Result combineWithUnavailableItems( - Map itemDueDateMap, - InstanceRequestRelatedRecords records){ + Map itemDueDateMap, InstanceRequestRelatedRecords records) { + + log.debug("combineWithUnavailableItems:: parameters itemDueDateMap: {}, records: {}", + () -> mapAsString(itemDueDateMap), () -> mapAsString(records.getItemRequestQueueMap())); return of(() -> { Map itemQueueMap = records.getItemRequestQueueMap(); if (itemDueDateMap == null && itemQueueMap == null) { + log.info("combineWithUnavailableItems:: itemDueDateMap and itemQueueMap are null"); return records; } @@ -443,6 +464,8 @@ private Result combineWithUnavailableItems( if (records.getItemsWithoutRequests() != null) finalOrderedList.addAll(records.getItemsWithoutRequests()); records.setSortedUnavailableItems(finalOrderedList); + log.info("combineWithUnavailableItems:: result: {}", listAsString(finalOrderedList)); + return records; }); } @@ -476,14 +499,14 @@ private Result> validateRequester(Map itemR private Result> validateItems(Collection items) { if (items == null || items.isEmpty()) { + log.warn("validateItems:: there are no items for this instance"); return failedValidation("There are no items for this instance", "items", "empty"); } return succeeded(items); } private ProxyRelationshipValidator createProxyRelationshipValidator( - JsonObject representation, - Clients clients) { + JsonObject representation, Clients clients) { return new ProxyRelationshipValidator(clients, () -> singleValidationError("proxyUserId is not valid", diff --git a/src/main/java/org/folio/circulation/resources/RequestFromRepresentationService.java b/src/main/java/org/folio/circulation/resources/RequestFromRepresentationService.java index 2fdea4f0d0..255b015535 100644 --- a/src/main/java/org/folio/circulation/resources/RequestFromRepresentationService.java +++ b/src/main/java/org/folio/circulation/resources/RequestFromRepresentationService.java @@ -206,6 +206,7 @@ private CompletableFuture> fillInMissingHoldingsRecordId(Json private CompletableFuture> fillInMissingInstanceId(JsonObject request) { final String holdingsRecordId = request.getString(HOLDINGS_RECORD_ID); if (holdingsRecordId == null) { + log.warn("fillInMissingInstanceId:: holdingRecordId is null"); return ofAsync(() -> request); } @@ -244,6 +245,7 @@ private CompletableFuture> fetchInstance(Request request) { private CompletableFuture> fetchItemAndLoan( RequestAndRelatedRecords records) { + log.debug("fetchItemAndLoan:: parameters records: {}", () -> records); Request request = records.getRequest(); Function>> itemAndLoanFetchingFunction; @@ -269,6 +271,8 @@ else if (request.isTitleLevel() && request.isRecall()) { private CompletableFuture> fetchItemAndLoanDefault( RequestAndRelatedRecords records) { + log.debug("fetchItemAndLoanDefault:: parameters records: {}", () -> records); + return fromFutureResult(findItemForRequest(records.getRequest())) .flatMapFuture(this::fetchLoan) .flatMapFuture(this::fetchUserForLoan) @@ -308,6 +312,7 @@ private CompletableFuture> fetchItemAndLoanForRecallTlrCreation( Request request = records.getRequest(); if (errorHandler.hasAny(INVALID_INSTANCE_ID)) { + log.warn("fetchItemAndLoanForRecallTlrCreation:: invalid instanceId"); return ofAsync(() -> request); } @@ -342,6 +347,7 @@ private CompletableFuture> shouldLookForTheLeastRecalledLoan(Loa } private CompletableFuture> findItemForRecall(Request request) { + log.debug("findItemForRecall:: parameters request: {}", () -> request); Loan loan = request.getLoan(); if (loan != null) { return itemRepository.fetchFor(loan) @@ -364,6 +370,7 @@ private Result findRecallableItemOrFail(Request request) { } private CompletableFuture> findInstanceItemsAndPolicies(Request request) { + log.debug("findInstanceItemsAndPolicies:: parameters request: {}", () -> request); final var instanceId = UUID.fromString(request.getInstanceId()); return itemByInstanceIdFinder.getItemsByInstanceId(instanceId, false) .thenApply(r -> r.map(request::withInstanceItems)) diff --git a/src/main/java/org/folio/circulation/resources/RequestHoldShelfClearanceResource.java b/src/main/java/org/folio/circulation/resources/RequestHoldShelfClearanceResource.java index eb2774b81b..7ea6ff1bec 100644 --- a/src/main/java/org/folio/circulation/resources/RequestHoldShelfClearanceResource.java +++ b/src/main/java/org/folio/circulation/resources/RequestHoldShelfClearanceResource.java @@ -9,7 +9,9 @@ import static org.folio.circulation.support.http.client.CqlQuery.exactMatch; import static org.folio.circulation.support.http.client.CqlQuery.exactMatchAny; import static org.folio.circulation.support.http.client.PageLimit.limit; +import static org.folio.circulation.support.utils.LogUtil.listAsString; +import java.lang.invoke.MethodHandles; import java.util.ArrayList; import java.util.Arrays; import java.util.Collection; @@ -21,6 +23,8 @@ import java.util.stream.IntStream; import org.apache.commons.lang3.StringUtils; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.HoldShelfClearanceRequestContext; import org.folio.circulation.domain.Item; import org.folio.circulation.domain.ItemsReportFetcher; @@ -60,6 +64,7 @@ public class RequestHoldShelfClearanceResource extends Resource { * DB queries directly. */ private static final int EXPIRED_CANCELLED_REQUEST_LIMIT = 10_000; + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); private static final String SERVICE_POINT_ID_PARAM = "servicePointId"; private static final String ITEM_ID_KEY = "itemId"; @@ -132,15 +137,20 @@ private List> splitIds(List itemsIds) { .collect(Collectors.toList()); } - private CompletableFuture> findAwaitingPickupRequestsByItemsIds(GetManyRecordsClient client, - List> batchItemIds) { + private CompletableFuture> findAwaitingPickupRequestsByItemsIds( + GetManyRecordsClient client, List> batchItemIds) { + + log.debug("findAwaitingPickupRequestsByItemsIds:: parameters batchItemIds: {}", + () -> listAsString(batchItemIds)); List>> awaitingPickupRequests = findAwaitingPickupRequests(client, batchItemIds); + return CompletableFuture.completedFuture(Result.succeeded( createHoldShelfClearanceRequestContext(batchItemIds, awaitingPickupRequests))); } - private List>> findAwaitingPickupRequests(GetManyRecordsClient client, - List> batchItemIds) { + private List>> findAwaitingPickupRequests( + GetManyRecordsClient client, List> batchItemIds) { + return batchItemIds.stream() .map(batch -> { final Result statusQuery = exactMatch(STATUS_KEY, OPEN_AWAITING_PICKUP.getValue()); @@ -155,8 +165,9 @@ private List>> findAwaitingPickupRequests(GetMan .collect(Collectors.toList()); } - private HoldShelfClearanceRequestContext createHoldShelfClearanceRequestContext(List> batchItemIds, - List>> results) { + private HoldShelfClearanceRequestContext createHoldShelfClearanceRequestContext( + List> batchItemIds, List>> results) { + List allAwaitingPickupItemIds = batchItemIds.stream() .flatMap(Collection::stream) .collect(Collectors.toList()); @@ -173,27 +184,38 @@ private HoldShelfClearanceRequestContext createHoldShelfClearanceRequestContext( .withAwaitingPickupRequestItemIds(awaitingPickupRequestItemIds); } - private CompletableFuture> findExpiredOrCancelledRequestByItemIds(GetManyRecordsClient client, - HoldShelfClearanceRequestContext context) { - List>> requestList = findRequestsSortedByClosedDate(client, context.getAwaitingPickupItemIds()); + private CompletableFuture> + findExpiredOrCancelledRequestByItemIds(GetManyRecordsClient client, + HoldShelfClearanceRequestContext context) { + + List>> requestList = findRequestsSortedByClosedDate(client, + context.getAwaitingPickupItemIds()); List firstRequestFromList = getFirstRequestFromList(requestList); - return CompletableFuture.completedFuture(Result.succeeded(context.withExpiredOrCancelledRequests(firstRequestFromList))); + log.debug("findExpiredOrCancelledRequestByItemIds:: firstRequestFromList: {}", + () -> listAsString(firstRequestFromList)); + + return CompletableFuture.completedFuture(Result.succeeded( + context.withExpiredOrCancelledRequests(firstRequestFromList))); } private Predicate hasContextRequestForServicePoint(String servicePointId) { return r -> r.getPickupServicePointId().equals(servicePointId); } - private Predicate hasNotContextAwaitingPickupRequestForItemId(HoldShelfClearanceRequestContext context) { + private Predicate hasNotContextAwaitingPickupRequestForItemId( + HoldShelfClearanceRequestContext context) { + return req -> !context.getAwaitingPickupRequestItemIds().contains(req.getItemId()); } private Result> findExpiredOrCancelledRequestByServicePoint(String servicePointId, - HoldShelfClearanceRequestContext context) { + HoldShelfClearanceRequestContext context) { + List requestList = context.getExpiredOrCancelledRequests().stream() .filter(hasContextRequestForServicePoint(servicePointId)) .filter(hasNotContextAwaitingPickupRequestForItemId(context)) .collect(Collectors.toList()); + return Result.succeeded(requestList); } diff --git a/src/main/java/org/folio/circulation/resources/RequestNoticeSender.java b/src/main/java/org/folio/circulation/resources/RequestNoticeSender.java index 94506b87d9..64111f3c92 100644 --- a/src/main/java/org/folio/circulation/resources/RequestNoticeSender.java +++ b/src/main/java/org/folio/circulation/resources/RequestNoticeSender.java @@ -97,6 +97,7 @@ public static RequestNoticeSender using(Clients clients) { public Result sendNoticeOnRequestCreated( RequestAndRelatedRecords records) { + log.debug("sendNoticeOnRequestCreated:: parameters records: {}", () -> records); Request request = records.getRequest(); recallRequestCount = records.getRequestQueue().getRequests() .stream() @@ -117,6 +118,7 @@ public Result sendNoticeOnRequestCreated( public Result sendNoticeOnRequestCancelled( RequestAndRelatedRecords records) { + log.debug("sendNoticeOnRequestCancelled:: parameters records: {}", () -> records); Request request = records.getRequest(); if (request.hasItemId()) { @@ -138,6 +140,7 @@ public Result sendNoticeOnRequestMoved(RequestAndRelat public Result sendNoticeOnRequestUpdated( RequestAndRelatedRecords records) { + log.debug("sendNoticeOnRequestUpdated:: parameters records: {}", () -> records); if (records.getRequest().getStatus() == RequestStatus.CLOSED_CANCELLED) { requestRepository.loadCancellationReason(records.getRequest()) .thenCompose(r -> r.after(this::fetchLatestPatronInfoAddedComment)) @@ -149,6 +152,7 @@ public Result sendNoticeOnRequestUpdated( } private CompletableFuture> fetchLatestPatronInfoAddedComment(Request request) { + log.debug("fetchLatestPatronInfoAddedComment:: parameters request: {}", () -> request); if(request.hasLoan()){ return loanRepository.fetchLatestPatronInfoAddedComment(request.getLoan()) .thenApply(r -> r.map(request::withLoan)); @@ -158,6 +162,7 @@ private CompletableFuture> fetchLatestPatronInfoAddedComment(Req } public Result sendNoticeOnRequestAwaitingPickup(CheckInContext context) { + log.debug("sendNoticeOnRequestAwaitingPickup:: parameters context: {}", () -> context); final Item item = context.getItem(); final RequestQueue requestQueue = context.getRequestQueue(); @@ -190,6 +195,9 @@ private CompletableFuture> fetchMissingLocationDetails(Request r Item item = request.getItem(); if (item == null || item.isNotFound() || item.getLocation() == null) { + log.info("fetchMissingLocationDetails:: location cannot be fetched, item: {}", + request.getItemId()); + return ofAsync(request); } @@ -201,6 +209,7 @@ private CompletableFuture> fetchMissingLocationDetails(Request r } private CompletableFuture> sendConfirmationNoticeForRequestWithItem(Request request) { + log.debug("sendConfirmationNoticeForRequestWithItem:: parameters request: {}", () -> request); PatronNoticeEvent event = createPatronNoticeEvent(request, getEventType(request)); return patronNoticeService.acceptNoticeEvent(event) @@ -211,6 +220,8 @@ private CompletableFuture> sendConfirmationNoticeForRequestWithItem private CompletableFuture> sendConfirmationNoticeForRequestWithoutItemId( Request request) { + log.debug("sendConfirmationNoticeForRequestWithoutItemId:: parameters request: {}", () -> request); + return sendNoticeForRequestWithoutItemId(request, getEventType(request), TlrSettingsConfiguration::getConfirmationPatronNoticeTemplateId); } @@ -218,6 +229,8 @@ private CompletableFuture> sendConfirmationNoticeForRequestWithoutI private CompletableFuture> sendCancellationNoticeForRequestWithItemId( Request request) { + log.debug("sendCancellationNoticeForRequestWithItemId:: parameters request: {}", () -> request); + return patronNoticeService.acceptNoticeEvent( createPatronNoticeEvent(request, REQUEST_CANCELLATION)); } @@ -225,6 +238,9 @@ private CompletableFuture> sendCancellationNoticeForRequestWithItem private CompletableFuture> sendCancellationNoticeForRequestWithoutItemId( Request request) { + log.debug("sendCancellationNoticeForRequestWithoutItemId:: parameters request: {}", + () -> request); + return sendNoticeForRequestWithoutItemId(request, REQUEST_CANCELLATION, TlrSettingsConfiguration::getCancellationPatronNoticeTemplateId); } @@ -247,6 +263,8 @@ private CompletableFuture> sendNoticeForRequestWithoutItemId(Reques private CompletableFuture> sendNotice(Request request, UUID templateId, NoticeEventType eventType) { + log.debug("sendNotice:: parameters request: {}, templateId: {}, eventType: {}", + () -> request, () -> templateId, () -> eventType); JsonObject noticeContext = createRequestNoticeContext(request); NoticeLogContext noticeLogContext = NoticeLogContext.from(request) .withTriggeringEvent(eventType.getRepresentation()) @@ -259,6 +277,9 @@ private CompletableFuture> sendNotice(Request request, UUID templat private CompletableFuture> fetchDataAndSendRequestAwaitingPickupNotice( Request request) { + log.debug("fetchDataAndSendRequestAwaitingPickupNotice:: parameters request: {}", + () -> request); + return ofAsync(() -> request) .thenCompose(r -> r.combineAfter(this::fetchServicePoint, Request::withPickupServicePoint)) .thenCompose(r -> r.combineAfter(this::fetchRequester, Request::withRequester)) @@ -270,6 +291,7 @@ private CompletableFuture> fetchDataAndSendRequestAwaitingPickupNot private CompletableFuture> fetchRequester(Request request) { String requesterId = request.getRequesterId(); + log.info("fetchRequester:: requesterId: {}", requesterId); return userRepository.getUserWithPatronGroup(requesterId) .thenApply(r -> r.failWhen(this::isNull, @@ -278,6 +300,7 @@ private CompletableFuture> fetchRequester(Request request) { private CompletableFuture> fetchServicePoint(Request request) { String pickupServicePointId = request.getPickupServicePointId(); + log.info("fetchServicePoint:: pickupServicePointId: {}", pickupServicePointId); return servicePointRepository.getServicePointById(pickupServicePointId) .thenApply(r -> r.failWhen(this::isNull, diff --git a/src/main/java/org/folio/circulation/resources/RequestQueueResource.java b/src/main/java/org/folio/circulation/resources/RequestQueueResource.java index aa8a495800..3696483058 100644 --- a/src/main/java/org/folio/circulation/resources/RequestQueueResource.java +++ b/src/main/java/org/folio/circulation/resources/RequestQueueResource.java @@ -8,10 +8,13 @@ import static org.folio.circulation.support.ValidationErrorFailure.singleValidationError; import static org.folio.circulation.support.results.Result.succeeded; +import java.lang.invoke.MethodHandles; import java.util.List; import java.util.concurrent.CompletableFuture; import java.util.stream.Collectors; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.MultipleRecords; import org.folio.circulation.domain.Request; import org.folio.circulation.domain.RequestQueue; @@ -45,6 +48,7 @@ import io.vertx.ext.web.RoutingContext; public class RequestQueueResource extends Resource { + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); public static final String URI_BASE = "/circulation/requests/queue"; public static final String INSTANCE_ID_PARAM_NAME = "instanceId"; public static final String ITEM_ID_PARAM_NAME = "itemId"; @@ -162,7 +166,9 @@ private CompletableFuture> validateTlrFeatureSt )); } - private Result publishReorderedQueue(EventPublisher eventPublisher, Result reorderRequestContext) { + private Result publishReorderedQueue(EventPublisher eventPublisher, + Result reorderRequestContext) { + reorderRequestContext.after(r -> { CompletableFuture.runAsync(() -> { List reordered = r.getReorderRequestToRequestMap().values().stream().filter(Request::hasChangedPosition).collect(Collectors.toList()); @@ -174,6 +180,7 @@ private Result publishReorderedQueue(EventPublisher event } private CompletableFuture> toRepresentation(ReorderRequestContext context) { + log.debug("toRepresentation:: parameters context: {}", () -> context); final RequestRepresentation requestRepresentation = new RequestRepresentation(); return completedFuture(succeeded(context.getRequestQueue())) @@ -187,6 +194,8 @@ private CompletableFuture> toRepresentation(ReorderRequestCon * @return Either instanceId or itemId parameter name depending on the queue type */ private String getIdParameterNameByQueueType(RequestQueueType requestQueueType) { + log.debug("getIdParameterNameByQueueType:: parameters requestQueueType: {}", + () -> requestQueueType); if (requestQueueType == FOR_INSTANCE) { return INSTANCE_ID_PARAM_NAME; } else { @@ -211,7 +220,7 @@ private CompletableFuture> getRequestQueueByType( RequestQueueRepository requestQueueRepository) { String idParamValue = getIdParameterValueByQueueType(routingContext, requestQueueType); - + log.info("getRequestQueueByType:: requestQueueType: {}", requestQueueType); if (requestQueueType == FOR_INSTANCE) { return requestQueueRepository.getByInstanceId(idParamValue); } else { diff --git a/src/main/java/org/folio/circulation/resources/RequestScheduledNoticeProcessingResource.java b/src/main/java/org/folio/circulation/resources/RequestScheduledNoticeProcessingResource.java index a4618addc4..e611e7cf29 100644 --- a/src/main/java/org/folio/circulation/resources/RequestScheduledNoticeProcessingResource.java +++ b/src/main/java/org/folio/circulation/resources/RequestScheduledNoticeProcessingResource.java @@ -9,7 +9,9 @@ import static org.folio.circulation.domain.notice.schedule.TriggeringEvent.TITLE_LEVEL_REQUEST_EXPIRATION; import static org.folio.circulation.support.results.Result.ofAsync; import static org.folio.circulation.support.results.ResultBinding.mapResult; +import static org.folio.circulation.support.utils.LogUtil.collectionAsString; +import java.lang.invoke.MethodHandles; import java.util.Arrays; import java.util.Collection; import java.util.List; @@ -19,6 +21,8 @@ import java.util.Set; import java.util.concurrent.CompletableFuture; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.circulation.domain.MultipleRecords; import org.folio.circulation.domain.Request; import org.folio.circulation.domain.notice.schedule.InstanceAwareRequestScheduledNoticeHandler; @@ -35,10 +39,12 @@ import org.folio.circulation.support.http.client.PageLimit; import org.folio.circulation.support.results.Result; import org.folio.circulation.support.utils.ClockUtil; +import org.folio.circulation.support.utils.LogUtil; import io.vertx.core.http.HttpClient; public class RequestScheduledNoticeProcessingResource extends ScheduledNoticeProcessingResource { + private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass()); public RequestScheduledNoticeProcessingResource(HttpClient client) { super("/circulation/request-scheduled-notices-processing", client); @@ -77,6 +83,8 @@ private CompletableFuture>> handleNotices( Clients clients, RequestRepository requestRepository, LoanRepository loanRepository, Collection notices, Collection requests) { + log.debug("handleNotices:: parameters notices: {}, requests: {}", () -> + collectionAsString(notices), () -> collectionAsString(requests)); Map requestsById = requests.stream() .collect(toMap(Request::getId, identity()));