SpringのAOPはログ出力を実現し、記録方法の実行時間

17264 ワード

AOPをよりよく理解するために、実践を行い、AOPでログ出力を実現し、方法の実行時間を記録する.プロジェクト全体構造Spring之AOP实现日志输出,记录方法执行时间_第1张图片プロジェクト概要;プロジェクトはSpringBootの簡単なアクセスモジュールを採用しています.このモジュールのログ出力をAOPで実現し,メソッドの実行時間を記録する.
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  ==

ページ表示Spring之AOP实现日志输出,记录方法执行时间_第2张图片