【Spring Boot学习之五】切面日志管理

环境
　　eclipse 4.7
　　jdk 1.8
　　Spring Boot 1.5.2

一、log4j

常见方式：log4j.properties + org.apache.log4j.Logger
比如：
log4j.properties：

log4j.rootLogger=info,error,CONSOLE,DEBUG

log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender     
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout     
log4j.appender.CONSOLE.layout.ConversionPattern=%d{yyyy-MM-dd-HH-mm} [%t] [%c] [%p] - %m%n     

log4j.logger.info=info
log4j.appender.info=org.apache.log4j.DailyRollingFileAppender
log4j.appender.info.layout=org.apache.log4j.PatternLayout     
log4j.appender.info.layout.ConversionPattern=%d{yyyy-MM-dd-HH-mm} [%t] [%c] [%p] - %m%n  
log4j.appender.info.datePattern='.'yyyy-MM-dd
log4j.appender.info.Threshold = info   
log4j.appender.info.append=true   
#log4j.appender.info.File=/home/admin/pms-api-services/logs/info/api_services_info
log4j.appender.info.File=../logs/info/api_services_info

log4j.logger.error=error  
log4j.appender.error=org.apache.log4j.DailyRollingFileAppender
log4j.appender.error.layout=org.apache.log4j.PatternLayout     
log4j.appender.error.layout.ConversionPattern=%d{yyyy-MM-dd-HH-mm} [%t] [%c] [%p] - %m%n  
log4j.appender.error.datePattern='.'yyyy-MM-dd
log4j.appender.error.Threshold = error   
log4j.appender.error.append=true   
#log4j.appender.error.File=/home/admin/pms-api-services/logs/error/api_services_error
log4j.appender.error.File=../logs/error/api_services_error

log4j.logger.DEBUG=DEBUG
log4j.appender.DEBUG=org.apache.log4j.DailyRollingFileAppender
log4j.appender.DEBUG.layout=org.apache.log4j.PatternLayout     
log4j.appender.DEBUG.layout.ConversionPattern=%d{yyyy-MM-dd-HH-mm} [%t] [%c] [%p] - %m%n  
log4j.appender.DEBUG.datePattern='.'yyyy-MM-dd
log4j.appender.DEBUG.Threshold = DEBUG   
log4j.appender.DEBUG.append=true   
#log4j.appender.DEBUG.File=/home/admin/pms-api-services/logs/debug/api_services_debug
log4j.appender.DEBUG.File=../logs/debug/api_services_debug

controller：

package com.wjy.controller;

import org.apache.log4j.Logger;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

import com.wjy.test1.service.UserServiceTest1;

@RestController
public class UserController {

    private static Logger log = Logger.getLogger(UserController.class);
    
    @Autowired
    public UserServiceTest1 userServiceTest1;
    
    @RequestMapping("/insertTest1ByService")
    public String insertTest1ByService(String name,Integer age) {
        log.info("insertTest1ByService:"+name+","+age);
        
        userServiceTest1.insertuser1(name, age);
        return "success";
    }
    
    
}

二、AOP 切面记录日志
1、引入依赖

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

2、切面

package com.wjy.aop;

import java.util.Arrays;
import java.util.Enumeration;

import javax.servlet.http.HttpServletRequest;

import org.apache.log4j.Logger;
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.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

@Aspect
@Component
public class WebLogAspect {
    private static Logger logger = Logger.getLogger(WebLogAspect.class);
    
    //执行顺序
    /**@Before -->目标方法 --> @AfterReturning -->  @After*/

    /**
     * @Pointcut 切点定义
     * 整个表达式可以分为五个部分：
         1、execution(): 表达式主体。
         2、第一个*号：表示返回类型，*号表示所有的类型。
         3、包名：表示需要拦截的包名，后面的两个句点表示当前包和当前包的所有子包，com.sample.service.impl包、子孙包下所有类的方法。
         4、第二个*号：表示类名，*号表示所有的类。
         5、*(..):最后这个星号表示方法名，*号表示所有的方法，后面括弧里面表示方法的参数，两个句点表示任何参数。 
     */
    @Pointcut("execution(public * com.wjy.controller..*.*(..))")
    public void weblog(String a,String b) {
        //具体业务处理  比如报文入表等等
        logger.info("执行目标方法 weblog(.....)");
    }
    
    /**
     * @Before: 前置通知, 在方法执行之前执行
     * 被切点类名：joinPoint.getTarget().getClass().getName()
     * 被切点方法：joinPoint.getSignature().getName()
     * 被切点方法入参：JSON.toJSONString(joinPoint.getArgs())
     */
    @Before("weblog()")
    public void doBefore(JoinPoint joinPoint) {
        // 接收到请求，记录请求内容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        logger.info("#####################请求开始####################");
        // 记录下请求内容
        logger.info("URL : " + request.getRequestURL().toString());
        logger.info("HTTP_METHOD : " + request.getMethod());
        logger.info("IP : " + request.getRemoteAddr());
        Enumeration<String> enu = request.getParameterNames();
        while (enu.hasMoreElements()) {
            String name = (String) enu.nextElement();
            logger.info("name:{" + name + "},value:{" + request.getParameter(name) + "}");
        }
    }
    
    /**
     * @After: 后置通知, 在方法执行之后执行 。 
     */
    @After("weblog()")
    public void doafter(JoinPoint joinPoint) {
        logger.info("{}.{} params:{}:"+ 
                joinPoint.getTarget().getClass().getName()+ "."+
                joinPoint.getSignature().getName()+ "."+
                Arrays.asList(joinPoint.getArgs()));
    }
    
    /**
     * @AfterRunning: 返回通知, 在方法返回结果之后执行
     * 如果连接点方法出现异常，则返回通知方法不执行
     */
    @AfterReturning(returning="ret",pointcut="weblog()")
    public void doAfterReturning(JoinPoint joinPoint,Object ret) {
        // 处理完请求，返回内容
        logger.info("RESPONSE : " + ret);
        logger.info("#####################请求结束####################");
    }
    
    /**
     * @AfterThrowing: 异常通知, 在方法抛出异常之后
     */
    @AfterThrowing(pointcut = "weblog()", throwing = "e")
    public void afterThrowExec(Throwable e) {
      logger.error(e.getMessage(), e);
    }
    
    
    /**
     * @Around: 环绕通知, 围绕着方法执行
     * 环绕通知方法可以包含上面四种通知方法，环绕通知的功能最全面。环绕通知需要携带 ProceedingJoinPoint 类型的参数，且环绕通知必须有返回值, 返回值即为目标方法的返回值。
     * 环绕通知实现了上面几种通知的结合 
     */
    @Around("weblog()")
    public Object aroundMethod(ProceedingJoinPoint pdj){
        /*result为连接点的返回结果  不可以在执行目标方法时在定义result变量*/
        Object result = null;
        String methodName = pdj.getSignature().getName();

        /*前置通知方法*/
        System.out.println("前置通知方法>目标方法名：" + methodName + ",参数为：" + Arrays.asList(pdj.getArgs()));

        /*执行目标方法*/
        try {
            result = pdj.proceed();
            /*返回通知方法*/
            System.out.println("返回通知方法>目标方法名" + methodName + ",返回结果为：" + result);
        } catch (Throwable e) {
            /*异常通知方法*/
            System.out.println("异常通知方法>目标方法名" + methodName + ",异常为：" + e);
        }

        /*后置通知*/
        System.out.println("后置通知方法>目标方法名" + methodName);

        return result;
    }
    
}

测试验证：http://localhost:8080/insertTest1ByService?name=wangsan&age=10

日志：

2019-07-24 09:00:04.039  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : #####################请求开始####################
2019-07-24 09:00:04.040  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : URL : http://localhost:8080/insertTest1ByService
2019-07-24 09:00:04.040  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : HTTP_METHOD : GET
2019-07-24 09:00:04.040  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : IP : 0:0:0:0:0:0:0:1
2019-07-24 09:00:04.040  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : name:{name},value:{wangsan}
2019-07-24 09:00:04.040  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : name:{age},value:{10}
2019-07-24 09:00:04.047  INFO 2856 --- [nio-8080-exec-1] com.wjy.controller.UserController        : insertTest1ByService:wangsan,10
2019-07-24 09:00:04.280  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : {}.{} params:{}:com.wjy.controller.UserController.insertTest1ByService.[wangsan, 10]
2019-07-24 09:00:04.280  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : RESPONSE : success
2019-07-24 09:00:04.280  INFO 2856 --- [nio-8080-exec-1] com.wjy.aop.WebLogAspect                 : #####################请求结束####################

 参考：

spring AOP切面表达式详解
AspectJ 切面注解中五种通知注解