Skip to content

Commit

Permalink
[PASELC-655] fix: added field for request tracing on LoggingAspect
Browse files Browse the repository at this point in the history
  • Loading branch information
@andrea-deri
andrea-deri committed Jan 18, 2024
1 parent f630ed7 commit 208dc01
Show file tree
Hide file tree
Showing 2 changed files with 167 additions and 139 deletions.
274 changes: 151 additions & 123 deletions src/main/java/it/gov/pagopa/apiconfig/selfcareintegration/config/LoggingAspect.java
View file
Original file line number Diff line number Diff line change
@@ -1,10 +1,7 @@
package it.gov.pagopa.apiconfig.selfcareintegration.config;

import java.util.Arrays;
import java.util.stream.StreamSupport;
import javax.annotation.PostConstruct;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import it.gov.pagopa.apiconfig.selfcareintegration.exception.AppError;
import it.gov.pagopa.apiconfig.selfcareintegration.model.ProblemJson;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
Expand All @@ -24,133 +21,164 @@
import org.springframework.http.ResponseEntity;
import org.springframework.stereotype.Component;

import javax.annotation.PostConstruct;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.Arrays;
import java.util.UUID;
import java.util.stream.StreamSupport;

@Aspect
@Component
@Slf4j
public class LoggingAspect {

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

@Autowired
HttpServletRequest httRequest;
@Autowired
HttpServletResponse httpResponse;

@Value("${info.application.artifactId}")
private String artifactId;

@Value("${info.application.version}")
private String version;

@Value("${info.properties.environment}")
private String environment;

private 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 "1";
}

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();
}

@Pointcut("@within(org.springframework.web.bind.annotation.RestController)")
public void restController() {
// all rest controllers
}

@Pointcut("execution(* it.gov.pagopa.apiconfig.selfcareintegration.repository..*.*(..))")
public void repository() {
// all repository methods
}

@Pointcut("execution(* it.gov.pagopa.apiconfig.selfcareintegration.service..*.*(..))")
public void service() {
// all service methods
}

@Autowired HttpServletRequest httRequest;
@Autowired HttpServletResponse httpResponse;
@Pointcut("execution(* it.gov.pagopa.apiconfig.selfcareintegration.exception.ErrorHandler.*(..))")
public void errorHandler() {
// all service methods
}

@Value("${info.application.artifactId}")
private String artifactId;
/**
* Log essential info of application during the startup.
*/
@PostConstruct
public void logStartup() {
log.info("-> Starting {} version {} - environment {}", artifactId, version, environment);
}

@Value("${info.application.version}")
private String version;
/**
* 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")
|| prop.toLowerCase().contains("key")
|| prop.toLowerCase().contains("secret")))
.forEach(prop -> log.debug("{}: {}", prop, env.getProperty(prop)));
}

@Value("${info.properties.environment}")
private String 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);
}
log.info("{} {}", httRequest.getMethod(), httRequest.getRequestURI());
log.info(
"Invoking API operation {} - args: {}",
joinPoint.getSignature().getName(),
joinPoint.getArgs());

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.getStatusCodeValue()));
MDC.put(RESPONSE_TIME, getExecutionTime());
MDC.put(FAULT_CODE, getTitle((ResponseEntity<ProblemJson>) result));
MDC.put(FAULT_DETAIL, getDetail((ResponseEntity<ProblemJson>) result));
log.info("Failed API operation {} - error: {}", MDC.get(METHOD), result);
MDC.clear();
}

private 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);
@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;
}
return "1";
}

@Pointcut("@within(org.springframework.web.bind.annotation.RestController)")
public void restController() {
// all rest controllers
}

@Pointcut("execution(* it.gov.pagopa.apiconfig.selfcareintegration.repository..*.*(..))")
public void repository() {
// all repository methods
}

@Pointcut("execution(* it.gov.pagopa.apiconfig.selfcareintegration.service..*.*(..))")
public void service() {
// all service methods
}

@Pointcut("execution(* it.gov.pagopa.apiconfig.selfcareintegration.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 {}", artifactId, 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")
|| prop.toLowerCase().contains("key")
|| prop.toLowerCase().contains("secret")))
.forEach(prop -> log.debug("{}: {}", prop, env.getProperty(prop)));
}

@Around(value = "restController()")
public Object logApiInvocation(ProceedingJoinPoint joinPoint) throws Throwable {
MDC.put(METHOD, joinPoint.getSignature().getName());
MDC.put(START_TIME, String.valueOf(System.currentTimeMillis()));
log.info("{} {}", httRequest.getMethod(), httRequest.getRequestURI());
log.info(
"Invoking API operation {} - args: {}",
joinPoint.getSignature().getName(),
joinPoint.getArgs());

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.getStatusCodeValue()));
MDC.put(RESPONSE_TIME, getExecutionTime());
log.info("Failed API operation {} - error: {}", MDC.get(METHOD), result);
MDC.remove(STATUS);
MDC.remove(CODE);
MDC.remove(RESPONSE_TIME);
MDC.remove(START_TIME);
}

@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;
}
}
32 changes: 16 additions & 16 deletions src/main/java/it/gov/pagopa/apiconfig/selfcareintegration/exception/AppError.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,23 +5,23 @@

@Getter
public enum AppError {
INTERNAL_SERVER_ERROR(
HttpStatus.INTERNAL_SERVER_ERROR, "Internal Server Error", "Something was wrong"),
CREDITOR_INSTITUTION_NOT_FOUND(
HttpStatus.NOT_FOUND,
"Creditor Institution not found",
"No Creditor Institution found with code: %s"),
INTERNAL_SERVER_ERROR(
HttpStatus.INTERNAL_SERVER_ERROR, "Internal Server Error", "Something was wrong"),
CREDITOR_INSTITUTION_NOT_FOUND(
HttpStatus.NOT_FOUND,
"Creditor Institution not found",
"No Creditor Institution found with code: %s"),

BROKER_NOT_FOUND(HttpStatus.NOT_FOUND, "Broker not found", "No Broker found with code: %s"),
;
BROKER_NOT_FOUND(HttpStatus.NOT_FOUND, "Broker not found", "No Broker found with code: %s"),
UNKNOWN(null, null, null);

public final HttpStatus httpStatus;
public final String title;
public final String details;
public final HttpStatus httpStatus;
public final String title;
public final String details;

AppError(HttpStatus httpStatus, String title, String details) {
this.httpStatus = httpStatus;
this.title = title;
this.details = details;
}
AppError(HttpStatus httpStatus, String title, String details) {
this.httpStatus = httpStatus;
this.title = title;
this.details = details;
}
}

0 comments on commit 208dc01

Please sign in to comment.