From 736124866b6ca0da0a90f0ccfa9f81c9483b373b Mon Sep 17 00:00:00 2001 From: Jacopo Carlini Date: Mon, 14 Oct 2024 12:30:47 +0200 Subject: [PATCH] feat(logging): sampling + enhancement logging + kibana --- Dockerfile | 5 +- helm/values-dev.yaml | 4 +- helm/values-prod.yaml | 2 + helm/values-uat.yaml | 2 + pom.xml | 5 + .../config/LoggingAspect.java | 238 +++++++++++------- .../util/CommonUtil.java | 17 ++ src/main/resources/application.properties | 2 +- src/main/resources/logback-spring.xml | 36 +++ 9 files changed, 209 insertions(+), 102 deletions(-) create mode 100644 src/main/java/it/gov/pagopa/reportingorgsenrollment/util/CommonUtil.java create mode 100644 src/main/resources/logback-spring.xml diff --git a/Dockerfile b/Dockerfile index 6f01ae3..fae0b43 100644 --- a/Dockerfile +++ b/Dockerfile @@ -9,12 +9,11 @@ COPY --from=buildtime /build/target/*.jar application.jar RUN java -Djarmode=layertools -jar application.jar extract -FROM ghcr.io/pagopa/docker-base-springboot-openjdk11:v1.0.1@sha256:bbbe948e91efa0a3e66d8f308047ec255f64898e7f9250bdb63985efd3a95dbf +FROM ghcr.io/pagopa/docker-base-springboot-openjdk17:v2.2.0@sha256:b866656c31f2c6ebe6e78b9437ce930d6c94c0b4bfc8e9ecc1076a780b9dfb18 + COPY --chown=spring:spring --from=builder dependencies/ ./ COPY --chown=spring:spring --from=builder snapshot-dependencies/ ./ # 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 \ No newline at end of file diff --git a/helm/values-dev.yaml b/helm/values-dev.yaml index ad98c83..df8807c 100644 --- a/helm/values-dev.yaml +++ b/helm/values-dev.yaml @@ -52,7 +52,7 @@ microservice-chart: autoscaling: enable: true minReplica: 1 - maxReplica: 3 + maxReplica: 1 pollingInterval: 10 # seconds cooldownPeriod: 50 # seconds triggers: @@ -62,7 +62,9 @@ microservice-chart: type: Utilization # Allowed types are 'Utilization' or 'AverageValue' value: "75" envConfig: + ENV: 'dev' WEBSITE_SITE_NAME: 'pagopa-d-reporting-orgs-enrollment-service' # required to show cloud role name in application insights + SERVICE_NAME: 'pagopa-reporting-orgs-enrollment' LOGGING_LEVEL: "INFO" ORGANIZATIONS_TABLE: pagopadflowsaorgstable envSecret: diff --git a/helm/values-prod.yaml b/helm/values-prod.yaml index a79117f..ed98342 100644 --- a/helm/values-prod.yaml +++ b/helm/values-prod.yaml @@ -62,7 +62,9 @@ microservice-chart: type: Utilization # Allowed types are 'Utilization' or 'AverageValue' value: "75" envConfig: + ENV: 'prod' WEBSITE_SITE_NAME: 'pagopa-reporting-orgs-enrollment-service' # required to show cloud role name in application insights + SERVICE_NAME: 'pagopa-reporting-orgs-enrollment' LOGGING_LEVEL: "INFO" ORGANIZATIONS_TABLE: pagopapflowsaorgstable envSecret: diff --git a/helm/values-uat.yaml b/helm/values-uat.yaml index 4f42717..30cf5f2 100644 --- a/helm/values-uat.yaml +++ b/helm/values-uat.yaml @@ -62,7 +62,9 @@ microservice-chart: type: Utilization # Allowed types are 'Utilization' or 'AverageValue' value: "75" envConfig: + ENV: 'uat' WEBSITE_SITE_NAME: 'pagopa-u-reporting-orgs-enrollment-service' # required to show cloud role name in application insights + SERVICE_NAME: 'pagopa-reporting-orgs-enrollment' LOGGING_LEVEL: "INFO" ORGANIZATIONS_TABLE: pagopauflowsaorgstable envSecret: diff --git a/pom.xml b/pom.xml index 516c55b..ad69af1 100644 --- a/pom.xml +++ b/pom.xml @@ -73,6 +73,11 @@ junit-jupiter test + + co.elastic.logging + logback-ecs-encoder + 1.6.0 + diff --git a/src/main/java/it/gov/pagopa/reportingorgsenrollment/config/LoggingAspect.java b/src/main/java/it/gov/pagopa/reportingorgsenrollment/config/LoggingAspect.java index 74e28cc..a3acccd 100644 --- a/src/main/java/it/gov/pagopa/reportingorgsenrollment/config/LoggingAspect.java +++ b/src/main/java/it/gov/pagopa/reportingorgsenrollment/config/LoggingAspect.java @@ -1,117 +1,161 @@ package it.gov.pagopa.reportingorgsenrollment.config; +import it.gov.pagopa.reportingorgsenrollment.exception.AppError; +import it.gov.pagopa.reportingorgsenrollment.model.ProblemJson; 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; +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; +import java.util.HashMap; +import java.util.Map; +import java.util.UUID; + +import static it.gov.pagopa.reportingorgsenrollment.util.CommonUtil.deNull; + @Aspect @Component @Slf4j public class LoggingAspect { - @Value("${info.application.artifactId}") - private String name; - - @Value("${info.application.version}") - private String version; - - @Value("${info.properties.environment}") - private String environment; - - - @Pointcut("@within(org.springframework.web.bind.annotation.RestController)") - public void restController() { - // all rest controllers - } - - @Pointcut("execution(* it.gov.pagopa.reportingorgsenrollment.repository..*.*(..))") - public void repository() { - // all repository methods - } - - @Pointcut("execution(* it.gov.pagopa.reportingorgsenrollment.service..*.*(..))") - public void service() { - // all service methods - } - - @Pointcut("execution(* it.gov.pagopa.reportingorgsenrollment.exception.ErrorHandler.*(..))") - public void errorHandler() { - // all service methods - } - - /** - * Log essential info of application during the startup. - */ - @PostConstruct - public void logStartup() { - log.info("-> Starting {} version {} - environment {}", name, version, environment); - } - - /** - * 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))); - } - - @Before(value = "restController()") - public void logApiInvocation(JoinPoint joinPoint) { - log.info("Invoking API operation {} - args: {}", joinPoint.getSignature().getName(), joinPoint.getArgs()); - } - - @AfterReturning(value = "restController()", returning = "result") - public void returnApiInvocation(JoinPoint joinPoint, Object result) { - log.info("Successful API operation {} - result: {}", joinPoint.getSignature().getName(), result); - } - - @AfterReturning(value = "errorHandler()", returning = "result") - public void trowingApiInvocation(JoinPoint joinPoint, Object result) { - log.info("Failed API operation {} - error: {}", joinPoint.getSignature().getName(), result); - } - - @Around(value = "repository() || service()") - public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable { - long startTime = System.currentTimeMillis(); - Object result = joinPoint.proceed(); - long endTime = System.currentTimeMillis(); - log.trace("Time taken for Execution of {} is: {}ms", joinPoint.getSignature().toShortString(), (endTime - startTime)); - return result; - } - - @Around(value = "repository() || service()") - public Object logTrace(ProceedingJoinPoint joinPoint) throws Throwable { - log.debug("Call method {} - args: {}", joinPoint.getSignature().toShortString(), joinPoint.getArgs()); - Object result = joinPoint.proceed(); - log.debug("Return method {} - result: {}", joinPoint.getSignature().toShortString(), result); - return result; - } + 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"; + + final HttpServletRequest httRequest; + + final HttpServletResponse httpResponse; + + @Value("${info.application.name}") + private String name; + + @Value("${info.application.version}") + private String version; + + @Value("${info.properties.environment}") + private String environment; + + 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(); + } + + 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 "-"; + } + + 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 + } + + @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()") + 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.debug("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/reportingorgsenrollment/util/CommonUtil.java b/src/main/java/it/gov/pagopa/reportingorgsenrollment/util/CommonUtil.java new file mode 100644 index 0000000..9baf377 --- /dev/null +++ b/src/main/java/it/gov/pagopa/reportingorgsenrollment/util/CommonUtil.java @@ -0,0 +1,17 @@ +package it.gov.pagopa.reportingorgsenrollment.util; + +import java.util.Optional; + +public class CommonUtil { + + private CommonUtil() { + } + + /** + * @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(); + } +} \ No newline at end of file diff --git a/src/main/resources/application.properties b/src/main/resources/application.properties index 8a6897a..8c2f194 100644 --- a/src/main/resources/application.properties +++ b/src/main/resources/application.properties @@ -3,7 +3,7 @@ info.application.artifactId=@project.artifactId@ info.application.name=@project.name@ info.application.version=@project.version@ info.application.description=@project.description@ -info.properties.environment=azure +info.properties.environment=${ENV:azure} # Storage Account reporting.sa.connection=${FLOW_SA_CONNECTION_STRING} organizations.table=${ORGANIZATIONS_TABLE} diff --git a/src/main/resources/logback-spring.xml b/src/main/resources/logback-spring.xml new file mode 100644 index 0000000..dfa8a34 --- /dev/null +++ b/src/main/resources/logback-spring.xml @@ -0,0 +1,36 @@ + + + + + + + + + + + %clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(%5p) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m %clr(%mdc){magenta}%n%wEx + + + + + + + + + + + + + + ${SERVICE_NAME} + ${ECS_SERVICE_VERSION} + ${ENV} + + + + + + + + + \ No newline at end of file