Skip to content

Commit

Permalink
perf($Log): enhance web request log format
Browse files Browse the repository at this point in the history
  • Loading branch information
Johnny Miller (锺俊) committed Dec 17, 2020
1 parent 81a16d1 commit a359d07
Showing 1 changed file with 37 additions and 23 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -35,10 +35,31 @@ public class WebRequestLogAspect {
private static final int MAX_LENGTH_OF_JSON_STRING = 500;
private static final String LINE_SEPARATOR = System.lineSeparator();
private final ObjectMapper mapper = new ObjectMapper();
private final String beforeTemplate = LINE_SEPARATOR +
"============ WEB REQUEST LOG AOP (@Before) ============" + LINE_SEPARATOR +
"URL : {}" + LINE_SEPARATOR +
"HTTP Method : {}" + LINE_SEPARATOR +
"Client IP:Port : {}" + LINE_SEPARATOR +
"Class Method : {}#{}" + LINE_SEPARATOR +
"Request Params :{}{}";
private final String afterTemplate = LINE_SEPARATOR +
"============ WEB REQUEST LOG AOP (@After) =============";
private final String aroundTemplateForJson = LINE_SEPARATOR +
"Response :{}{}";
private final String aroundTemplateForNonJson = LINE_SEPARATOR +
"Response (non-JSON): {}";
private final String aroundTemplateEnd = LINE_SEPARATOR +
"Elapsed time : {} ({} ms)" + LINE_SEPARATOR +
"============ WEB REQUEST LOG AOP (@Around) ============";
private final String afterThrowingTemplate = LINE_SEPARATOR +
"Signature : {}" + LINE_SEPARATOR +
"Exception : {}, message: {}" + LINE_SEPARATOR +
"======== WEB REQUEST LOG AOP (@AfterThrowing) =========";

/**
* Define pointcut. Pointcut is a predicate or expression that matches join points. In WebRequestLogAspect, we need
* to cut any method annotated with `@GetMapping`, `@PostMapping`, `@PutMapping`, `@DeleteMapping`, `@PatchMapping`, `@RequestMapping`.
* to cut any method annotated with `@GetMapping`, `@PostMapping`, `@PutMapping`, `@DeleteMapping`,
* `@PatchMapping`, `@RequestMapping`.
* <p>
* More detail at: <a href="https://howtodoinjava.com/spring-aop/aspectj-pointcut-expressions/">Spring aop aspectJ
* pointcut expression examples</a>
Expand All @@ -64,14 +85,17 @@ public void beforeHandleRequest(JoinPoint joinPoint) {
val attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
assert attributes != null;
val request = attributes.getRequest();
log.info("============ WEB REQUEST LOG START ============");
log.info("URL : {}", request.getRequestURL().toString());
log.info("HTTP Method : {}", request.getMethod());
log.info("Client IP:Port : {}", RequestUtil.getRequestIpAndPort(request));
log.info("Class Method : {}#{}",
joinPoint.getSignature().getDeclaringTypeName(),
joinPoint.getSignature().getName());
log.info("Request Params :{}{}", LINE_SEPARATOR, JSONUtil.toJsonPrettyStr(joinPoint.getArgs()));
log.info(beforeTemplate, request.getRequestURL().toString(), request.getMethod(),
RequestUtil.getRequestIpAndPort(request), joinPoint.getSignature().getDeclaringTypeName(),
joinPoint.getSignature().getName(), LINE_SEPARATOR, JSONUtil.toJsonPrettyStr(joinPoint.getArgs()));
}

/**
* `@After` annotated methods run exactly after the all methods matching with pointcut expression.
*/
@After("requestLogPointcut()")
public void afterHandleRequest() {
log.info(afterTemplate);
}

/**
Expand All @@ -95,22 +119,14 @@ public Object aroundHandleRequest(ProceedingJoinPoint proceedingJoinPoint) throw
String.format("%s… [The length(%d) of JSON string is larger than the maximum(%d)]", substring,
formattedJsonString.length(), MAX_LENGTH_OF_JSON_STRING);
}
log.info("Response :{}{}", LINE_SEPARATOR, formattedJsonString);
log.info(aroundTemplateForJson, LINE_SEPARATOR, formattedJsonString);
} catch (JsonProcessingException e) {
log.info("Response (non-JSON): {}", result);
log.info(aroundTemplateForNonJson, result);
}
log.info("Elapsed time : {} ({} ms)", duration, duration.toMillis());
log.info(aroundTemplateEnd, duration, duration.toMillis());
return result;
}

/**
* `@After` annotated methods run exactly after the all methods matching with pointcut expression.
*/
@After("requestLogPointcut()")
public void afterHandleRequest() {
log.info("============= WEB REQUEST LOG END =============");
}

/**
* `@AfterThrowing` annotated methods run after the method (matching with pointcut expression) exits by throwing an
* exception.
Expand All @@ -120,8 +136,6 @@ public void afterHandleRequest() {
*/
@AfterThrowing(pointcut = "requestLogPointcut()", throwing = "e")
public void afterThrowingException(JoinPoint joinPoint, Exception e) {
log.info("Signature : {}", joinPoint.getSignature().toShortString());
log.error("Exception : {}, message: {}", e.toString(), e.getMessage());
log.error("====== WEB REQUEST LOG END WITH EXCEPTION =====");
log.error(afterThrowingTemplate, joinPoint.getSignature().toShortString(), e.toString(), e.getMessage());
}
}

0 comments on commit a359d07

Please sign in to comment.