SpringBoot 学习记录(五): aop记录日志

在Spring框架应用中，我们使用aop一般都是通过配置来实现，在spring_boot中我们只需要定义一个java类，使用注解方式来实现

具体步骤如下：

一，引入依赖，在pom.xml中添加：

<dependency>      <groupId>org.springframework.boot</groupId>      <artifactId>spring-boot-starter-aop</artifactId></dependency>

二，编写切面类，这里主要是记录日志，LogAop

package com.example.aop;import java.util.Arrays;import java.util.Enumeration;import javax.servlet.http.HttpServletRequest;import org.aspectj.lang.JoinPoint;import org.aspectj.lang.ProceedingJoinPoint;import org.aspectj.lang.annotation.After;import org.aspectj.lang.annotation.AfterReturning;import org.aspectj.lang.annotation.AfterThrowing;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.slf4j.Logger;import org.slf4j.LoggerFactory;import org.springframework.core.annotation.Order;import org.springframework.stereotype.Component;import org.springframework.web.context.request.RequestAttributes;import org.springframework.web.context.request.RequestContextHolder;import org.springframework.web.context.request.ServletRequestAttributes;@Component@Aspect // 将一个java类定义为切面类@Order(-1)//如果有多个aop,这里可以定义优先级,越小级别越高public class LogAop {private Logger logger = LoggerFactory.getLogger(this.getClass());ThreadLocal<Long> startTime = new ThreadLocal<Long>();/** * 定义一个切入点,注意这里只定义controller包 */@Pointcut("execution(public * com.example.controller..*.*(..))")public void log() {}/** * 在切入点开始处切入内容 * @param joinPoint */@Before("log()")public void doBefore(JoinPoint joinPoint) {startTime.set(System.currentTimeMillis());// 接收到请求，记录请求内容logger.info("LogAop.doBefore()");RequestAttributes ra = RequestContextHolder.getRequestAttributes();  ServletRequestAttributes sra = (ServletRequestAttributes) ra;  HttpServletRequest request = sra.getRequest(); // 记录下请求内容logger.info("URL : " + request.getRequestURL().toString());logger.info("HTTP_METHOD : " + request.getMethod());logger.info("IP : " + request.getRemoteAddr());logger.info("CLASS_METHOD : " + joinPoint.getSignature().getDeclaringTypeName() + "."+ joinPoint.getSignature().getName());logger.info("ARGS : " + Arrays.toString(joinPoint.getArgs()));// 获取所有参数方法一：Enumeration<String> enu = request.getParameterNames();while (enu.hasMoreElements()) {String paraName = (String) enu.nextElement();System.out.println(paraName + ": " + request.getParameter(paraName));}}/** * 在切入点前后切入内容，并自己控制何时执行切入点自身的内容 * 可以实现拦截器的功能 */@Around("log()")public Object doAround(ProceedingJoinPoint pjp){logger.info("LogAop.doAround()");try {return pjp.proceed();} catch (Throwable e) {logger.info("exception: ", e);throw new RuntimeException("unknown error");}}/** * 用来处理当切入内容部分抛出异常之后的处理逻辑 */@AfterThrowing("log()")public void doAfterThrowing(){logger.info("LogAop.doAfterThrowing()");}/** * 在切入点结尾处切入内容 */@After("log()")public void doAfter(JoinPoint joinPoint){logger.info("LogAop.doAfter()");}/** * 在切入点return内容之后切入内容（可以用来对处理返回值做一些加工处理） * @param joinPoint */@AfterReturning("log()")public void doAfterReturning(JoinPoint joinPoint) {// 处理完请求，返回内容logger.info("LogAop.doAfterReturning()");logger.info("耗时（毫秒） : " + (System.currentTimeMillis() - startTime.get()));}}

三，测试,HelloController

package com.example.controller;import org.springframework.web.bind.annotation.RequestMapping;import org.springframework.web.bind.annotation.RestController;import org.slf4j.Logger;import org.slf4j.LoggerFactory;@RestControllerpublic class HelloController {private Logger logger =  LoggerFactory.getLogger(this.getClass());@RequestMapping("/sayHello")public String sayHello(String name){logger.info("default info logging");logger.debug("dev debug logging");logger.error("prod error logging");return "Hello: "+name;}@RequestMapping("/hello")public String hello(){logger.info("=== hello world");return "Hello World";}@RequestMapping("/hello/error")public String helloError(){logger.info("=== hello world exception");int i = Integer.parseInt("a");return "Hello World";}}

四，启动测试：

1，http://localhost:8088/spring-boot/hello

查看日志：

2017-04-11 09:31:47.023 DEBUG 7424 --- [nio-8088-exec-2] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/spring-boot/hello]2017-04-11 09:31:47.024 DEBUG 7424 --- [nio-8088-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /hello2017-04-11 09:31:47.024 DEBUG 7424 --- [nio-8088-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public java.lang.String com.example.controller.HelloController.hello()]2017-04-11 09:31:47.024 DEBUG 7424 --- [nio-8088-exec-2] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/spring-boot/hello] is: -12017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : LogAop.doAround()2017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : LogAop.doBefore()2017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : URL : http://localhost:8088/spring-boot/hello2017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : HTTP_METHOD : GET2017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : IP : 0:0:0:0:0:0:0:12017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : CLASS_METHOD : com.example.controller.HelloController.hello2017-04-11 09:31:47.025  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : ARGS : []2017-04-11 09:31:47.026  INFO 7424 --- [nio-8088-exec-2] com.example.controller.HelloController   : === hello world2017-04-11 09:31:47.026  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : LogAop.doAfter()2017-04-11 09:31:47.026  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : LogAop.doAfterReturning()2017-04-11 09:31:47.026  INFO 7424 --- [nio-8088-exec-2] com.example.aop.LogAop                   : 耗时（毫秒） : 12017-04-11 09:31:47.032 DEBUG 7424 --- [nio-8088-exec-2] m.m.a.RequestResponseBodyMethodProcessor : Written [Hello World] as "text/plain;charset=UTF-8" using [org.springframework.http.converter.StringHttpMessageConverter@32ea82a3]2017-04-11 09:31:47.032 DEBUG 7424 --- [nio-8088-exec-2] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling2017-04-11 09:31:47.033 DEBUG 7424 --- [nio-8088-exec-2] o.s.web.servlet.DispatcherServlet        : Successfully completed request

可以看到执行过程：doAround- doBefore - HelloController - doAfter - doAfterReturning

2，http://localhost:8088/spring-boot/hello/error

查看日志：

2017-04-11 09:37:04.329 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing servlet 'dispatcherServlet'2017-04-11 09:37:04.331  INFO 5056 --- [nio-8088-exec-1] o.a.c.c.C.[.[localhost].[/spring-boot]   : Initializing Spring FrameworkServlet 'dispatcherServlet'2017-04-11 09:37:04.331  INFO 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started2017-04-11 09:37:04.331 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Using MultipartResolver [org.springframework.web.multipart.support.StandardServletMultipartResolver@19eb3a47]2017-04-11 09:37:04.337 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Unable to locate LocaleResolver with name 'localeResolver': using default [org.springframework.web.servlet.i18n.AcceptHeaderLocaleResolver@790e82ac]2017-04-11 09:37:04.344 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Unable to locate ThemeResolver with name 'themeResolver': using default [org.springframework.web.servlet.theme.FixedThemeResolver@94817cb]2017-04-11 09:37:04.355 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Unable to locate RequestToViewNameTranslator with name 'viewNameTranslator': using default [org.springframework.web.servlet.view.DefaultRequestToViewNameTranslator@71e76c10]2017-04-11 09:37:04.365 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Unable to locate FlashMapManager with name 'flashMapManager': using default [org.springframework.web.servlet.support.SessionFlashMapManager@6db51401]2017-04-11 09:37:04.366 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Published WebApplicationContext of servlet 'dispatcherServlet' as ServletContext attribute with name [org.springframework.web.servlet.FrameworkServlet.CONTEXT.dispatcherServlet]2017-04-11 09:37:04.366  INFO 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 35 ms2017-04-11 09:37:04.366 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Servlet 'dispatcherServlet' configured successfully2017-04-11 09:37:04.392 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/spring-boot/hello/error]2017-04-11 09:37:04.399 DEBUG 5056 --- [nio-8088-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /hello/error2017-04-11 09:37:04.402 DEBUG 5056 --- [nio-8088-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public java.lang.String com.example.controller.HelloController.helloError()]2017-04-11 09:37:04.404 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/spring-boot/hello/error] is: -12017-04-11 09:37:04.435  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : LogAop.doAround()2017-04-11 09:37:04.435  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : LogAop.doBefore()2017-04-11 09:37:04.436  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : URL : http://localhost:8088/spring-boot/hello/error2017-04-11 09:37:04.436  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : HTTP_METHOD : GET2017-04-11 09:37:04.438  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : IP : 0:0:0:0:0:0:0:12017-04-11 09:37:04.441  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : CLASS_METHOD : com.example.controller.HelloController.helloError2017-04-11 09:37:04.441  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : ARGS : []2017-04-11 09:37:04.452  INFO 5056 --- [nio-8088-exec-1] com.example.controller.HelloController   : === hello world exception2017-04-11 09:37:04.457  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : exception: java.lang.NumberFormatException: For input string: "a"at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)at java.lang.Integer.parseInt(Integer.java:580)at java.lang.Integer.parseInt(Integer.java:615)at com.example.controller.HelloController.helloError(HelloController.java:30).............2017-04-11 09:37:04.460  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : LogAop.doAfter()2017-04-11 09:37:04.460  INFO 5056 --- [nio-8088-exec-1] com.example.aop.LogAop                   : LogAop.doAfterThrowing()2017-04-11 09:37:04.462 DEBUG 5056 --- [nio-8088-exec-1] .m.m.a.ExceptionHandlerExceptionResolver : Resolving exception from handler [public java.lang.String com.example.controller.HelloController.helloError()]: java.lang.RuntimeException: unknown error2017-04-11 09:37:04.465 DEBUG 5056 --- [nio-8088-exec-1] .w.s.m.a.ResponseStatusExceptionResolver : Resolving exception from handler [public java.lang.String com.example.controller.HelloController.helloError()]: java.lang.RuntimeException: unknown error2017-04-11 09:37:04.465 DEBUG 5056 --- [nio-8088-exec-1] .w.s.m.s.DefaultHandlerExceptionResolver : Resolving exception from handler [public java.lang.String com.example.controller.HelloController.helloError()]: java.lang.RuntimeException: unknown error2017-04-11 09:37:04.467 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Could not complete requestjava.lang.RuntimeException: unknown errorat com.example.aop.LogAop.doAround(LogAop.java:84)....................2017-04-11 09:37:04.484 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/spring-boot/error]2017-04-11 09:37:04.486 DEBUG 5056 --- [nio-8088-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /error2017-04-11 09:37:04.488 DEBUG 5056 --- [nio-8088-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)]2017-04-11 09:37:04.488 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/spring-boot/error] is: -12017-04-11 09:37:04.588 DEBUG 5056 --- [nio-8088-exec-1] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Written [{timestamp=Tue Apr 11 09:37:04 CST 2017, status=500, error=Internal Server Error, exception=java.lang.RuntimeException, message=unknown error, path=/spring-boot/hello/error}] as "application/json;charset=UTF-8" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@47854de0]2017-04-11 09:37:04.589 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling2017-04-11 09:37:04.591 DEBUG 5056 --- [nio-8088-exec-1] o.s.web.servlet.DispatcherServlet        : Successfully completed request

在HelloController中我们给定了一个异常，

可以看到执行过程：doAround- doBefore - HelloController - doAfter - doAfterThrowing

=====================================================================================================

这篇提到了异常，那么下篇我们来学习公共异常的处理：SpringBoot 学习记录(六): Exception