From 1c233ea52ce6e4826551c02cbfebb0995bc22db0 Mon Sep 17 00:00:00 2001 From: Jacopo Carlini Date: Wed, 25 Sep 2024 10:00:14 +0200 Subject: [PATCH] logging --- Dockerfile | 6 + docker/applicationinsights.json | 27 +++ .../pagopa/payments/config/LoggingAspect.java | 202 ++++++++++++------ .../pagopa/payments/entity/ReceiptEntity.java | 6 +- .../payments/model/PaymentsModelResponse.java | 4 + .../payments/model/ReceiptModelResponse.java | 2 + .../model/spontaneous/DebtorModel.java | 11 +- .../spontaneous/PaymentPositionModel.java | 10 +- .../pagopa/payments/scheduler/Scheduler.java | 22 +- .../gov/pagopa/payments/utils/CommonUtil.java | 9 + .../pagopa/payments/utils/SchedulerUtils.java | 35 +++ 11 files changed, 252 insertions(+), 82 deletions(-) create mode 100644 docker/applicationinsights.json create mode 100644 src/main/java/it/gov/pagopa/payments/utils/SchedulerUtils.java diff --git a/Dockerfile b/Dockerfile index a35f12cc..ab2f296c 100644 --- a/Dockerfile +++ b/Dockerfile @@ -15,11 +15,17 @@ RUN java -Djarmode=layertools -jar application.jar extract FROM ghcr.io/pagopa/docker-base-springboot-openjdk17:v1.1.0@sha256:6fa320d452fa22066441f1ef292d15eb06f944bc8bca293e1a91ea460d30a613 +ADD --chown=spring:spring https://github.com/open-telemetry/opentelemetry-java-instrumentation/releases/download/v1.25.1/opentelemetry-javaagent.jar . + COPY --chown=spring:spring --from=builder dependencies/ ./ COPY --chown=spring:spring --from=builder snapshot-dependencies/ ./ +COPY --chown=spring:spring docker/applicationinsights.json ./applicationinsights.json + # https://github.com/moby/moby/issues/37965#issuecomment-426853382 RUN true COPY --chown=spring:spring --from=builder spring-boot-loader/ ./ COPY --chown=spring:spring --from=builder application/ ./ EXPOSE 8080 + +ENTRYPOINT ["java","-javaagent:opentelemetry-javaagent.jar","--enable-preview","org.springframework.boot.loader.JarLauncher"] \ No newline at end of file diff --git a/docker/applicationinsights.json b/docker/applicationinsights.json new file mode 100644 index 00000000..07b03ef0 --- /dev/null +++ b/docker/applicationinsights.json @@ -0,0 +1,27 @@ +{ + "selfDiagnostics": { + "destination": "console", + "level": "INFO" + }, + "sampling": { + "percentage": 5, + "overrides": [ + { + "telemetryType": "request", + "percentage": 5 + }, + { + "telemetryType": "dependency", + "percentage": 5 + }, + { + "telemetryType": "trace", + "percentage": 5 + }, + { + "telemetryType": "exception", + "percentage": 100 + } + ] + } +} \ No newline at end of file diff --git a/src/main/java/it/gov/pagopa/payments/config/LoggingAspect.java b/src/main/java/it/gov/pagopa/payments/config/LoggingAspect.java index b53627fc..6daa0011 100644 --- a/src/main/java/it/gov/pagopa/payments/config/LoggingAspect.java +++ b/src/main/java/it/gov/pagopa/payments/config/LoggingAspect.java @@ -1,95 +1,165 @@ package it.gov.pagopa.payments.config; +import static it.gov.pagopa.payments.utils.CommonUtil.deNull; + +import it.gov.pagopa.payments.exception.AppError; +import it.gov.pagopa.payments.model.ProblemJson; +import java.util.HashMap; +import java.util.Map; +import java.util.UUID; +import javax.annotation.PostConstruct; +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; import lombok.extern.slf4j.Slf4j; import org.aspectj.lang.JoinPoint; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.AfterReturning; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; -import org.aspectj.lang.annotation.Before; +import org.aspectj.lang.annotation.Pointcut; +import org.aspectj.lang.reflect.CodeSignature; +import org.slf4j.MDC; import org.springframework.beans.factory.annotation.Value; -import org.springframework.context.event.ContextRefreshedEvent; -import org.springframework.context.event.EventListener; -import org.springframework.core.env.AbstractEnvironment; -import org.springframework.core.env.EnumerablePropertySource; -import org.springframework.core.env.Environment; -import org.springframework.core.env.MutablePropertySources; +import org.springframework.http.ResponseEntity; import org.springframework.stereotype.Component; -import javax.annotation.PostConstruct; -import java.util.Arrays; -import java.util.stream.StreamSupport; - @Aspect @Component @Slf4j public class LoggingAspect { - @Value("${application.name}") - private String name; + public static final String START_TIME = "startTime"; + public static final String METHOD = "method"; + public static final String STATUS = "status"; + public static final String CODE = "httpCode"; + public static final String RESPONSE_TIME = "responseTime"; + public static final String FAULT_CODE = "faultCode"; + public static final String FAULT_DETAIL = "faultDetail"; + public static final String REQUEST_ID = "requestId"; + public static final String OPERATION_ID = "operationId"; + public static final String ARGS = "args"; - @Value("${application.version}") - private String version; + final HttpServletRequest httRequest; - @Value("${properties.environment}") - private String environment; + final HttpServletResponse httpResponse; - /** - * Log essential info of application during the startup. - */ - @PostConstruct - public void logStartup() { - log.info("-> Starting {} version {} - environment {}", name, version, environment); - } + @Value("${info.application.name}") + private String name; - /** - * If DEBUG log-level is enabled prints the env variables and the application properties. - * - * @param event Context of application - */ - @EventListener - public void handleContextRefresh(ContextRefreshedEvent event) { - final Environment env = event.getApplicationContext().getEnvironment(); - log.debug("Active profiles: {}", Arrays.toString(env.getActiveProfiles())); - final MutablePropertySources sources = ((AbstractEnvironment) env).getPropertySources(); - StreamSupport.stream(sources.spliterator(), false) - .filter(EnumerablePropertySource.class::isInstance) - .map(ps -> ((EnumerablePropertySource) ps).getPropertyNames()) - .flatMap(Arrays::stream) - .distinct() - .filter( - prop -> - !(prop.toLowerCase().contains("credentials") - || prop.toLowerCase().contains("password") - || prop.toLowerCase().contains("pass") - || prop.toLowerCase().contains("pwd"))) - .forEach(prop -> log.debug("{}: {}", prop, env.getProperty(prop))); - } + @Value("${info.application.version}") + private String version; + @Value("${info.properties.environment}") + private String environment; - @AfterReturning(value = "execution(* it.gov.pagopa.payments.controller..*.*(..)) || execution(* it.gov.pagopa.payments.endpoints..*.*(..))", returning = "result") - public void returnApiInvocation(JoinPoint joinPoint, Object result) { - log.debug("Successful API operation {} - result: {}", joinPoint.getSignature().getName(), result); - } + public LoggingAspect(HttpServletRequest httRequest, HttpServletResponse httpResponse) { + this.httRequest = httRequest; + this.httpResponse = httpResponse; + } + + private static String getDetail(ResponseEntity result) { + if (result != null && result.getBody() != null && result.getBody().getDetail() != null) { + return result.getBody().getDetail(); + } else return AppError.UNKNOWN.getDetails(); + } - @AfterReturning( - value = "execution(* it.gov.pagopa.payments.exception.ErrorHandler.*(..))", - returning = "result") - public void trowingApiInvocation(JoinPoint joinPoint, Object result) { - log.info("Failed API operation {} - error: {}", joinPoint.getSignature().getName(), result); + private static String getTitle(ResponseEntity result) { + if (result != null && result.getBody() != null && result.getBody().getTitle() != null) { + return result.getBody().getTitle(); + } else return AppError.UNKNOWN.getTitle(); + } + + public static String getExecutionTime() { + String startTime = MDC.get(START_TIME); + if (startTime != null) { + long endTime = System.currentTimeMillis(); + long executionTime = endTime - Long.parseLong(startTime); + return String.valueOf(executionTime); } + return "-"; + } - @Around(value = "execution(* it.gov.pagopa.payments.service..*.*(..))") - public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable { - long startTime = System.currentTimeMillis(); - Object result = joinPoint.proceed(); - long endTime = System.currentTimeMillis(); - log.debug("Time taken for Execution of {} is: {}ms", joinPoint.getSignature().toShortString(), (endTime - startTime)); - return result; + private static Map getParams(ProceedingJoinPoint joinPoint) { + CodeSignature codeSignature = (CodeSignature) joinPoint.getSignature(); + Map params = new HashMap<>(); + int i = 0; + for (var paramName : codeSignature.getParameterNames()) { + params.put(paramName, deNull(joinPoint.getArgs()[i++])); } + return params; + } + + @Pointcut("@within(org.springframework.web.bind.annotation.RestController)") + public void restController() { + // all rest controllers + } - @Before(value = "execution(* it.gov.pagopa.payments..*.*(..))") - public void logTrace(JoinPoint joinPoint) { - log.trace("Trace method {} - args: {}", joinPoint.getSignature().toShortString(), joinPoint.getArgs()); + @Pointcut("@within(org.springframework.ws.server.endpoint.annotation.Endpoint)") + public void endpointClass() { + // all rest controllers + } + + @Pointcut("@within(org.springframework.stereotype.Repository)") + public void repository() { + // all repository methods + } + + @Pointcut("@within(org.springframework.stereotype.Service)") + public void service() { + // all service methods + } + + /** Log essential info of application during the startup. */ + @PostConstruct + public void logStartup() { + log.info("-> Starting {} version {} - environment {}", name, version, environment); + } + + @Around(value = "restController() || endpointClass()") + public Object logApiInvocation(ProceedingJoinPoint joinPoint) throws Throwable { + MDC.put(METHOD, joinPoint.getSignature().getName()); + MDC.put(START_TIME, String.valueOf(System.currentTimeMillis())); + MDC.put(OPERATION_ID, UUID.randomUUID().toString()); + if (MDC.get(REQUEST_ID) == null) { + var requestId = UUID.randomUUID().toString(); + MDC.put(REQUEST_ID, requestId); } + Map params = getParams(joinPoint); + MDC.put(ARGS, params.toString()); + + log.info("Invoking API operation {} - args: {}", joinPoint.getSignature().getName(), params); + + Object result = joinPoint.proceed(); + + MDC.put(STATUS, "OK"); + MDC.put(CODE, String.valueOf(httpResponse.getStatus())); + MDC.put(RESPONSE_TIME, getExecutionTime()); + log.info( + "Successful API operation {} - result: {}", joinPoint.getSignature().getName(), result); + MDC.remove(STATUS); + MDC.remove(CODE); + MDC.remove(RESPONSE_TIME); + MDC.remove(START_TIME); + return result; + } + + @AfterReturning(value = "execution(* *..exception.ErrorHandler.*(..))", returning = "result") + public void trowingApiInvocation(JoinPoint joinPoint, ResponseEntity result) { + MDC.put(STATUS, "KO"); + MDC.put(CODE, String.valueOf(result.getStatusCode().value())); + MDC.put(RESPONSE_TIME, getExecutionTime()); + MDC.put(FAULT_CODE, getTitle(result)); + MDC.put(FAULT_DETAIL, getDetail(result)); + log.info("Failed API operation {} - error: {}", MDC.get(METHOD), result); + MDC.clear(); + } + + @Around(value = "repository() || service()") + public Object logTrace(ProceedingJoinPoint joinPoint) throws Throwable { + Map params = getParams(joinPoint); + log.debug("Call method {} - args: {}", joinPoint.getSignature().toShortString(), params); + Object result = joinPoint.proceed(); + log.debug("Return method {} - result: {}", joinPoint.getSignature().toShortString(), result); + return result; + } } diff --git a/src/main/java/it/gov/pagopa/payments/entity/ReceiptEntity.java b/src/main/java/it/gov/pagopa/payments/entity/ReceiptEntity.java index 4e2af9c0..533f9b8e 100644 --- a/src/main/java/it/gov/pagopa/payments/entity/ReceiptEntity.java +++ b/src/main/java/it/gov/pagopa/payments/entity/ReceiptEntity.java @@ -1,9 +1,6 @@ package it.gov.pagopa.payments.entity; -import lombok.AllArgsConstructor; -import lombok.Data; -import lombok.Getter; -import lombok.NoArgsConstructor; +import lombok.*; @Data @NoArgsConstructor @@ -13,6 +10,7 @@ public class ReceiptEntity { private String organizationFiscalCode; private String iuv; + @ToString.Exclude private String debtor; private String paymentDateTime; private String status = Status.PAID.name(); diff --git a/src/main/java/it/gov/pagopa/payments/model/PaymentsModelResponse.java b/src/main/java/it/gov/pagopa/payments/model/PaymentsModelResponse.java index d31092a0..5b67ef1f 100644 --- a/src/main/java/it/gov/pagopa/payments/model/PaymentsModelResponse.java +++ b/src/main/java/it/gov/pagopa/payments/model/PaymentsModelResponse.java @@ -32,7 +32,9 @@ public class PaymentsModelResponse implements Serializable { private String idFlowReporting; private PaymentOptionStatus status; private Type type; + @ToString.Exclude private String fiscalCode; + @ToString.Exclude private String fullName; private String streetName; private String civicNumber; @@ -41,7 +43,9 @@ public class PaymentsModelResponse implements Serializable { private String province; private String region; private String country; + @ToString.Exclude private String email; + @ToString.Exclude private String phone; private String companyName; private String officeName; diff --git a/src/main/java/it/gov/pagopa/payments/model/ReceiptModelResponse.java b/src/main/java/it/gov/pagopa/payments/model/ReceiptModelResponse.java index 8b33e44a..e7c6c312 100644 --- a/src/main/java/it/gov/pagopa/payments/model/ReceiptModelResponse.java +++ b/src/main/java/it/gov/pagopa/payments/model/ReceiptModelResponse.java @@ -3,6 +3,7 @@ import lombok.Getter; import lombok.NoArgsConstructor; import lombok.Setter; +import lombok.ToString; import lombok.experimental.SuperBuilder; @Getter @@ -13,6 +14,7 @@ public class ReceiptModelResponse { private String organizationFiscalCode; private String iuv; + @ToString.Exclude private String debtor; private String paymentDateTime; private String status; diff --git a/src/main/java/it/gov/pagopa/payments/model/spontaneous/DebtorModel.java b/src/main/java/it/gov/pagopa/payments/model/spontaneous/DebtorModel.java index 70fd2d5a..e1cd1091 100644 --- a/src/main/java/it/gov/pagopa/payments/model/spontaneous/DebtorModel.java +++ b/src/main/java/it/gov/pagopa/payments/model/spontaneous/DebtorModel.java @@ -5,11 +5,8 @@ import javax.validation.constraints.Email; import javax.validation.constraints.NotBlank; import javax.validation.constraints.NotNull; -import lombok.AccessLevel; -import lombok.AllArgsConstructor; -import lombok.Builder; -import lombok.Data; -import lombok.NoArgsConstructor; + +import lombok.*; @Data @NoArgsConstructor @@ -21,9 +18,11 @@ public class DebtorModel implements Serializable { private Type type; @NotBlank(message = "fiscal code is required") + @ToString.Exclude private String fiscalCode; @NotBlank(message = "full name is required") + @ToString.Exclude private String fullName; private String streetName; @@ -41,7 +40,9 @@ public class DebtorModel implements Serializable { private String country; @Email(message = "Please provide a valid email address") + @ToString.Exclude private String email; + @ToString.Exclude private String phone; } diff --git a/src/main/java/it/gov/pagopa/payments/model/spontaneous/PaymentPositionModel.java b/src/main/java/it/gov/pagopa/payments/model/spontaneous/PaymentPositionModel.java index 4d7da320..d9598f34 100644 --- a/src/main/java/it/gov/pagopa/payments/model/spontaneous/PaymentPositionModel.java +++ b/src/main/java/it/gov/pagopa/payments/model/spontaneous/PaymentPositionModel.java @@ -11,10 +11,8 @@ import javax.validation.constraints.Email; import javax.validation.constraints.NotBlank; import javax.validation.constraints.NotNull; -import lombok.AllArgsConstructor; -import lombok.Builder; -import lombok.Data; -import lombok.NoArgsConstructor; + +import lombok.*; @Builder @Data @@ -29,9 +27,11 @@ public class PaymentPositionModel implements Serializable { private Type type; @NotBlank(message = "fiscal code is required") + @ToString.Exclude private String fiscalCode; @NotBlank(message = "full name is required") + @ToString.Exclude private String fullName; private String streetName; @@ -49,8 +49,10 @@ public class PaymentPositionModel implements Serializable { private String country; @Email(message = "Please provide a valid email address") + @ToString.Exclude private String email; + @ToString.Exclude private String phone; @Schema( diff --git a/src/main/java/it/gov/pagopa/payments/scheduler/Scheduler.java b/src/main/java/it/gov/pagopa/payments/scheduler/Scheduler.java index fed08bfb..ffd699f5 100644 --- a/src/main/java/it/gov/pagopa/payments/scheduler/Scheduler.java +++ b/src/main/java/it/gov/pagopa/payments/scheduler/Scheduler.java @@ -1,7 +1,9 @@ package it.gov.pagopa.payments.scheduler; import it.gov.pagopa.payments.service.SchedulerService; +import it.gov.pagopa.payments.utils.SchedulerUtils; import lombok.extern.slf4j.Slf4j; +import org.slf4j.MDC; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; import org.springframework.scheduling.annotation.Async; @@ -12,6 +14,8 @@ import java.time.LocalDateTime; import java.time.format.DateTimeFormatter; +import static it.gov.pagopa.payments.utils.SchedulerUtils.*; + @Component @Slf4j @EnableScheduling @@ -28,9 +32,21 @@ public class Scheduler { @Scheduled(cron = "${cron.job.schedule.expression.retry.trigger}") @Async public void retryPaSendRT() { - log.info(String.format(LOG_BASE_HEADER_INFO, CRON_JOB, "retry sendRT", "Running at " + DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss").format(LocalDateTime.now()))); - schedulerService.retryFailedPaSendRT(); - this.threadOfExecution = Thread.currentThread(); + try { + updateMDCForStartExecution("retryPaSendRT", ""); + log.info(String.format(LOG_BASE_HEADER_INFO, CRON_JOB, "retry sendRT", "Running at " + DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss").format(LocalDateTime.now()))); + schedulerService.retryFailedPaSendRT(); + this.threadOfExecution = Thread.currentThread(); + updateMDCForEndExecution(); + } + catch (Exception e){ + updateMDCError(e, "retryPaSendRT"); + throw e; + } + finally { + MDC.clear(); + } + } public Thread getThreadOfExecution() { diff --git a/src/main/java/it/gov/pagopa/payments/utils/CommonUtil.java b/src/main/java/it/gov/pagopa/payments/utils/CommonUtil.java index b212af0b..145fb97d 100644 --- a/src/main/java/it/gov/pagopa/payments/utils/CommonUtil.java +++ b/src/main/java/it/gov/pagopa/payments/utils/CommonUtil.java @@ -7,6 +7,7 @@ import java.time.ZoneId; import java.util.Date; import java.util.GregorianCalendar; +import java.util.Optional; import javax.xml.XMLConstants; import javax.xml.stream.XMLInputFactory; import javax.xml.stream.XMLStreamException; @@ -58,4 +59,12 @@ public static GregorianCalendar convertToGregorianCalendar(LocalDateTime dateToC public static String sanitizeInput(String input) { return input != null ? input.replace("\n", "").replaceAll("[^a-zA-Z0-9_\\-+/]", "") : ""; } + + /** + * @param value value to deNullify. + * @return return empty string if value is null + */ + public static String deNull(Object value) { + return Optional.ofNullable(value).orElse("").toString(); + } } diff --git a/src/main/java/it/gov/pagopa/payments/utils/SchedulerUtils.java b/src/main/java/it/gov/pagopa/payments/utils/SchedulerUtils.java new file mode 100644 index 00000000..a762e390 --- /dev/null +++ b/src/main/java/it/gov/pagopa/payments/utils/SchedulerUtils.java @@ -0,0 +1,35 @@ +package it.gov.pagopa.payments.utils; + +import org.slf4j.MDC; + +import java.util.Calendar; +import java.util.UUID; + +import static it.gov.pagopa.payments.config.LoggingAspect.*; + + +public class SchedulerUtils { + + public static void updateMDCForStartExecution(String method, String args) { + MDC.put(METHOD, method); + MDC.put(START_TIME, String.valueOf(Calendar.getInstance().getTimeInMillis())); + MDC.put(REQUEST_ID, UUID.randomUUID().toString()); + MDC.put(OPERATION_ID, UUID.randomUUID().toString()); + MDC.put(ARGS, args); + } + + public static void updateMDCForEndExecution() { + MDC.put(STATUS, "OK"); + MDC.put(CODE, "201"); + MDC.put(RESPONSE_TIME, getExecutionTime()); + } + + public static void updateMDCError(Exception e, String method) { + MDC.put(STATUS, "KO"); + MDC.put(CODE, "500"); + MDC.put(RESPONSE_TIME, getExecutionTime()); + MDC.put(FAULT_CODE, method); + MDC.put(FAULT_DETAIL, e.getMessage()); + } + +}