Chris Spring 注解 @After,@Around,@Before 的执行顺序是什么？
AOP 中有@Before，@After，@Around，@AfterRunning注解等等。
首先上下自己的代码，定义了切点的定义
@Aspect
@Component
public class LogApsect {
private static final Logger logger = LoggerFactory.getLogger(LogApsect.class);
ThreadLocal<Long> startTime = new ThreadLocal<>();
// 第一个*代表返回类型不限
// 第二个*代表所有类
// 第三个*代表所有方法
// (..) 代表参数不限
@Pointcut("execution(public * com.lmx.blog.controller.*.*(..))")
@Order(2)
public void pointCut(){};
@Pointcut("@annotation(com.lmx.blog.annotation.RedisCache)")
@Order(1) // Order 代表优先级，数字越小优先级越高
public void annoationPoint(){};
@Before(value = "annoationPoint() || pointCut()")
public void before(JoinPoint joinPoint){
System.out.println("方法执行前执行......before");
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
logger.info("<=====================================================");
logger.info("请求来源： =》" + request.getRemoteAddr());
logger.info("请求 URL：" + request.getRequestURL().toString());
logger.info("请求方式：" + request.getMethod());
logger.info("响应方法：" + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
logger.info("请求参数：" + Arrays.toString(joinPoint.getArgs()));
logger.info("------------------------------------------------------");
startTime.set(System.currentTimeMillis());
}
// 定义需要匹配的切点表达式，同时需要匹配参数
@Around("pointCut() && args(arg)")
public Response around(ProceedingJoinPoint pjp,String arg) throws Throwable{
System.out.println("name:" + arg);
System.out.println("方法环绕 start...around");
String result = null;
try{
result = pjp.proceed().toString() + "aop String";
System.out.println(result);
}catch (Throwable e){
e.printStackTrace();
}
System.out.println("方法环绕 end...around");
return (Response) pjp.proceed();
}
@After("within(com.lmx.blog.controller.*Controller)")
public void after(){
System.out.println("方法之后执行...after.");
}
@AfterReturning(pointcut="pointCut()",returning = "rst")
public void afterRunning(Response rst){
if(startTime.get() == null){
startTime.set(System.currentTimeMillis());
}
System.out.println("方法执行完执行...afterRunning");
logger.info("耗时（毫秒）：" + (System.currentTimeMillis() - startTime.get()));
logger.info("返回数据：{}", rst);
logger.info("==========================================>");
}
@AfterThrowing("within(com.lmx.blog.controller.*Controller)")
public void afterThrowing(){
System.out.println("异常出现之后...afterThrowing");
}
}
@Before，@After，@Around注解的区别大家可以自行百度下。总之就是@Around可以实现@Before和@After的功能，并且只需要在一个方法中就可以实现。
首先我们来测试一个方法用于获取数据库一条记录的：
@RequestMapping("/achieve")
public Response achieve(){
System.out.println("方法执行-----------");
return Response.ok(articleDetailSercice.getPrimaryKeyById(1L));
}
以下是控制台打印的日志：
方法执行前执行......before 2018-11-23 16:31:59.795 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - <===================================================== 2018-11-23 16:31:59.795 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 请求来源： =》0:0:0:0:0:0:0:1 2018-11-23 16:31:59.795 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 请求 URL：http://localhost:8888/user/achieve 2018-11-23 16:31:59.795 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 请求方式：GET 2018-11-23 16:31:59.795 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 响应方法：com.lmx.blog.controller.UserController.achieve 2018-11-23 16:31:59.796 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 请求参数：[] 2018-11-23 16:31:59.796 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - ------------------------------------------------------ 方法执行----------- 2018-11-23 16:31:59.806 [http-nio-8888-exec-9] DEBUG c.l.b.m.A.selectPrimaryKey - ==> Preparing: select * from article_detail where id = ? 2018-11-23 16:31:59.806 [http-nio-8888-exec-9] DEBUG c.l.b.m.A.selectPrimaryKey - ==> Preparing: select * from article_detail where id = ? 2018-11-23 16:31:59.806 [http-nio-8888-exec-9] DEBUG c.l.b.m.A.selectPrimaryKey - ==> Parameters: 1(Long) 2018-11-23 16:31:59.806 [http-nio-8888-exec-9] DEBUG c.l.b.m.A.selectPrimaryKey - ==> Parameters: 1(Long) 2018-11-23 16:31:59.814 [http-nio-8888-exec-9] DEBUG c.l.b.m.A.selectPrimaryKey - <== Total: 1 2018-11-23 16:31:59.814 [http-nio-8888-exec-9] DEBUG c.l.b.m.A.selectPrimaryKey - <== Total: 1 方法之后执行...after. 方法执行完执行...afterRunning 2018-11-23 16:31:59.824 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 耗时（毫秒）：27 2018-11-23 16:31:59.824 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - 返回数据：com.lmx.blog.common.Response@8675ce5 2018-11-23 16:31:59.824 [http-nio-8888-exec-9] INFO c.l.blog.config.LogApsect - ==========================================>
可以看到，因为没有匹配@Around的规则，所以没有进行环绕通知。（PS：我定义的环绕通知意思是要符合是 controller 包下的方法并且方法必须带有参数，而上述方法没有参数，所以只走了@before和@after方法，不符合@Around的匹配逻辑）
我们再试一下另一个带有参数的方法：
@RedisCache(type = Response.class)
@RequestMapping("/sendEmail")
public Response sendEmailToAuthor(String content){
System.out.println("测试执行次数");
return Response.ok(true);
}
以下是该部分代码的 console 打印：
name:第二封邮件呢 方法环绕 start...around 方法执行前执行......before 2018-11-23 16:34:55.347 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - <===================================================== 2018-11-23 16:34:55.347 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求来源： =》0:0:0:0:0:0:0:1 2018-11-23 16:34:55.347 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求 URL：http://localhost:8888/user/sendEmail 2018-11-23 16:34:55.348 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求方式：GET 2018-11-23 16:34:55.348 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 响应方法：com.lmx.blog.controller.UserController.sendEmailToAuthor 2018-11-23 16:34:55.348 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求参数：[第二封邮件呢] 2018-11-23 16:34:55.348 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - ------------------------------------------------------ 测试执行次数 com.lmx.blog.common.Response@6d17f2fdaop String 方法环绕 end...around 方法执行前执行......before 2018-11-23 16:34:55.349 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - <===================================================== 2018-11-23 16:34:55.349 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求来源： =》0:0:0:0:0:0:0:1 2018-11-23 16:34:55.349 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求 URL：http://localhost:8888/user/sendEmail 2018-11-23 16:34:55.349 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求方式：GET 2018-11-23 16:34:55.349 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 响应方法：com.lmx.blog.controller.UserController.sendEmailToAuthor 2018-11-23 16:34:55.349 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 请求参数：[第二封邮件呢] 2018-11-23 16:34:55.350 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - ------------------------------------------------------ 测试执行次数 方法之后执行...after. 方法执行完执行...afterRunning 2018-11-23 16:34:55.350 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 耗时（毫秒）：0 2018-11-23 16:34:55.350 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - 返回数据：com.lmx.blog.common.Response@79f85428 2018-11-23 16:34:55.350 [http-nio-8888-exec-2] INFO c.l.blog.config.LogApsect - ==========================================>
显而易见，该方法符合 @Around 环绕通知的匹配规则，所以进入了@Around的逻辑，但是发现了问题，所有的方法都被执行了 2 次，不管是切面层还是方法层。（有人估计要问我不是用的自定义注解 @RedisCache(type = Response.class) 么。为什么会符合 @Around的匹配规则呢，这个等会在下面说）
我们分析日志的打印顺序可以得出，在执行环绕方法时候，会优先进入 @Around下的方法。@Around的方法再贴一下代码。
// 定义需要匹配的切点表达式，同时需要匹配参数
@Around("pointCut() && args(arg)")
public Response around(ProceedingJoinPoint pjp,String arg) throws Throwable{
System.out.println("name:" + arg);
System.out.println("方法环绕 start...around");
String result = null;
try{
result = pjp.proceed().toString() + "aop String";
System.out.println(result);
}catch (Throwable e){
e.printStackTrace();
}
System.out.println("方法环绕 end...around");
return (Response) pjp.proceed();
}
打印了前两行代码以后，转而去执行了 @Before方法，是因为中途触发了 ProceedingJoinPoint.proceed() 方法。这个方法的作用是执行被代理的方法，也就是说执行了这个方法之后会执行我们 controller 的方法，而后执行 @before，@after，然后回到@Around 执行未执行的方法，最后执行 @afterRunning，如果有异常抛出能执行 @AfterThrowing。
也就是说环绕的执行顺序是 @Around→@Before→@After→@Around执行 ProceedingJoinPoint.proceed() 之后的操作→@AfterRunning(如果有异常→@AfterThrowing)。
而我们上述的日志相当于把上述结果执行了 2 遍，根本原因在于 ProceedingJoinPoint.proceed() 这个方法，可以发现在@Around 方法中我们使用了 2 次这个方法，然而每次调用这个方法时都会走一次@Before→@After→@Around执行 ProceedingJoinPoint.proceed() 之后的操作→@AfterRunning(如果有异常→@AfterThrowing)。因此问题是出现在这里。所以更改@Around部分的代码即可解决该问题。更改之后的代码如下：
@Around("pointCut() && args(arg)")
public Response around(ProceedingJoinPoint pjp,String arg) throws Throwable{
System.out.println("name:" + arg);
System.out.println("方法环绕 start...around");
String result = null;
Object object = pjp.proceed();
try{
result = object.toString() + "aop String";
System.out.println(result);
}catch (Throwable e){
e.printStackTrace();
}
System.out.println("方法环绕 end...around");
return (Response) object;
}
更改代码之后的运行结果：
name:第二封邮件呢 方法环绕 start...around 方法执行前执行......before 2018-11-23 16:52:14.315 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - <===================================================== 2018-11-23 16:52:14.315 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 请求来源： =》0:0:0:0:0:0:0:1 2018-11-23 16:52:14.315 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 请求 URL：http://localhost:8888/user/sendEmail 2018-11-23 16:52:14.315 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 请求方式：GET 2018-11-23 16:52:14.316 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 响应方法：com.lmx.blog.controller.UserController.sendEmailToAuthor 2018-11-23 16:52:14.316 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 请求参数：[第二封邮件呢] 2018-11-23 16:52:14.316 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - ------------------------------------------------------ 测试执行次数 com.lmx.blog.common.Response@1b1c76afaop String 方法环绕 end...around 方法之后执行...after. 方法执行完执行...afterRunning 2018-11-23 16:52:14.316 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 耗时（毫秒）：0 2018-11-23 16:52:14.316 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - 返回数据：com.lmx.blog.common.Response@1b1c76af 2018-11-23 16:52:14.316 [http-nio-8888-exec-4] INFO c.l.blog.config.LogApsect - ==========================================>
回到上述未解决的问题，为什么我定义了切面的另一个注解还可以进入@Around 方法呢？
因为我们的方法仍然在 controller 下，因此满足该需求，如果我们定义了 controller 包下的某个 controller 才有用。例如：
@Pointcut("execution(public * com.lmx.blog.controller.UserController.*(..))")
而如果我们刚才定义的方法是写在 TestController 之下的，那么就不符合 @Around方法的匹配规则了，也不符合@before和@after的注解规则，因此不会匹配任何一个规则，如果需要匹配特定的方法，可以用自定义的注解形式或者特性 controller 下的方法。
①：特性的注解形式：
@Pointcut("@annotation(com.lmx.blog.annotation.RedisCache)")
@Order(1) // Order 代表优先级，数字越小优先级越高
public void annoationPoint(){};
然后在所需要的方法上加入 @RedisCache注解，在@Before，@After，@Around等方法上添加该切点的方法名（“annoationPoint()”），如果有多个注解需要匹配则用 || 隔开。
②：指定 controller 或者指定 controller 下的方法：
@Pointcut("execution(public * com.lmx.blog.controller.UserController.*(..))")
@Order(2)
public void pointCut(){};
该部分代码是指定了 com.lmx.blog.controller包下的 UserController 下的所有方法。
第一个*代表的是返回类型不限
第二个*代表的是该 controller 下的所有方法，(..)代表的是参数不限
总结
当方法符合切点规则不符合环绕通知的规则时候，执行的顺序如下：
@Before > @After > @AfterRunning（如果有异常 > @AfterThrowing）
当方法符合切点规则并且符合环绕通知的规则时候，执行的顺序如下：
@Around > @Before > @Around > @After 执行 ProceedingJoinPoint.proceed() 之后的操作 > @AfterRunning（如果有异常 > @AfterThrowing）
原文链接：点击这里
微信
支付宝声明：本站所有文章，如无特殊说明或标注，均为本站原创发布。任何个人或组织，在未征得本站同意时，禁止复制、盗用、采集、发布本站内容到任何网站、书籍等各类媒体平台。如若本站内容侵犯了原著者的合法权益，可联系我们进行处理。
码云笔记 » Spring 注解 @After,@Around,@Before 的执行顺序是什么？
码云笔记 » Spring 注解 @After,@Around,@Before 的执行顺序是什么？
