利用AOP进行简单的性能监控及用户行为审计
做web项目后台开发的时候,比较关心的一个问题程序跑的快不快,这个问题的最好度量就是计时器了。但是在每一个方法里面都写一个计时器,弊端太明显了:代码冗余大,维护起来巨麻烦。切面编程为解决这个问题的不错方案。
现在web开发通用的做法采用MVC的模式,而比较消耗时间的主要是在数据库操作和磁盘读写这一块,理论上在DAO层添加计时器更能清楚每个函数耗时。但是我自己的做法是放在Action层,关注整体的耗时。因为action里面里面通过service层多次调用DAO层的函数(如批量操作),还有就是网络传输,和磁盘读写也不一定发生在DAO层,所以放在action层的话,反应的是用户一次操作的后台处理时间。
使用Spring的AOP技术,第一步进行配置,因为我主要使用的是注解,所以配置很少,现在applicationContext.xml文件中添加
<!--支持aspectj,采用代理--> <aop:aspectj-autoproxy proxy-target-class="true"/>
第二步,编写切面
1)定义切点
@Pointcut("execution(* com.nci.system.*.action.*Action.*(..)) || execution(* com.nci.app.*.action.*Action.*(..))") public void allActionMethods(){}
2)拦截Action函数,添加计时器。
@Around(value = "allActionMethods()") public Object allMonitorTime(ProceedingJoinPoint pjp){ .... }
下面是完整的类【包括简单的用户行为审计的日志记录】:
package com.nci.common.aspect; import com.nci.common.utils.DateUtil; import com.nci.common.utils.HttpUtils; import com.nci.common.utils.LoggerUtils; import com.nci.system.account.model.Account; import com.nci.system.log.logAction.OperateLogAction; import com.nci.system.log.model.OperateLog; import org.aspectj.lang.JoinPoint; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.AfterReturning; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.Pointcut; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Component; import org.springframework.util.StopWatch; import javax.servlet.http.HttpSession; import java.util.Date; /** * 记录日志的控制切面实现类 * */ @Component @Aspect public class OperateLogAspect { @Autowired // private OperateLogService operateLogService; private OperateLogAction operateLogAction; private static String CREATE = "新建"; private static String UPDATE = "修改"; private static String DELETE = "删除"; private static String FIND = "查询";//尽量不用,否则产生大量的日志 private static String LOGIN = "登录"; private static String OTHERS = "其他"; private static Logger logger = LoggerUtils.getLogger(); //=======================定义切点====================== @Pointcut("execution(* com.nci.system.*.service.*Service.create*(..)) || execution(* com.nci.app.*.service.*Service.create*(..))") public void create(){} @Pointcut("execution(* com.nci.system.*.service.*Service.update*(..)) || execution(* com.nci.app.*.service.*Service.update*(..))") public void update(){} @Pointcut("execution(* com.nci.system.*.service.*Service.delete*(..)) || execution(* com.nci.app.*.service.*Service.delete*(..))") public void delete(){} @Pointcut("execution(* com.nci.system.*.action.*Action.*(..)) || execution(* com.nci.app.*.action.*Action.*(..))") public void allActionMethods(){} //增加,删除,修改 @Pointcut("create() || update() || delete()") public void cud(){} //=======================通知========================= @AfterReturning(value = "cud()") public void cudMethods(JoinPoint joinPoint){ //保存操作日志到数据库 operateLogAction.save(setOperateLog(joinPoint)); } /** * 计算Action中方法的运行时间 * @param pjp * @return */ @Around(value = "allActionMethods()") public Object allMonitorTime(ProceedingJoinPoint pjp){ logger = LoggerFactory.getLogger(pjp.getTarget().getClass()); StopWatch stopWatch = new StopWatch(pjp.getTarget().toString()); Object object = null; stopWatch.start(); try { object= pjp.proceed(); } catch (Throwable throwable) { throw new RuntimeException(throwable.getMessage()); }finally { stopWatch.stop(); /** * 好处:运行时间太短,没有必要打印 * 避免Action中属性的getXX(),setXX()也打印时间 * 【太多打印反而不好】 */ if(stopWatch.getTotalTimeSeconds() > 0.1){ logger.debug(pjp.getTarget().getClass()+"."+pjp.getSignature().getName()+"() 运行时间:"+stopWatch.getTotalTimeSeconds()+" 秒\r\n"); } return object; } } /** * 将操作日志的信息保存到OperateLog对象中 * @param joinPoint * @return */ OperateLog setOperateLog(JoinPoint joinPoint){ //操作日志信息 OperateLog log = new OperateLog(); log.setType(getSignatureType(joinPoint.getSignature().getName())); log.setOperateDate(DateUtil.formateDateToStringWithSecond(new Date())); log.setHostIp(HttpUtils.getIpAddr(HttpUtils.getRequest())); HttpSession session = HttpUtils.getRequest().getSession(); Account account = (Account) session.getAttribute("user"); log.setOperator(account.getAccountName()); log.setClassName(joinPoint.getSignature().getDeclaringTypeName()); log.setMethod(joinPoint.getSignature().getName()); //参数 String params = ""; for (int i = 0; i <joinPoint.getArgs().length ; i++) { params += joinPoint.getArgs()[i].toString()+", "; } //若含有参数,去掉末尾的", " params = params.length() > 0 ? params.substring(0,params.length() - 2) : params; log.setParameter(params); return log; } /** * 获得被调用的方法类型 * @param methodName * @return */ String getSignatureType(String methodName){ //添加类操作 if(methodName.startsWith("create")) return CREATE; //更新类操作 if(methodName.startsWith("update")) return UPDATE; //删除类操作 if(methodName.startsWith("delete")) return DELETE; //查询类操作【一般记录不开启查询类的日志】 // if(methodName.startsWith("find")||methodName.startsWith("get")) return FIND; //登录类操作 if (methodName.startsWith("login")) return LOGIN; return OTHERS; } /** * 连接点详细详细信息 * @param joinPoint */ private void printJoinPointInfo(JoinPoint joinPoint){ System.out.println("=========================printJoinPointInfo==============================="); System.out.println(); logger.debug("joinPoint.getKind(): " + joinPoint.getKind()); logger.debug("joinPoint.getClass(): " + joinPoint.getClass()); logger.debug("joinPoint.getTarget(): " + joinPoint.getTarget()); logger.debug("joinPoint.getSourceLocation(): " + joinPoint.getSourceLocation()); logger.debug("joinPoint.getThis(): " + joinPoint.getThis()); System.out.println("joinPoint.getArgs()");//参数 for (int i = 0; i <joinPoint.getArgs().length ; i++) { System.out.print(joinPoint.getArgs()[i].toString() + "\t"); } System.out.println(); logger.debug("joinPoint.getSignature(): " + joinPoint.getSignature());//方法签名 logger.debug("joinPoint.getSignature().getName(): " + joinPoint.getSignature().getName());//方法名 //被调用方法所在类【声明方法的类】 logger.debug("joinPoint.getSignature().getDeclaringTypeName(): " + joinPoint.getSignature().getDeclaringTypeName()); logger.debug("joinPoint.getStaticPart(): " + joinPoint.getStaticPart()); logger.debug("joinPoint.getTarget(): " + joinPoint.getTarget()); System.out.println("=========================================================================="); } }
通过添加@Component注解,让Spring可以扫描到,添加@Aspect,声明这是一个切面。准备工作基本OK了。
思路很单,实现也不困难。在是通常开发的时候,会使用到泛型。比如所有的Action都集成了一个自定义的BaseAction<T>,以减少重复代码,如:
@SuppressWarnings({ "unchecked" }) public abstract class BaseAction<T> extends ActionSupport implements Preparable, ModelDriven, ServletRequestAware, ServletResponseAware { /** * */ private static final long serialVersionUID = 1L; // 动态模型参数 protected T entity; // 模型对象 protected Class<T> entityClass; // 模型对象对象类 // protected String entityClassName; // 模型对象对象类名 // 分页参数 protected Page<T> page = new Page(Page.NOW_PAGESIZE); // 分页对象 protected Map mapRef; // 页面关联Map protected Map listRef; // 页面关联List // 其他参数 protected HttpServletRequest request; protected HttpServletResponse response; protected Object[] values; // 记录操作日志 protected final Logger logger = LogManager.getLogger(this.getClass()); // 为子类定义的logger // 构造函数 public BaseAction() { super();
//通过反射机制求出泛型类型 entityClass = (Class<T>) ((ParameterizedType) this.getClass().getGenericSuperclass()).getActualTypeArguments()[0]; } ... }
注意上面标红的代码,这是搭项目架构的同事的写法:将泛型的类型放在构造函数,若不对action配置AOP的话,项目是可以运行的,但是,若对action进行切面编程就 玩不下去了。抛出如下异常:
Unable to instantiate Action, com.nci.system.account.action.AccountAction, defined for 'login' in namespace '/account'Error creating bean with name 'com.nci.system.account.action.AccountAction': Initialization of bean failed; nested exception is org.springframework.aop.framework.AopConfigException: Could not generate CGLIB subclass of class [class com.nci.system.account.action.AccountAction]: Common causes of this problem include using a final class or a non-visible class; nested exception is net.sf.cglib.core.CodeGenerationException: java.lang.ClassCastException-->java.lang.Class cannot be cast to java.lang.reflect.ParameterizedType
让人各种闹心:向我们这种小白,之前也没怎么玩过泛型,求泛型的类类型(Class)。但是呢,项目不在action层进行切入,放在其他层总有种不舒服的感觉。于是各种Google和百度,找了好几周也没解决。最后,网上有人说求泛型的类类型Class在编译期间会报错,在运行调用期间再求就OK了。于是我将BaseAction<T>改写下,就一点点。
//构造函数 public BaseAction() { super(); //entityClass = (Class<T>) ((ParameterizedType) this.getClass().getGenericSuperclass()).getActualTypeArguments()[0]; }
将求泛型的类类型语句entityClass = (Class<T>) ((ParameterizedType) this.getClass().getGenericSuperclass()).getActualTypeArguments()[0];从构造函数中注释掉,写一个求entityClass的函数:
/** * 求泛型的类类型 * @return */ private Class<T> getEntityClass(){ if(null == entityClass){ entityClass = (Class<T>) ((ParameterizedType) this.getClass().getGenericSuperclass()).getActualTypeArguments()[0]; } return entityClass; }
需要引用entityClass的地方全部改为getEntityClass(),我们项目用到的地方其实,只有一处:
/** * @see Preparable */ public void prepare() throws Exception { // entity = entityClass.newInstance();// entity = getEntityClass().newInstance();// onPrepare(); }
现在就OK了。项目中action方法大于0.2秒【参数自己设定】的方法就可以打印控制台了【包括类名、方法、运行时间】。运行效果如下: