Spring Boot 使用 Aspect 完整記錄(log) Restful API 的request、response，且可以寫成一行log
前言
網路上可以找到各種寫log的作法，有透過filter、interceptor、aspect
但總會有些缺陷，無法完整的記錄
像filter，只取得到request
interceptor，取得到request、response、method，但拿不到入參
不然就是response部份寫在@AfterReturning()裡，如下：
@AfterReturning(returning = "ret", pointcut = "logPointCut()")
public void doAfterReturning(Object ret) throws Throwable {
logger.info("response: " + ret);
}導致log強迫拆成多行來寫
經過多方資料的拼湊後，總算用aspect成功寫出完整的log
且可以直接一條log完整記錄！
輸出範例
實際log記錄方式，依需求自行調整，僅提供範例寫法
為便於閱讀，範例裡仍寫成多行
但可以寫成只有一行log完整記錄request、response詳細內容
GET(範例)
API：http://localhost:8080/hello?id=123&name=andy&age=18
[2021-06-18 10:17:25.988] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - ------------------------------------------
[2021-06-18 10:17:25.991] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - [0:0:0:0:0:0:0:1] [GET] [http://localhost:8080/hello] [DemoController.hello()] [46 ms]
[2021-06-18 10:17:25.992] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - -----------------REQUEST------------------
[2021-06-18 10:17:26.118] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - request parameter: {
"id" : [ "123" ],
"name" : [ "andy" ],
"age" : [ "18" ]
}
[2021-06-18 10:17:26.119] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - request body:
[2021-06-18 10:17:26.121] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - -----------------RESPONSE-----------------
[2021-06-18 10:17:26.148] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - RESPONSE: "hello!"
[2021-06-18 10:17:26.149] [http-nio-8080-exec-3] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - ------------------------------------------ POST(範例)
API：http://localhost:8080/user，新增user
[2021-06-18 10:19:47.857] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - ------------------------------------------
[2021-06-18 10:19:47.857] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - [0:0:0:0:0:0:0:1] [POST] [http://localhost:8080/user] [Cm0099Controller.createUser()] [84 ms]
[2021-06-18 10:19:47.857] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - -----------------REQUEST------------------
[2021-06-18 10:19:47.857] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - request parameter: { }
[2021-06-18 10:19:47.857] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - request body: {"name":"andy","age":18,"phone":0912345678}
[2021-06-18 10:19:47.858] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - -----------------RESPONSE-----------------
[2021-06-18 10:19:47.881] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - RESPONSE: {
"id" : "1",
"name" : "andy",
"age" : "18",
"phone" : "0912345678"
}
[2021-06-18 10:19:47.881] [http-nio-8080-exec-2] [INFO ] [com.example.demo.core.logging.HttpLogAspect] - ------------------------------------------ 作法
SpringBootApplication增加@ServletComponentScan
打開Spring Boot 入口程式，增加@ServletComponentScan裝飾器，使Spring Boot可以使用WebFilter裝飾器
@SpringBootApplication
+@ServletComponentScan
public class DemoApplication {
public static void main(String[] args) {
SpringApplication.run(DemoApplication.class, args);
}
}增加LogFilter，以wrapper request
因request的流在進入aop時被關閉了，若由request取body，會拋exception
故包裝一份在aop寫log時可以取body
@WebFilter
public class LogFilter extends OncePerRequestFilter {
private final Logger logger = LoggerFactory.getLogger(getClass());
@Override
protected void doFilterInternal(HttpServletRequest httpServletRequest,
HttpServletResponse httpServletResponse,
FilterChain filterChain) throws ServletException, IOException {
httpServletRequest = new ContentCachingRequestWrapper(httpServletRequest, 1024); // 最大長度取1024，依需要自行調整數字
filterChain.doFilter(httpServletRequest, httpServletResponse);
}
}增加LogAspect，實際寫log
相關說明都在註解裡了
@Aspect
@Component
public class LogAspect {
private final Logger logger = LoggerFactory.getLogger(getClass());
@Autowired
private ObjectMapper mapper;
@Pointcut("bean(*Controller)") // 抓取所有Controller，可依實際需求調整
public void logPointCut() { }
@Around("logPointCut()")
public Object logging(ProceedingJoinPoint joinPoint) throws Throwable {
long startTime = System.currentTimeMillis();
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
// 僅取到Controller名字，去掉前面package的路徑。實務上同一專案不同路徑卻同一命名機會應該頗低
// 若仍想印完整，拿掉`lastPointIndex`，直接印`joinPoint.getSignature().getDeclaringTypeName()`即可
int lastPointIndex = joinPoint.getSignature().getDeclaringTypeName().lastIndexOf(".") + 1;
String class_method = joinPoint.getSignature().getDeclaringTypeName().substring(lastPointIndex) + "." +
joinPoint.getSignature().getName() + "()";
Object responseBody = joinPoint.proceed();
logger.info("------------------------------------------");
// [IP] [方法(GET/POST)] [API網址] [controller.method()] [執行時間]
logger.info("[{}] [{}] [{}] [{}] [{} ms]", request.getRemoteAddr(), request.getMethod(), request.getRequestURL(), class_method, System.currentTimeMillis() - startTime);
logger.info("-----------------REQUEST------------------");
logger.info("request parameter: {}", mapper.writerWithDefaultPrettyPrinter().writeValueAsString(request.getParameterMap())); // 若想要一行呈現，拿掉`writerWithDefaultPrettyPrinter()`，寫成`mapper.writeValueAsString(參數)`即可
logger.info("request body: {}", getPayload(request));
logger.info("-----------------RESPONSE-----------------");
logger.info("RESPONSE: {}",this.mapper.writerWithDefaultPrettyPrinter().writeValueAsString(responseBody)); // / 若想要一行呈現，拿掉`writerWithDefaultPrettyPrinter()`，寫成`mapper.writeValueAsString(參數)`即可
logger.info("------------------------------------------");
return responseBody;
}
private String getPayload(HttpServletRequest request) {
ContentCachingRequestWrapper wrapper = WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
if (wrapper != null) {
byte[] buf = wrapper.getContentAsByteArray();
if (buf.length > 0) {
try {
int length = Math.min(buf.length, 1024);// 最多只印出1024長度
return new String(buf, 0, length, wrapper.getCharacterEncoding());
} catch (UnsupportedEncodingException ex) {
return "[unknown]";
}
}
}
return "";
}
}心得
網路上查到Aspect的解法，都會提到：
// ...(doBefore)...
Object object = proceedingJoinPoint.proceed();
// ...(doAfter)...
return object;但卻沒人說明到proceedingJoinPoint.proceed();回傳的object，就是responseBody！
一直在想辦法由HttpServletResponse res = attributes.getResponse();去找Body，但都找不到
而Java直接print object.toString()，也是object代號而已= =
結果答案就眼前。真是眾裡尋他千百度，就在燈火闌珊處…
參考資料
Spring AOP @Around output request parameters and return parameters
spring boot aop打印http請求回復日誌包含請求體