[CIRC-1910] Logging - circulation domain (M - U) (#1364)

* CIRC-1910 improve logging

* CIRC-1910 fix code smells

* CIRC-1910 include code review comments

src/main/java/org/folio/circulation/domain/MoveRequestProcessAdapter.java

@@ -1,46 +1,64 @@
 package org.folio.circulation.domain;
 
+import java.lang.invoke.MethodHandles;
 import java.util.concurrent.CompletableFuture;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.folio.circulation.infrastructure.storage.inventory.ItemRepository;
 import org.folio.circulation.infrastructure.storage.loans.LoanRepository;
 import org.folio.circulation.infrastructure.storage.requests.RequestRepository;
 import org.folio.circulation.support.results.Result;
 
 public class MoveRequestProcessAdapter {
+  private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass());
   private final ItemRepository itemRepository;
   private final LoanRepository loanRepository;
   private final RequestRepository requestRepository;
 
   public MoveRequestProcessAdapter(ItemRepository itemRepository, LoanRepository loanRepository,
-      RequestRepository requestRepository) {
+    RequestRepository requestRepository) {
+
     this.itemRepository = itemRepository;
     this.loanRepository = loanRepository;
     this.requestRepository = requestRepository;
   }
 
   CompletableFuture<Result<RequestAndRelatedRecords>> findDestinationItem(
-     RequestAndRelatedRecords requestAndRelatedRecords) {
+    RequestAndRelatedRecords requestAndRelatedRecords) {
+
+    log.debug("findDestinationItem:: parameters requestAndRelatedRecords: {}",
+      () -> requestAndRelatedRecords);
+
     return itemRepository.fetchById(requestAndRelatedRecords.getDestinationItemId())
       .thenApply(r -> r.map(requestAndRelatedRecords::withItem))
       .thenComposeAsync(r -> r.after(this::findLoanForItem));
   }
 
   private CompletableFuture<Result<RequestAndRelatedRecords>> findLoanForItem(
-      RequestAndRelatedRecords requestAndRelatedRecords) {
+    RequestAndRelatedRecords requestAndRelatedRecords) {
+
     return loanRepository.findOpenLoanForRequest(requestAndRelatedRecords.getRequest())
       .thenApply(r -> r.map(requestAndRelatedRecords::withLoan));
   }
 
   CompletableFuture<Result<RequestAndRelatedRecords>> findSourceItem(
-      RequestAndRelatedRecords requestAndRelatedRecords) {
+    RequestAndRelatedRecords requestAndRelatedRecords) {
+
+    log.debug("findSourceItem:: parameters requestAndRelatedRecords: {}",
+      () -> requestAndRelatedRecords);
+
     return itemRepository.fetchById(requestAndRelatedRecords.getSourceItemId())
       .thenApply(result -> result.map(requestAndRelatedRecords::withItem))
       .thenComposeAsync(r -> r.after(this::findLoanForItem));
   }
 
   CompletableFuture<Result<RequestAndRelatedRecords>> getRequest(
-      RequestAndRelatedRecords requestAndRelatedRecords) {
+    RequestAndRelatedRecords requestAndRelatedRecords) {
+
+    log.debug("getRequest:: parameters requestAndRelatedRecords: {}",
+      () -> requestAndRelatedRecords);
+
     return requestRepository.getById(requestAndRelatedRecords.getRequest().getId())
       .thenApply(r -> r.map(requestAndRelatedRecords::withRequest));
   }

src/main/java/org/folio/circulation/domain/MoveRequestService.java

@@ -3,8 +3,11 @@
 import static org.folio.circulation.domain.representations.logs.LogEventType.REQUEST_MOVED;
 import static org.folio.circulation.support.results.Result.of;
 
+import java.lang.invoke.MethodHandles;
 import java.util.concurrent.CompletableFuture;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.folio.circulation.domain.validation.RequestLoanValidator;
 import org.folio.circulation.infrastructure.storage.ConfigurationRepository;
 import org.folio.circulation.infrastructure.storage.requests.RequestPolicyRepository;
@@ -24,6 +27,7 @@ public class MoveRequestService {
   private final ConfigurationRepository configurationRepository;
   private final EventPublisher eventPublisher;
   private final RequestQueueRepository requestQueueRepository;
+  private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass());
 
   public MoveRequestService(RequestRepository requestRepository, RequestPolicyRepository requestPolicyRepository,
     UpdateUponRequest updateUponRequest, MoveRequestProcessAdapter moveRequestHelper,
@@ -71,11 +75,14 @@ public CompletableFuture<Result<RequestAndRelatedRecords>> moveRequest(
   }
 
   private RequestAndRelatedRecords pagedRequestIfDestinationItemAvailable(
-      RequestAndRelatedRecords requestAndRelatedRecords) {
+    RequestAndRelatedRecords requestAndRelatedRecords) {
 
+    log.debug("pagedRequestIfDestinationItemAvailable parameters requestAndRelatedRecords: {}",
+      () -> requestAndRelatedRecords);
     Item item = requestAndRelatedRecords.getRequest().getItem();
 
     if (item.getStatus().equals(ItemStatus.AVAILABLE)) {
+      log.info("pagedRequestIfDestinationItemAvailable:: item: {} is available", item.getItemId());
       return requestAndRelatedRecords.withRequestType(RequestType.PAGE);
     }
 
@@ -85,6 +92,9 @@ private RequestAndRelatedRecords pagedRequestIfDestinationItemAvailable(
   private CompletableFuture<Result<RequestAndRelatedRecords>> validateUpdateRequest(
       RequestAndRelatedRecords requestAndRelatedRecords) {
 
+    log.debug("validateUpdateRequest parameters requestAndRelatedRecords: {}",
+      () -> requestAndRelatedRecords);
+
     return of(() -> requestAndRelatedRecords)
       .next(RequestServiceUtility::refuseWhenItemDoesNotExist)
       .next(RequestServiceUtility::refuseWhenInvalidUserAndPatronGroup)
@@ -98,6 +108,9 @@ private CompletableFuture<Result<RequestAndRelatedRecords>> validateUpdateReques
   private CompletableFuture<Result<RequestAndRelatedRecords>> updateRelatedObjects(
       RequestAndRelatedRecords requestAndRelatedRecords) {
 
+    log.debug("updateRelatedObjects parameters requestAndRelatedRecords: {}",
+      () -> requestAndRelatedRecords);
+
     return updateUponRequest.updateItem.onRequestCreateOrUpdate(requestAndRelatedRecords)
       .thenComposeAsync(r -> r.after(updateUponRequest.updateLoan::onRequestCreateOrUpdate));
   }

src/main/java/org/folio/circulation/domain/MultipleRecords.java

@@ -4,7 +4,9 @@
 import static java.util.stream.Stream.concat;
 import static org.folio.circulation.support.json.JsonObjectArrayPropertyFetcher.mapToList;
 import static org.folio.circulation.support.results.Result.succeeded;
+import static org.folio.circulation.support.utils.LogUtil.multipleRecordsAsString;
 
+import java.lang.invoke.MethodHandles;
 import java.util.ArrayList;
 import java.util.Collection;
 import java.util.List;
@@ -16,6 +18,8 @@
 import java.util.function.Predicate;
 import java.util.stream.Collectors;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.folio.circulation.support.http.client.Response;
 import org.folio.circulation.support.http.client.ResponseInterpreter;
 import org.folio.circulation.support.results.Result;
@@ -25,6 +29,7 @@
 
 public class MultipleRecords<T> {
   private static final String TOTAL_RECORDS_PROPERTY_NAME = "totalRecords";
+  private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass());
 
   private final Collection<T> records;
   private final Integer totalRecords;
@@ -38,19 +43,22 @@ public static <T> MultipleRecords<T> empty() {
     return new MultipleRecords<>(new ArrayList<>(), 0);
   }
 
-  public static <T> Result<MultipleRecords<T>> from(
-    Response response,
-    Function<JsonObject, T> mapper,
-    String recordsPropertyName) {
+  public static <T> Result<MultipleRecords<T>> from(Response response,
+    Function<JsonObject, T> mapper, String recordsPropertyName) {
+
+    log.debug("from:: parameters response: {}, recordsPropertyName: {}",
+      response, recordsPropertyName);
 
     return new ResponseInterpreter<MultipleRecords<T>>()
       .flatMapOn(200, r -> from(r.getJson(), mapper, recordsPropertyName))
       .apply(response);
   }
 
   public static <T> Result<MultipleRecords<T>> from(JsonObject representation,
-                                                    Function<JsonObject, T> mapper,
-                                                    String recordsPropertyName) {
+    Function<JsonObject, T> mapper, String recordsPropertyName) {
+
+    log.debug("from:: parameters representation: {}, recordsPropertyName: {}",
+      () -> representation, () -> recordsPropertyName);
 
     List<T> wrappedRecords = mapToList(representation, recordsPropertyName, mapper);
     Integer totalRecords = representation.getInteger(TOTAL_RECORDS_PROPERTY_NAME);
@@ -63,6 +71,9 @@ public <R> MultipleRecords<T> combineRecords(MultipleRecords<R> otherRecords,
     Function<T, Predicate<R>> matcher,
     BiFunction<T, R, T> combiner, R defaultOtherRecord) {
 
+    log.debug("combineRecords:: parameters otherRecords: {}",
+      () -> multipleRecordsAsString(otherRecords));
+
     return mapRecords(mainRecord -> combiner.apply(mainRecord, otherRecords
       .filter(matcher.apply(mainRecord))
       .firstOrElse(defaultOtherRecord)));
@@ -113,6 +124,7 @@ public <R> Result<MultipleRecords<R>> flatMapRecords(Function<T, Result<R>> mapp
   }
 
   public MultipleRecords<T> combine(MultipleRecords<T> other) {
+    log.debug("combine:: parameters other: {}", () -> multipleRecordsAsString(other));
     final List<T> allRecords = concat(records.stream(), other.records.stream())
       .collect(Collectors.toList());
 
@@ -125,13 +137,11 @@ public MultipleRecords<T> filter(Predicate<T> predicate) {
       .collect(Collectors.toList());
 
     final int numberOfFilteredOutRecords = totalRecords - filteredRecords.size();
+    log.info("filter:: totalRecords: {}", totalRecords);
     return new MultipleRecords<>(filteredRecords, totalRecords - numberOfFilteredOutRecords);
   }
 
-  public JsonObject asJson(
-    Function<T, JsonObject> mapper,
-    String recordsPropertyName) {
-
+  public JsonObject asJson(Function<T, JsonObject> mapper, String recordsPropertyName) {
     final List<JsonObject> mappedRecords = getRecords().stream()
       .map(mapper)
       .collect(Collectors.toList());

src/main/java/org/folio/circulation/domain/OpeningDay.java

@@ -6,13 +6,16 @@
 import static org.folio.circulation.support.json.JsonPropertyFetcher.getLocalDateProperty;
 import static org.folio.circulation.support.json.JsonPropertyWriter.write;
 
+import java.lang.invoke.MethodHandles;
 import java.time.LocalDate;
 import java.time.ZoneId;
 import java.time.ZonedDateTime;
 import java.util.Collections;
 import java.util.List;
 import java.util.stream.Collector;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.folio.circulation.support.utils.DateTimeUtil;
 
 import lombok.AllArgsConstructor;
@@ -31,6 +34,7 @@ public class OpeningDay {
   private static final String ALL_DAY_KEY = "allDay";
   private static final String OPEN_KEY = "open";
   private static final String OPENINGS_KEY = "openings";
+  private static final Logger log = LogManager.getLogger(MethodHandles.lookup().lookupClass());
 
   private final List<OpeningHour> openings;
   private final LocalDate date;
@@ -99,6 +103,7 @@ public JsonObject toJson() {
     write(json, ALL_DAY_KEY, allDay);
     write(json, OPEN_KEY, open);
     write(json, OPENINGS_KEY, openingHourToJsonArray());
+    log.debug("toJson:: result: {}", () -> json);
 
     return json;
   }
@@ -107,6 +112,7 @@ public JsonObject toJson() {
    * Create a list of {@link OpeningHour OpeningHour} from the provided daily opening object
    */
   private static List<OpeningHour> createOpeningTimes(JsonObject representation) {
+    log.debug("createOpeningTimes:: parameters representation: {}", () -> representation);
     return mapToList(representation, OPENINGS_KEY, OpeningHour::new);
   }
 }