SpringのAOPはログ出力を実現し、記録方法の実行時間
17264 ワード
AOPをよりよく理解するために、実践を行い、AOPでログ出力を実現し、方法の実行時間を記録する.プロジェクト全体構造プロジェクト概要;プロジェクトはSpringBootの簡単なアクセスモジュールを採用しています.このモジュールのログ出力をAOPで実現し,メソッドの実行時間を記録する.
pom.xml
ここではspringbootガイドパッケージを初めて使用する場合は、ネットワーク速度を具体的に見ると長い場合があることに注意してください.
UserControllerテスト用の制御層
ここまでは実は簡単なアクセスモジュールでいいので、SpringBootの便利なところでもあります.
制御レイヤブロック、レコードリクエストの開始、リクエストの終了
サービス層ブロック、メソッド呼び出しの実行時間、パラメータなどを記録する
Orderクラス
カスタムレスポンスヘッダRespHeadクラス
カスタムレスポンス結果Resultクラス
Userクラス
OrderServiceクラス
UserServiceクラス
タイムツールクラス
アプリケーションクラスの起動
アクセスの検証
コンソール表示
ページ表示
pom.xml
4.0.0
com.yj
Aspect2
0.0.1-SNAPSHOT
jar
Aspect2
http://maven.apache.org
UTF-8
org.springframework.boot
spring-boot-starter-parent
1.5.2.RELEASE
org.springframework.boot
spring-boot-starter-web
org.springframework.boot
spring-boot-starter-test
org.springframework.boot
spring-boot-starter-aop
ここではspringbootガイドパッケージを初めて使用する場合は、ネットワーク速度を具体的に見ると長い場合があることに注意してください.
UserControllerテスト用の制御層
package com.yj.controller;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
import com.yj.model.RespHead;
import com.yj.model.Result;
import com.yj.model.User;
import com.yj.service.UserService;
/**
* UserController
* @author Administrator
*
*/
@RestController
public class UserController {
@Autowired
private UserService userService;
@RequestMapping("/getUser")
public Result getUser(User user){
System.out.println("#####################################");
user=userService.getUser(user);
Result result =new Result();
RespHead respHead=new RespHead();
result.setRespHead(respHead);
result.setContent(user);
return result;
}
}
ここまでは実は簡単なアクセスモジュールでいいので、SpringBootの便利なところでもあります.
制御レイヤブロック、レコードリクエストの開始、リクエストの終了
package com.yj.aspect;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
import com.yj.utils.CommUtils;
/**
* ControllerAspect , ,
* @author Administrator
*
*/
@Component
@Aspect
public class ControllerAspect {
private static final Log LOG = LogFactory.getLog(ControllerAspect.class);
@Before(value = "controllerPointCut()")
public void doBefore(JoinPoint joinPoint) {
LOG.info("==" + CommUtils.getTimeStr() + " " + joinPoint.getSignature().getDeclaringTypeName() + "."
+ joinPoint.getSignature().getName() + "==");
}
@After(value = "controllerPointCut()")
public void doAfter(JoinPoint joinPoint) throws Throwable {
LOG.info("==" + CommUtils.getTimeStr() + " " + joinPoint.getSignature().getDeclaringTypeName() + "."
+ joinPoint.getSignature().getName() + " ==");
}
@Pointcut("execution(* com.yj.controller..*.*(..))")
private void controllerPointCut() {
}
}
サービス層ブロック、メソッド呼び出しの実行時間、パラメータなどを記録する
package com.yj.aspect;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
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.springframework.stereotype.Component;
/**
* MethodAspect , ,
* @author Administrator
*
*/
@Component
@Aspect
public class MethodAspect {
private static final Log LOG = LogFactory.getLog(MethodAspect.class);
@Pointcut("execution(public * com.yj.service..*.*(..))")
public void methodPointcut() {
}
@Around("methodPointcut()")
public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis();
try {
Object result = joinPoint.proceed();
long end = System.currentTimeMillis();
LOG.info(" " + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName()
+ " ," + parseParames(joinPoint.getArgs()) + ", :" + (end - start) + " ms!");
return result;
} catch (Throwable e) {
long end = System.currentTimeMillis();
LOG.error(joinPoint + ", :" + (end - start) + " ms, :" + e.getMessage());
throw e;
}
}
@AfterReturning(returning = "ret", pointcut = "methodPointcut()")
public void doAfterReturning(Object ret) throws Throwable {
LOG.info(" :" + ret);
}
private String parseParames(Object[] parames) {
if (null == parames || parames.length <= 0) {
return " ";
}
StringBuffer param = new StringBuffer(" # :[ ");
int i = 0;
for (Object obj : parames) {
i++;
if (i == 1) {
param.append(obj.toString());
continue;
}
param.append(" ,").append(obj.toString());
}
return param.append(" ]").toString().replace("#", String.valueOf(i));
}
}
Orderクラス
package com.yj.model;
public class Order {
private long orderId;
private String createTime;
public long getOrderId() {
return orderId;
}
public void setOrderId(long orderId) {
this.orderId = orderId;
}
public String getCreateTime() {
return createTime;
}
public void setCreateTime(String createTime) {
this.createTime = createTime;
}
@Override
public String toString() {
return "Order [orderId=" + orderId + ", createTime=" + createTime + "]";
}
}
カスタムレスポンスヘッダRespHeadクラス
package com.yj.model;
/**
*
* @author Administrator
*
*/
public class RespHead {
private int code=0;
private String desc;
public int getCode() {
return code;
}
public void setCode(int code) {
this.code = code;
}
public String getDesc() {
return desc;
}
public void setDesc(String desc) {
this.desc = desc;
}
@Override
public String toString() {
return "RespHead [code=" + code + ", desc=" + desc + "]";
}
}
カスタムレスポンス結果Resultクラス
package com.yj.model;
/**
*
* @author Administrator
*
* @param
*/
public class Result {
private RespHead respHead;
private T content;
public RespHead getRespHead() {
return respHead;
}
public void setRespHead(RespHead respHead) {
this.respHead = respHead;
}
public T getContent() {
return content;
}
public void setContent(T content) {
this.content = content;
}
@Override
public String toString() {
return "Result [respHead=" + respHead + ", content=" + content + "]";
}
}
Userクラス
package com.yj.model;
import java.util.List;
public class User {
private String name;
private int age;
private List orders;
public String getName() {
return name;
}
public void setName(String name) {
this.name = name;
}
public int getAge() {
return age;
}
public void setAge(int age) {
this.age = age;
}
public List getOrders() {
return orders;
}
public void setOrders(List orders) {
this.orders = orders;
}
@Override
public String toString() {
return "User [name=" + name + ", age=" + age + ", orders=" + orders + "]";
}
}
OrderServiceクラス
package com.yj.service;
import org.springframework.stereotype.Service;
import com.yj.model.Order;
import com.yj.utils.CommUtils;
@Service
public class OrderService {
public Order getOrder(Long orderId){
Order order =new Order();
order.setOrderId(orderId);
order.setCreateTime(CommUtils.getTimeStr());
return order;
}
}
UserServiceクラス
package com.yj.service;
import java.util.ArrayList;
import java.util.List;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service;
import com.yj.model.Order;
import com.yj.model.User;
@Service
public class UserService {
@Autowired
private OrderService orderService;
public User getUser(User user){
Order order=orderService.getOrder(1L);
List orders =new ArrayList();
orders.add(order);
user.setOrders(orders);
return user;
}
}
タイムツールクラス
package com.yj.utils;
import java.text.SimpleDateFormat;
import java.util.Calendar;
/**
*
* @author Administrator
*
*/
public class CommUtils {
public static final String format = "yyyy-MM-dd HH:mm:ss";
public static String getTimeStr() {
Calendar cal = Calendar.getInstance();
return new SimpleDateFormat(format).format(cal.getTime());
}
}
アプリケーションクラスの起動
package com.yj;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
@SpringBootApplication
public class Application {
public static void main(String[] args) throws Exception {
SpringApplication.run(Application.class, args);
}
}
アクセスの検証
http://localhost:8080/getUser
コンソール表示
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v1.5.2.RELEASE)
2018-09-30 23:44:36.964 INFO 2972 --- [ main] com.yj.Application : Starting Application on WIN-20180311JVI with PID 2972 (D:\workspace\Aspect2\target\classes started by Administrator in D:\workspace\Aspect2)
2018-09-30 23:44:36.968 INFO 2972 --- [ main] com.yj.Application : No active profile set, falling back to default profiles: default
2018-09-30 23:44:37.067 INFO 2972 --- [ main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@176dcec: startup date [Sun Sep 30 23:44:37 CST 2018]; root of context hierarchy
2018-09-30 23:44:40.145 INFO 2972 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)
2018-09-30 23:44:40.196 INFO 2972 --- [ main] o.apache.catalina.core.StandardService : Starting service Tomcat
2018-09-30 23:44:40.197 INFO 2972 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet Engine: Apache Tomcat/8.5.11
2018-09-30 23:44:40.583 INFO 2972 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2018-09-30 23:44:40.584 INFO 2972 --- [ost-startStop-1] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 3532 ms
2018-09-30 23:44:40.894 INFO 2972 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean : Mapping servlet: 'dispatcherServlet' to [/]
2018-09-30 23:44:40.909 INFO 2972 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'characterEncodingFilter' to: [/*]
2018-09-30 23:44:40.910 INFO 2972 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2018-09-30 23:44:40.910 INFO 2972 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2018-09-30 23:44:40.910 INFO 2972 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'requestContextFilter' to: [/*]
2018-09-30 23:44:41.912 INFO 2972 --- [ main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@176dcec: startup date [Sun Sep 30 23:44:37 CST 2018]; root of context hierarchy
2018-09-30 23:44:42.054 INFO 2972 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/getUser]}" onto public com.yj.model.Result com.yj.controller.UserController.getUser(com.yj.model.User)
2018-09-30 23:44:42.058 INFO 2972 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2018-09-30 23:44:42.059 INFO 2972 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-09-30 23:44:42.161 INFO 2972 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-09-30 23:44:42.161 INFO 2972 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-09-30 23:44:42.278 INFO 2972 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-09-30 23:44:42.648 INFO 2972 --- [ main] o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup
2018-09-30 23:44:42.942 INFO 2972 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2018-09-30 23:44:42.946 INFO 2972 --- [ main] com.yj.Application : Started Application in 6.481 seconds (JVM running for 7.448)
2018-09-30 23:44:43.611 INFO 2972 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring FrameworkServlet 'dispatcherServlet'
2018-09-30 23:44:43.611 INFO 2972 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization started
2018-09-30 23:44:43.657 INFO 2972 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization completed in 46 ms
2018-09-30 23:44:43.776 INFO 2972 --- [nio-8080-exec-1] com.yj.aspect.ControllerAspect : ==2018-09-30 23:44:43 com.yj.controller.UserController.getUser==
#####################################
2018-09-30 23:44:43.813 INFO 2972 --- [nio-8080-exec-1] com.yj.aspect.MethodAspect : com.yj.service.OrderService.getOrder , 1 :[ 1 ], :16 ms!
2018-09-30 23:44:43.814 INFO 2972 --- [nio-8080-exec-1] com.yj.aspect.MethodAspect : :Order [orderId=1, createTime=2018-09-30 23:44:43]
2018-09-30 23:44:43.814 INFO 2972 --- [nio-8080-exec-1] com.yj.aspect.MethodAspect : com.yj.service.UserService.getUser , 1 :[ User [name=null, age=0, orders=[Order [orderId=1, createTime=2018-09-30 23:44:43]]] ], :25 ms!
2018-09-30 23:44:43.814 INFO 2972 --- [nio-8080-exec-1] com.yj.aspect.MethodAspect : :User [name=null, age=0, orders=[Order [orderId=1, createTime=2018-09-30 23:44:43]]]
2018-09-30 23:44:43.815 INFO 2972 --- [nio-8080-exec-1] com.yj.aspect.ControllerAspect : ==2018-09-30 23:44:43 com.yj.controller.UserController.getUser ==
ページ表示