chore(logging): sampling and improvements for logging [PAGOPA-2178]

.github/workflows/release_deploy.yml

@@ -21,9 +21,8 @@ on:
  type: choice
  description: Select the version
  options:
- - ''
- - skip
- - promote
+ - patch
+ - skip_or_promote
  - new_release
  - breaking_change
 
@@ -73,7 +72,7 @@ jobs:
  - if: ${{ github.ref_name != 'main' }}
  run: echo "SEMVER=buildNumber" >> $GITHUB_ENV
 
- - if: ${{ inputs.version == 'skip' || inputs.version == 'promote' }}
+ - if: ${{ inputs.version == 'skip_or_promote' }}
  run: echo "SEMVER=skip" >> $GITHUB_ENV
 
  - id: get_semver

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"]

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
+ }
+ ]
+ }
+}

helm/Chart.yaml

@@ -2,8 +2,8 @@ apiVersion: v2
 name: pagopa-gpd-payments
 description: Microservice that exposes API for payment receipts retrieving and other operations
 type: application
-version: 0.102.0
-appVersion: 0.12.28
+version: 0.106.0
+appVersion: 0.12.28-4-PAGOPA-2178-gpd-debito-tecnico-ottimizzazione-dei-log
 dependencies:
  - name: microservice-chart
  version: 2.4.0

helm/values-dev.yaml

@@ -4,7 +4,7 @@ microservice-chart:
  fullnameOverride: ""
  image:
  repository: ghcr.io/pagopa/pagopa-gpd-payments
- tag: "0.12.28"
+ tag: "0.12.28-4-PAGOPA-2178-gpd-debito-tecnico-ottimizzazione-dei-log"
  pullPolicy: Always
  livenessProbe:
  httpGet:

helm/values-prod.yaml

@@ -4,7 +4,7 @@ microservice-chart:
  fullnameOverride: ""
  image:
  repository: ghcr.io/pagopa/pagopa-gpd-payments
- tag: "0.12.28"
+ tag: "0.12.28-4-PAGOPA-2178-gpd-debito-tecnico-ottimizzazione-dei-log"
  pullPolicy: Always
  livenessProbe:
  httpGet:

helm/values-uat.yaml

@@ -4,7 +4,7 @@ microservice-chart:
  fullnameOverride: ""
  image:
  repository: ghcr.io/pagopa/pagopa-gpd-payments
- tag: "0.12.28"
+ tag: "0.12.28-4-PAGOPA-2178-gpd-debito-tecnico-ottimizzazione-dei-log"
  pullPolicy: Always
  livenessProbe:
  httpGet:

openapi/openapi.json

@@ -4,7 +4,7 @@
  "title": "PagoPA API Payments",
  "description": "Payments",
  "termsOfService": "https://www.pagopa.gov.it/",
- "version": "0.12.28"
+ "version": "0.12.28-4-PAGOPA-2178-gpd-debito-tecnico-ottimizzazione-dei-log"
  },
  "servers": [
  {

pom.xml

@@ -13,7 +13,7 @@
 
  <groupId>it.gov.pagopa</groupId>
  <artifactId>payments</artifactId>
- <version>0.12.28</version>
+ <version>0.12.28-4-PAGOPA-2178-gpd-debito-tecnico-ottimizzazione-dei-log</version>
  <name>Payments</name>
  <description>Payments</description>
 

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<ProblemJson> 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<ProblemJson> 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<String, String> getParams(ProceedingJoinPoint joinPoint) {
+ CodeSignature codeSignature = (CodeSignature) joinPoint.getSignature();
+ Map<String, String> 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<String, String> 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<ProblemJson> 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<String, String> 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;
+ }
 }

src/main/java/it/gov/pagopa/payments/config/SwaggerConfig.java

@@ -22,8 +22,8 @@ public class SwaggerConfig {
 
  @Bean
  public OpenAPI customOpenAPI(
- @Value("${application.description}") String appDescription,
- @Value("${application.version}") String appVersion) {
+ @Value("${info.application.description}") String appDescription,
+ @Value("${info.application.version}") String appVersion) {
  return new OpenAPI()
  .components(
  new Components()
@@ -55,7 +55,10 @@ public OpenAPI customOpenAPI(
  public OpenApiCustomiser sortOperationsAlphabetically() {
  return openApi -> {
  Paths paths =
- openApi.getPaths().entrySet().stream()
+ openApi
+ .getPaths()
+ .entrySet()
+ .stream()
  .sorted(Map.Entry.comparingByKey())
  .collect(
  Paths::new,
@@ -68,7 +71,10 @@ public OpenApiCustomiser sortOperationsAlphabetically() {
  .forEach(
  operation -> {
  var responses =
- operation.getResponses().entrySet().stream()
+ operation
+ .getResponses()
+ .entrySet()
+ .stream()
  .sorted(Map.Entry.comparingByKey())
  .collect(
  ApiResponses::new,