Skip to content

Commit

Permalink
[CIRC-1896] Logging - circulation resources: O - T (#1346)
Browse files Browse the repository at this point in the history 
* 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
  • Loading branch information
@roman-barannyk
roman-barannyk authored Oct 20, 2023
1 parent 233f505 commit a27ef5d
Show file tree
Hide file tree
Showing 8 changed files with 153 additions and 29 deletions.
32 changes: 26 additions & 6 deletions src/main/java/org/folio/circulation/resources/PickSlipsResource.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;

Expand Down Expand Up @@ -113,6 +118,8 @@ private void getMany(RoutingContext routingContext) {
private CompletableFuture<Result<MultipleRecords<Location>>> 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);
}
Expand All @@ -121,6 +128,8 @@ private CompletableFuture<Result<Collection<Item>>> fetchPagedItemsForLocations(
MultipleRecords<Location> multipleLocations,
ItemRepository itemRepository, LocationRepository locationRepository) {

log.debug("fetchPagedItemsForLocations:: parameters multipleLocations: {}",
() -> multipleRecordsAsString(multipleLocations));
Collection<Location> locations = multipleLocations.getRecords();

Set<String> locationIds = locations.stream()
Expand All @@ -129,6 +138,8 @@ private CompletableFuture<Result<Collection<Item>>> fetchPagedItemsForLocations(
.collect(toSet());

if (locationIds.isEmpty()) {
log.info("fetchPagedItemsForLocations:: locationIds is empty");

return completedFuture(succeeded(emptyList()));
}

Expand All @@ -143,13 +154,18 @@ private CompletableFuture<Result<Collection<Item>>> fetchLocationDetailsForItems
MultipleRecords<Item> items, Collection<Location> locationsForServicePoint,
LocationRepository locationRepository) {

log.debug("fetchLocationDetailsForItems:: parameters items: {}",
() -> multipleRecordsAsString(items));

Set<String> locationIdsFromItems = items.toKeys(Item::getEffectiveLocationId);

Set<Location> locationsForItems = locationsForServicePoint.stream()
.filter(location -> locationIdsFromItems.contains(location.getId()))
.collect(toSet());

if (locationsForItems.isEmpty()) {
log.info("fetchLocationDetailsForItems:: locationsForItems is empty");

return completedFuture(succeeded(emptyList()));
}

Expand All @@ -163,6 +179,9 @@ private CompletableFuture<Result<Collection<Item>>> fetchLocationDetailsForItems
private Result<Collection<Item>> matchLocationsToItems(
MultipleRecords<Item> items, Collection<Location> locations) {

log.debug("matchLocationsToItems:: parameters items: {}, locations: {}",
() -> multipleRecordsAsString(items), () -> collectionAsString(locations));

Map<String, Location> locationsMap = locations.stream()
.collect(toMap(Location::getId, identity()));

Expand All @@ -182,6 +201,8 @@ private CompletableFuture<Result<MultipleRecords<Request>>> fetchOpenPageRequest
.collect(toSet());

if(itemIds.isEmpty()) {
log.info("fetchOpenPageRequestsForItems:: itemIds is empty");

return completedFuture(succeeded(MultipleRecords.empty()));
}

Expand All @@ -207,6 +228,7 @@ private Result<MultipleRecords<Request>> matchItemsToRequests(
}

private Result<JsonObject> mapResultToJson(MultipleRecords<Request> requests) {
log.debug("mapResultToJson:: parameters requests: {}", () -> multipleRecordsAsString(requests));
List<JsonObject> representations = requests.getRecords().stream()
.map(TemplateContextUtil::createStaffSlipContext)
.collect(Collectors.toList());
Expand All @@ -216,6 +238,4 @@ private Result<JsonObject> mapResultToJson(MultipleRecords<Request> requests) {

return succeeded(jsonRepresentations);
}


}
12 changes: 12 additions & 0 deletions src/main/java/org/folio/circulation/resources/RenewalValidator.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -30,19 +34,25 @@ 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() { }

public static void errorWhenEarlierOrSameDueDate(Loan loan,
ZonedDateTime proposedDueDate, List<ValidationError> 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<ZonedDateTime> 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));
}
Expand Down Expand Up @@ -77,6 +87,8 @@ public static ValidationError loanPolicyValidationError(LoanPolicy loanPolicy,
private static Map<String, String> buildLoanPolicyParameters(
Map<String, String> additionalParameters, LoanPolicy loanPolicy) {

log.debug("buildLoanPolicyParameters:: parameters additionalParameters: {}, loanPolicy: {}",
() -> mapAsString(additionalParameters), () -> loanPolicy);
Map<String, String> result = new HashMap<>(additionalParameters);
result.put("loanPolicyId", loanPolicy.getId());
result.put("loanPolicyName", loanPolicy.getName());
Expand Down
41 changes: 32 additions & 9 deletions src/main/java/org/folio/circulation/resources/RequestByInstanceIdResource.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -86,14 +89,13 @@

public class RequestByInstanceIdResource extends Resource {

private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass());
private static final List<RequestType> 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
Expand Down Expand Up @@ -154,8 +156,9 @@ private CompletableFuture<Result<Map<Item, ZonedDateTime>>> getLoanItems(
InstanceRequestRelatedRecords instanceRequestPackage, LoanRepository loanRepository) {

final List<Item> 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));
}

Expand All @@ -182,6 +185,8 @@ private CompletableFuture<Result<Map<Item, ZonedDateTime>>> getLoanItems(
}
}
instanceRequestPackage.setItemsWithoutLoans(itemsWithoutLoansList);
log.debug("getLoanItems:: result: {}", () -> mapAsString(itemDueDateMap));

return succeeded(itemDueDateMap);
});
}
Expand Down Expand Up @@ -223,6 +228,8 @@ private CompletableFuture<Result<Map<Item, RequestQueue>>> getRequestQueues(
}
instanceRequestPackage.setItemsWithoutRequests(itemsWithoutRequestQueues);
instanceRequestPackage.setItemRequestQueueMap(itemQueueMap);
log.debug("getRequestQueues:: result: {}", () -> mapAsString(itemQueueMap));

return succeeded(itemQueueMap);
});
}
Expand All @@ -248,6 +255,9 @@ private CompletableFuture<Result<List<JsonObject>>> buildRequests(
private CompletableFuture<Result<List<JsonObject>>> buildTitleLevelRequests(
JsonObject requestRepresentation) {

log.debug("buildTitleLevelRequests:: parameters requestRepresentation: {}",
() -> requestRepresentation);

return ofAsync(() -> ORDERED_REQUEST_TYPES.stream()
.map(requestType -> requestRepresentation.copy()
.put(REQUEST_TYPE, requestType.getValue())
Expand All @@ -261,6 +271,8 @@ private CompletableFuture<Result<List<JsonObject>>> 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))
Expand Down Expand Up @@ -301,6 +313,8 @@ private CompletableFuture<Result<RequestAndRelatedRecords>> 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));
Expand Down Expand Up @@ -338,6 +352,8 @@ public static Result<InstanceRequestRelatedRecords> rankItemsByMatchingServicePo
InstanceRequestRelatedRecords records) {

final Collection<Item> unsortedAvailableItems = records.getUnsortedAvailableItems();
log.debug("rankItemsByMatchingServicePoint:: unsortedAvailableItems: {}",
() -> collectionAsString(unsortedAvailableItems));
final UUID pickupServicePointId = records.getInstanceLevelRequest().getPickupServicePointId();

return of(() -> {
Expand All @@ -363,6 +379,8 @@ static Result<List<JsonObject>> instanceToItemRequests(
InstanceRequestRelatedRecords requestRecords) {

final RequestByInstanceIdRequest requestByInstanceIdRequest = requestRecords.getInstanceLevelRequest();
log.debug("instanceToItemRequests:: requestByInstanceIdRequest: {}",
() -> requestByInstanceIdRequest);
final List<Item> combinedItems = requestRecords.getCombinedSortedItemsList();

if (combinedItems == null || combinedItems.isEmpty()) {
Expand Down Expand Up @@ -397,7 +415,7 @@ static Result<List<JsonObject>> instanceToItemRequests(
}

private Result<InstanceRequestRelatedRecords> segregateItemsList(
InstanceRequestRelatedRecords requestRelatedRecords ){
InstanceRequestRelatedRecords requestRelatedRecords) {

Collection<Item> items = requestRelatedRecords.getAllUnsortedItems();

Expand All @@ -413,13 +431,16 @@ private Result<InstanceRequestRelatedRecords> segregateItemsList(
}

private Result<InstanceRequestRelatedRecords> combineWithUnavailableItems(
Map<Item, ZonedDateTime> itemDueDateMap,
InstanceRequestRelatedRecords records){
Map<Item, ZonedDateTime> itemDueDateMap, InstanceRequestRelatedRecords records) {

log.debug("combineWithUnavailableItems:: parameters itemDueDateMap: {}, records: {}",
() -> mapAsString(itemDueDateMap), () -> mapAsString(records.getItemRequestQueueMap()));

return of(() -> {
Map<Item, RequestQueue> itemQueueMap = records.getItemRequestQueueMap();

if (itemDueDateMap == null && itemQueueMap == null) {
log.info("combineWithUnavailableItems:: itemDueDateMap and itemQueueMap are null");
return records;
}

Expand All @@ -443,6 +464,8 @@ private Result<InstanceRequestRelatedRecords> combineWithUnavailableItems(
if (records.getItemsWithoutRequests() != null)
finalOrderedList.addAll(records.getItemsWithoutRequests());
records.setSortedUnavailableItems(finalOrderedList);
log.info("combineWithUnavailableItems:: result: {}", listAsString(finalOrderedList));

return records;
});
}
Expand Down Expand Up @@ -476,14 +499,14 @@ private Result<Collection<Item>> validateRequester(Map<Item, RequestQueue> itemR

private Result<Collection<Item>> validateItems(Collection<Item> 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",
Expand Down
7 changes: 7 additions & 0 deletions src/main/java/org/folio/circulation/resources/RequestFromRepresentationService.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -206,6 +206,7 @@ private CompletableFuture<Result<JsonObject>> fillInMissingHoldingsRecordId(Json
private CompletableFuture<Result<JsonObject>> fillInMissingInstanceId(JsonObject request) {
final String holdingsRecordId = request.getString(HOLDINGS_RECORD_ID);
if (holdingsRecordId == null) {
log.warn("fillInMissingInstanceId:: holdingRecordId is null");
return ofAsync(() -> request);
}

Expand Down Expand Up @@ -244,6 +245,7 @@ private CompletableFuture<Result<Request>> fetchInstance(Request request) {
private CompletableFuture<Result<RequestAndRelatedRecords>> fetchItemAndLoan(
RequestAndRelatedRecords records) {

log.debug("fetchItemAndLoan:: parameters records: {}", () -> records);
Request request = records.getRequest();
Function<RequestAndRelatedRecords, CompletableFuture<Result<Request>>>
itemAndLoanFetchingFunction;
Expand All @@ -269,6 +271,8 @@ else if (request.isTitleLevel() && request.isRecall()) {
private CompletableFuture<Result<Request>> fetchItemAndLoanDefault(
RequestAndRelatedRecords records) {

log.debug("fetchItemAndLoanDefault:: parameters records: {}", () -> records);

return fromFutureResult(findItemForRequest(records.getRequest()))
.flatMapFuture(this::fetchLoan)
.flatMapFuture(this::fetchUserForLoan)
Expand Down Expand Up @@ -308,6 +312,7 @@ private CompletableFuture<Result<Request>> fetchItemAndLoanForRecallTlrCreation(

Request request = records.getRequest();
if (errorHandler.hasAny(INVALID_INSTANCE_ID)) {
log.warn("fetchItemAndLoanForRecallTlrCreation:: invalid instanceId");
return ofAsync(() -> request);
}

Expand Down Expand Up @@ -342,6 +347,7 @@ private CompletableFuture<Result<Boolean>> shouldLookForTheLeastRecalledLoan(Loa
}

private CompletableFuture<Result<Request>> findItemForRecall(Request request) {
log.debug("findItemForRecall:: parameters request: {}", () -> request);
Loan loan = request.getLoan();
if (loan != null) {
return itemRepository.fetchFor(loan)
Expand All @@ -364,6 +370,7 @@ private Result<Request> findRecallableItemOrFail(Request request) {
}

private CompletableFuture<Result<Request>> 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))
Expand Down
Loading

0 comments on commit a27ef5d

Please sign in to comment.