Skip to content

Commit

Permalink
feat(logging): sampling + enhancement logging + kibana
Browse files Browse the repository at this point in the history
  • Loading branch information
jacopocarlini committed Oct 14, 2024
1 parent 7cfe300 commit 7361248
Show file tree
Hide file tree
Showing 9 changed files with 209 additions and 102 deletions.
5 changes: 2 additions & 3 deletions Dockerfile
Original file line number Diff line number Diff line change
Expand Up @@ -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
4 changes: 3 additions & 1 deletion helm/values-dev.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ microservice-chart:
autoscaling:
enable: true
minReplica: 1
maxReplica: 3
maxReplica: 1
pollingInterval: 10 # seconds
cooldownPeriod: 50 # seconds
triggers:
Expand All @@ -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:
Expand Down
2 changes: 2 additions & 0 deletions helm/values-prod.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
2 changes: 2 additions & 0 deletions helm/values-uat.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
5 changes: 5 additions & 0 deletions pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -73,6 +73,11 @@
<artifactId>junit-jupiter</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>co.elastic.logging</groupId>
<artifactId>logback-ecs-encoder</artifactId>
<version>1.6.0</version>
</dependency>
</dependencies>

<dependencyManagement>
Expand Down
Original file line number Diff line number Diff line change
@@ -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<ProblemJson> 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<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 "-";
}

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
}

@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<String, String> 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<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;
}
}
Original file line number Diff line number Diff line change
@@ -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();
}
}
2 changes: 1 addition & 1 deletion src/main/resources/application.properties
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ [email protected]@
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}
Expand Down
36 changes: 36 additions & 0 deletions src/main/resources/logback-spring.xml
Original file line number Diff line number Diff line change
@@ -0,0 +1,36 @@
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<springProfile name="!default">
<conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter"/>
<conversionRule conversionWord="wex" converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter"/>
<conversionRule conversionWord="wEx" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter"/>

<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
<Pattern>
%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
</Pattern>
</layout>
</appender>

<root level="INFO">
<appender-ref ref="stdout"/>
</root>
</springProfile>

<springProfile name="default">
<springProperty name="ECS_SERVICE_VERSION" source="info.application.version"/>
<appender name="ECS_JSON_CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="co.elastic.logging.logback.EcsEncoder">
<serviceName>${SERVICE_NAME}</serviceName>
<serviceVersion>${ECS_SERVICE_VERSION}</serviceVersion>
<serviceEnvironment>${ENV}</serviceEnvironment>
</encoder>
</appender>

<root level="INFO">
<appender-ref ref="ECS_JSON_CONSOLE"/>
</root>
</springProfile>

</configuration>

0 comments on commit 7361248

Please sign in to comment.