前言

在系统中涉及到的方法有很多，有的时候我们需要监控，系统中哪些方法执行效率低，耗时长，这样有助于我们得知系统中存在哪些隐患；

得知隐患后，我们可以针对这些隐患做性能的优化

本篇博客的内容，是基于spring的aop以及自定义注解完成的；

效果图

当浏览器输入

http://localhost/login

执行登录

控制台输出

登录系统控制台产生的所有日志输出

16:24:28 [http-nio-80-exec-9] INFO  c.j.b.common.aspect.WebLogAspect - 请求地址 : http://localhost/login
16:24:28 [http-nio-80-exec-9] INFO  c.j.b.common.aspect.WebLogAspect - HTTP METHOD : POST
16:24:28 [http-nio-80-exec-9] INFO  c.j.b.common.aspect.WebLogAspect - CLASS_METHOD : com.javaxl.bootdo.system.controller.LoginController.ajaxLogin
16:24:28 [http-nio-80-exec-9] INFO  c.j.b.common.aspect.WebLogAspect - 参数 : [admin, 111111, 1969, org.apache.shiro.web.servlet.ShiroHttpServletRequest@78f55dd6]
16:24:28 [http-nio-80-exec-9] INFO  c.j.b.common.aspect.WebLogAspect - 耗时 : 2345
16:24:28 [http-nio-80-exec-9] DEBUG c.j.b.common.aspect.WebLogAspect - 返回值 : {msg=请输入正确的验证码, code=500}
16:24:28 [SimpleAsyncTaskExecutor-3] DEBUG c.j.bootdo.common.dao.LogDao.save - ==>  Preparing: insert into sys_log ( `user_id`, `username`, `operation`, `time`, `method`, `params`, `ip`, `gmt_create` ) values ( ?, ?, ?, ?, ?, ?, ?, ? ) 
16:24:28 [SimpleAsyncTaskExecutor-3] DEBUG c.j.bootdo.common.dao.LogDao.save - ==> Parameters: 1(Long), admin(String), 登录(String), 2345(Integer), com.javaxl.bootdo.system.controller.LoginController.ajaxLogin()(String), null, 127.0.0.1(String), 2019-06-24 16:24:28.03(Timestamp)
16:24:28 [SimpleAsyncTaskExecutor-3] DEBUG c.j.bootdo.common.dao.LogDao.save - <==    Updates: 1
16:24:47 [http-nio-80-exec-6] INFO  c.j.b.common.aspect.WebLogAspect - 请求地址 : http://localhost/login
16:24:47 [http-nio-80-exec-6] INFO  c.j.b.common.aspect.WebLogAspect - HTTP METHOD : POST
16:24:47 [http-nio-80-exec-6] INFO  c.j.b.common.aspect.WebLogAspect - CLASS_METHOD : com.javaxl.bootdo.system.controller.LoginController.ajaxLogin
16:24:47 [http-nio-80-exec-6] INFO  c.j.b.common.aspect.WebLogAspect - 参数 : [admin, 111111, 9054, org.apache.shiro.web.servlet.ShiroHttpServletRequest@3f83b3f0]
16:24:47 [http-nio-80-exec-6] DEBUG c.j.bootdo.system.dao.UserDao.list - ==>  Preparing: select `user_id`,`username`,`name`,`password`,`dept_id`,`email`,`mobile`,`status`,`user_id_create`,`gmt_create`,`gmt_modified`,`sex`,`birth`,`pic_id`,`live_address`,`hobby`,`province`,`city`,`district` from sys_user WHERE username = ? order by user_id desc 
16:24:47 [http-nio-80-exec-6] DEBUG c.j.bootdo.system.dao.UserDao.list - ==> Parameters: admin(String)
16:24:47 [http-nio-80-exec-6] DEBUG c.j.bootdo.system.dao.UserDao.list - <==      Total: 1
16:24:47 [http-nio-80-exec-6] DEBUG c.j.b.s.dao.UserRoleDao.listRoleSign - ==>  Preparing: select distinct r.role_sign from sys_role r left join sys_user_role ur on r.role_id = ur.role_id where ur.user_id=? 
16:24:47 [http-nio-80-exec-6] DEBUG c.j.b.s.dao.UserRoleDao.listRoleSign - ==> Parameters: 1(Long)
16:24:47 [http-nio-80-exec-6] DEBUG c.j.b.s.dao.UserRoleDao.listRoleSign - <==      Total: 3
16:24:47 [http-nio-80-exec-6] INFO  c.j.b.common.aspect.WebLogAspect - 耗时 : 2534
16:24:47 [http-nio-80-exec-6] DEBUG c.j.b.common.aspect.WebLogAspect - 返回值 : {msg=操作成功, code=0}
16:24:47 [SimpleAsyncTaskExecutor-4] DEBUG c.j.bootdo.common.dao.LogDao.save - ==>  Preparing: insert into sys_log ( `user_id`, `username`, `operation`, `time`, `method`, `params`, `ip`, `gmt_create` ) values ( ?, ?, ?, ?, ?, ?, ?, ? ) 
16:24:47 [SimpleAsyncTaskExecutor-4] DEBUG c.j.bootdo.common.dao.LogDao.save - ==> Parameters: 1(Long), admin(String), 登录(String), 2534(Integer), com.javaxl.bootdo.system.controller.LoginController.ajaxLogin()(String), null, 127.0.0.1(String), 2019-06-24 16:24:47.954(Timestamp)
16:24:47 [SimpleAsyncTaskExecutor-4] DEBUG c.j.bootdo.common.dao.LogDao.save - <==    Updates: 1
16:24:50 [http-nio-80-exec-2] INFO  c.j.b.common.aspect.WebLogAspect - 请求地址 : http://localhost/index
16:24:50 [http-nio-80-exec-2] INFO  c.j.b.common.aspect.WebLogAspect - HTTP METHOD : GET
16:24:50 [http-nio-80-exec-2] INFO  c.j.b.common.aspect.WebLogAspect - CLASS_METHOD : com.javaxl.bootdo.system.controller.LoginController.index
16:24:50 [http-nio-80-exec-2] INFO  c.j.b.common.aspect.WebLogAspect - 参数 : [{}]
16:24:50 [http-nio-80-exec-2] DEBUG c.j.b.s.dao.MenuDao.listMenuByUserId - ==>  Preparing: select distinct m.menu_id , parent_id, name, url, perms,`type`,icon,order_num,gmt_create, gmt_modified from sys_menu m left join sys_role_menu rm on m.menu_id = rm.menu_id left join sys_user_role ur on rm.role_id =ur.role_id where ur.user_id = ? and m.type in(0,1) order by m.order_num 
16:24:50 [http-nio-80-exec-2] DEBUG c.j.b.s.dao.MenuDao.listMenuByUserId - ==> Parameters: 1(Long)
16:24:50 [http-nio-80-exec-2] DEBUG c.j.b.s.dao.MenuDao.listMenuByUserId - <==      Total: 30
16:24:50 [http-nio-80-exec-2] DEBUG c.j.bootdo.common.dao.FileDao.get - ==>  Preparing: select `id`,`type`,`url`,`create_date` from sys_file where id = ? 
16:24:50 [http-nio-80-exec-2] DEBUG c.j.bootdo.common.dao.FileDao.get - ==> Parameters: 138(Long)
16:24:50 [http-nio-80-exec-2] DEBUG c.j.bootdo.common.dao.FileDao.get - <==      Total: 1
16:24:50 [http-nio-80-exec-2] INFO  c.j.b.common.aspect.WebLogAspect - 耗时 : 2040
16:24:50 [http-nio-80-exec-2] DEBUG c.j.b.common.aspect.WebLogAspect - 返回值 : index_v1
16:24:50 [SimpleAsyncTaskExecutor-5] DEBUG c.j.bootdo.common.dao.LogDao.save - ==>  Preparing: insert into sys_log ( `user_id`, `username`, `operation`, `time`, `method`, `params`, `ip`, `gmt_create` ) values ( ?, ?, ?, ?, ?, ?, ?, ? ) 
16:24:50 [SimpleAsyncTaskExecutor-5] DEBUG c.j.bootdo.common.dao.LogDao.save - ==> Parameters: 1(Long), admin(String), 请求访问主页(String), 2040(Integer), com.javaxl.bootdo.system.controller.LoginController.index()(String), null, 127.0.0.1(String), 2019-06-24 16:24:50.033(Timestamp)
16:24:50 [SimpleAsyncTaskExecutor-5] DEBUG c.j.bootdo.common.dao.LogDao.save - <==    Updates: 1
16:24:51 [http-nio-80-exec-1] INFO  c.j.b.common.aspect.WebLogAspect - 请求地址 : http://localhost/main
16:24:51 [http-nio-80-exec-1] INFO  c.j.b.common.aspect.WebLogAspect - HTTP METHOD : GET
16:24:51 [http-nio-80-exec-1] INFO  c.j.b.common.aspect.WebLogAspect - CLASS_METHOD : com.javaxl.bootdo.system.controller.LoginController.main
16:24:51 [http-nio-80-exec-1] INFO  c.j.b.common.aspect.WebLogAspect - 参数 : []
16:24:51 [http-nio-80-exec-1] INFO  c.j.b.common.aspect.WebLogAspect - 耗时 : 1111
16:24:51 [http-nio-80-exec-1] DEBUG c.j.b.common.aspect.WebLogAspect - 返回值 : main
16:24:51 [http-nio-80-exec-10] INFO  c.j.b.common.aspect.WebLogAspect - 请求地址 : http://localhost/oa/notify/message
16:24:51 [http-nio-80-exec-10] INFO  c.j.b.common.aspect.WebLogAspect - HTTP METHOD : GET
16:24:51 [http-nio-80-exec-10] INFO  c.j.b.common.aspect.WebLogAspect - CLASS_METHOD : com.javaxl.bootdo.oa.controller.NotifyController.message
16:24:51 [http-nio-80-exec-10] INFO  c.j.b.common.aspect.WebLogAspect - 参数 : []
16:24:52 [http-nio-80-exec-5] INFO  c.j.b.common.aspect.WebLogAspect - 请求地址 : http://localhost/main
16:24:52 [http-nio-80-exec-5] INFO  c.j.b.common.aspect.WebLogAspect - HTTP METHOD : GET
16:24:52 [http-nio-80-exec-5] INFO  c.j.b.common.aspect.WebLogAspect - CLASS_METHOD : com.javaxl.bootdo.system.controller.LoginController.main
16:24:52 [http-nio-80-exec-5] INFO  c.j.b.common.aspect.WebLogAspect - 参数 : []
16:24:52 [http-nio-80-exec-5] INFO  c.j.b.common.aspect.WebLogAspect - 耗时 : 1413
16:24:52 [http-nio-80-exec-5] DEBUG c.j.b.common.aspect.WebLogAspect - 返回值 : main
16:24:52 [http-nio-80-exec-10] DEBUG c.j.bootdo.oa.dao.NotifyDao.listDTO - ==>  Preparing: select DISTINCT n.id ,`type`,`title`,`content`,`files`,r.is_read,`status`,`create_by`,`create_date`,`update_by`,`update_date`,`remarks`,`del_flag` from oa_notify_record r right JOIN oa_notify n on r.notify_id = n.id WHERE r.is_read = ? and r.user_id = ? order by is_read ASC, update_date DESC limit ?, ? 
16:24:52 [http-nio-80-exec-10] DEBUG c.j.bootdo.oa.dao.NotifyDao.listDTO - ==> Parameters: 0(String), 1(Long), 0(Integer), 3(Integer)
16:24:52 [http-nio-80-exec-10] DEBUG c.j.bootdo.oa.dao.NotifyDao.listDTO - <==      Total: 0
16:24:52 [http-nio-80-exec-10] DEBUG c.j.bootdo.oa.dao.NotifyDao.countDTO - ==>  Preparing: select count(*) from oa_notify_record r right JOIN oa_notify n on r.notify_id = n.id where r.user_id =? and r.is_read = ? 
16:24:52 [http-nio-80-exec-10] DEBUG c.j.bootdo.oa.dao.NotifyDao.countDTO - ==> Parameters: 1(Long), 0(String)
16:24:52 [http-nio-80-exec-10] DEBUG c.j.bootdo.oa.dao.NotifyDao.countDTO - <==      Total: 1
16:24:52 [http-nio-80-exec-10] INFO  c.j.b.common.aspect.WebLogAspect - 耗时 : 1433
16:24:52 [http-nio-80-exec-10] DEBUG c.j.b.common.aspect.WebLogAspect - 返回值 : com.javaxl.bootdo.common.utils.PageUtils@34bd65e2

系统日志监控界面

核心代码

自定义注解

Log

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface Log {
   String value() default "";
}

这个注解类的作用在于可以动态获取调用的方法所携带的参数

参考文章

https://blog.csdn.net/Merci_sen/article/details/80886206

浏览器请求日志文件输出相关切面类

WebLogAspect

package com.javaxl.bootdo.common.aspect;

import com.javaxl.bootdo.common.utils.HttpContextUtils;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import sun.net.util.IPAddressUtil;

import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.util.Arrays;

@Aspect
@Component
public class WebLogAspect {

    private static final Logger logger = LoggerFactory.getLogger(WebLogAspect.class);

    @Pointcut("execution( * com.javaxl.bootdo..controller.*.*(..))")//两个..代表所有子目录，最后括号里的两个..代表所有参数
    public void logPointCut() {
    }


    @Before("logPointCut()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {
        // 接收到请求，记录请求内容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        // 记录下请求内容
        logger.info("请求地址 : " + request.getRequestURL().toString());
        logger.info("HTTP METHOD : " + request.getMethod());
        // 获取真实的ip地址
        //logger.info("IP : " + IPAddressUtil.getClientIpAddress(request));
        logger.info("CLASS_METHOD : " + joinPoint.getSignature().getDeclaringTypeName() + "."
                + joinPoint.getSignature().getName());
        logger.info("参数 : " + Arrays.toString(joinPoint.getArgs()));
//        loggger.info("参数 : " + joinPoint.getArgs());

    }

    @AfterReturning(returning = "ret", pointcut = "logPointCut()")// returning的值和doAfterReturning的参数名一致
    public void doAfterReturning(Object ret) throws Throwable {
        // 处理完请求，返回内容(返回值太复杂时，打印的是物理存储空间的地址)
        logger.debug("返回值 : " + ret);
    }

    @Around("logPointCut()")
    public Object doAround(ProceedingJoinPoint pjp) throws Throwable {
        long startTime = System.currentTimeMillis();
        Object ob = pjp.proceed();// ob 为方法的返回值
        logger.info("耗时 : " + (System.currentTimeMillis() - startTime));
        return ob;
    }
}

后台日志表记录切面类

LogAspect

package com.javaxl.bootdo.common.aspect;

import java.lang.reflect.Method;
import java.util.Date;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

import javax.servlet.http.HttpServletRequest;

import com.javaxl.bootdo.common.service.LogService;
import com.javaxl.bootdo.system.domain.UserToken;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.scheduling.annotation.Async;
import org.springframework.stereotype.Component;

import com.javaxl.bootdo.common.annotation.Log;
import com.javaxl.bootdo.common.dao.LogDao;
import com.javaxl.bootdo.common.domain.LogDO;
import com.javaxl.bootdo.common.utils.HttpContextUtils;
import com.javaxl.bootdo.common.utils.IPUtils;
import com.javaxl.bootdo.common.utils.JSONUtils;
import com.javaxl.bootdo.common.utils.ShiroUtils;
import com.javaxl.bootdo.system.domain.UserDO;

@Aspect
@Component
public class LogAspect {
    private static final Logger logger = LoggerFactory.getLogger(LogAspect.class);

    @Autowired
    LogService logService;


    @Pointcut("@annotation(com.javaxl.bootdo.common.annotation.Log)")
    public void logPointCut() {
    }

    @Around("logPointCut()")
    public Object around(ProceedingJoinPoint point) throws Throwable {
        long beginTime = System.currentTimeMillis();
        // 执行方法
        Object result = point.proceed();
        // 执行时长(毫秒)
        long time = System.currentTimeMillis() - beginTime;
        //异步保存日志
        saveLog(point, time);
        return result;
    }

    void saveLog(ProceedingJoinPoint joinPoint, long time) throws InterruptedException {
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();
        Method method = signature.getMethod();
        LogDO sysLog = new LogDO();
        Log syslog = method.getAnnotation(Log.class);
        if (syslog != null) {
            // 注解上的描述
            sysLog.setOperation(syslog.value());
        }
        // 请求的方法名
        String className = joinPoint.getTarget().getClass().getName();
        String methodName = signature.getName();
        sysLog.setMethod(className + "." + methodName + "()");
        // 请求的参数
        Object[] args = joinPoint.getArgs();
        try {
            String params = JSONUtils.beanToJson(args[0]).substring(0, 4999);
            sysLog.setParams(params);
        } catch (Exception e) {

        }
        // 获取request
        HttpServletRequest request = HttpContextUtils.getHttpServletRequest();
        // 设置IP地址
        sysLog.setIp(IPUtils.getIpAddr(request));
        // 用户名
        UserDO currUser = ShiroUtils.getUser();
        if (null == currUser) {
            if (null != sysLog.getParams()) {
                sysLog.setUserId(-1L);
                sysLog.setUsername(sysLog.getParams());
            } else {
                sysLog.setUserId(-1L);
                sysLog.setUsername("获取用户信息为空");
            }
        } else {
            sysLog.setUserId(ShiroUtils.getUserId());
            sysLog.setUsername(ShiroUtils. getUser().getUsername());
        }
        sysLog.setTime((int) time);
        // 系统当前时间
        Date date = new Date();
        sysLog.setGmtCreate(date);
        // 保存系统日志
        logService.save(sysLog);
    }
}

over.......