Unified processing of Web request logs using AOP in Spring boot

AOP is the abbreviation of Aspect oriented programming, which means: face-cutting programming, through the pre-compilation method and run-time dynamic agent implementation of the unified maintenance of the program functions of a technology. AOP is an important part of the spring framework by defining an entry point for an existing program and then cutting into different executions before and after it, such as: Opening a database connection/closing a database connection, opening a transaction/closing a transaction, logging, and so on. AOP does not break the original program logic, so it can be very good to isolate the various parts of the business logic, thus reducing the coupling between parts of business logic, improving the reusability of the program, and improving the efficiency of development.

Here are two topics, one on how to introduce AOP in spring boot, and how to use AOP as a slice to unify the log of Web requests.

All of the following operations are based on the Chapter4-2-2 project.

Preparatory work

Because you need to make a slice of the Web request to log logs, you first introduce the Web module and create a simple hello request processing.

• pom.xmlThe introduction of Web modules in

12345

<dependency> <groupid>org.springframework.boot</groupid> <artifactid>spring-boot-starter-web</artifactid> </dependency>

• Implement a simple request processing: Returns the function "Hello xxx" by passing in the name parameter.

1234567891011

@RestController public class Hellocontroller { @RequestMapping (value = "/hello", method = Requestmethod.get)@ResponseBodypublicstring Hello(@RequestParam string name) { return "Hello" + name;}}

Below, we can make a slice log record of the above/hello request.

Introducing AOP Dependencies

Introducing AOP in spring boot is as simple as introducing other modules, just pom.xml add the following dependencies in:

12345

<dependency> <groupid>org.springframework.boot</groupid> <artifactid>spring-boot-starter-aop</artifactid> </dependency>

After the introduction of the AOP dependency package is completed, it is generally not necessary to do other configuration. Perhaps people who have used the annotation configuration method in spring will ask if it needs to be added to the main class of the program @EnableAspectJAutoProxy and is not actually needed.

You can look at the following default configuration properties for AOP, where spring.aop.auto properties are turned on by default, which means that the default is increased as long as the AOP dependency is introduced @EnableAspectJAutoProxy .

12345

# AOPspring.aop.auto=true # Add @EnableAspectJAutoProxy. Spring.aop.proxy-target-class=false # Whether subclass-based (CGLIB) proxies is to be created (true)as opposed to standard Java interface-based proxies (false).

And when we need to use Cglib to implement AOP, we need to configure spring.aop.proxy-target-class=true , otherwise the default is to use the standard Java implementation.

Implementing a log slice of the web layer

The facets that implement AOP are mainly the following elements:

• Use @Aspect annotations to define a Java class as a slice class
• Use to @Pointcut define a pointcut, which can be a regular expression, such as all functions under a package in the following example, or an annotation.
• Cut-in content at different points in the pointcut as needed
  • Use @Before to cut into content at the beginning of a pointcut
  • Use @After to cut into content at the end of a pointcut
  • Use to @AfterReturning cut into content after entry return content (can be used to do some processing of processing return values)
  • Use to @Around cut content before and after a pointcut, and control when to execute the pointcut itself
  • @AfterThrowingthe processing logic used to handle the exception that is thrown when the cut-in content part throws

1234567891011121314151617181920212223242526272829303132

@Aspect@Componentpublic class Weblogaspect { private Logger Logger = Logger.getlogger (GetClass ()); @Pointcut ("Execution (public * com.didispace.web). *.*(..))")public void WebLog() {} @Before ("WebLog ()") public void dobefore(joinpoint joinpoint) throws Throwable { //Receive request, log request contentServletrequestattributes attributes = (servletrequestattributes) requestcontextholder.getrequestattributes (); HttpServletRequest request = Attributes.getrequest ();//Record the requested contentLogger.info ("URL:" + request.getrequesturl (). toString ());Logger.info ("Http_method:" + Request.getmethod ());Logger.info ("IP:" + request.getremoteaddr ());Logger.info ("Class_method:" + joinpoint.getsignature (). Getdeclaringtypename () + "." + joinpoint.getsignature (). GetName () );Logger.info ("ARGS:" + arrays.tostring (Joinpoint.getargs ()));}@AfterReturning (returning = "ret", pointcut = "WebLog ()") public void doafterreturning(Object ret) throws Throwable { //Finished processing the request, return contentLogger.info ("RESPONSE:" + ret);} }

You can see the example above, by @Pointcut defining the pointcut for com.didispace.web all functions under the package (the Web layer all request processing to make a pointcut), and then through the @Before implementation, the request content of the log record (this article only describes the process, you can adjust the content as needed), and finally through @AfterReturning Records the object returned by the request.

By running the program and accessing: http://localhost:8080/hello?name=didi , you can get the following log output

1234567

2016-05-19 13:42:13,156 info weblogaspect:41-url:http://localhost:8080/hello2016-05-19 13:42:13,156 Info weblogaspect:42-http_method:http://localhost:8080/hello2016-05-19 13:42:13,157 INFO weblogaspect:43-ip:0:0:0:0:0: 0:0:12016-05-19 13:42:13,160 INFO weblogaspect:44-class_method:com.didispace.web.hellocontroller.hello2016-05-19 13:42:13,160 info Weblogaspect:45-args: [didi]2016-05-19 13:42:13,170 info Weblogaspect:52-response:hello Didi

Optimization: Synchronization issues in AOP facets

In the Weblogaspect section, respectively, through the Dobefore and doafterreturning two separate functions to achieve the tangent head and the pointcut after the return of the execution of the content, if we want to count the processing time of the request, we need to record time at Dobefore, The consumed time of the request processing is calculated at the doafterreturning by the current time and the time recorded at the beginning.

So can we define a member variable in the Weblogaspect slice to be accessed by Dobefore and doafterreturning? Is there a sync problem?

It is true that there is a synchronization problem in defining the basic type directly here, so we can introduce the Threadlocal object and record it as follows:

12345678910111213141516171819202122232425262728

@Aspect@Componentpublic class Weblogaspect { private Logger Logger = Logger.getlogger (GetClass ());Threadlocal<long> StartTime =new Threadlocal<> ();@Pointcut ("Execution (public * com.didispace.web). *.*(..))")public void WebLog() {} @Before ("WebLog ()") public void dobefore(joinpoint joinpoint) throws Throwable { Starttime.set (System.currenttimemillis ());//Omit log record contents}@AfterReturning (returning = "ret", pointcut = "WebLog ()") public void doafterreturning(Object ret) throws Throwable { //Finished processing the request, return contentLogger.info ("RESPONSE:" + ret);Logger.info ("Spend time:" + (System.currenttimemillis ()-Starttime.get ()));}  }

Optimization: Precedence of AOP facets

Due to the implementation of AOP, the program is well decoupled, but also brings some problems, such as: We may be on the web layer to do multiple facets, verify the user, check the header information and so on, this time often encounter the processing order of the aspect of the problem.

So, we need to define the priority of each slice, and we need @Order(i) annotations to identify the priority of the slices. the smaller the value of I, the higher the priority . Suppose we also have a tangent that is used to verify that the CheckNameAspect name must be Didi, which we set for it, @Order(10) and Weblogaspect is set in the above @Order(5) , so Weblogaspect has a higher priority, this time the order of execution is this:

• What @Before to do in priority @Order(5) , and what to do @Order(10)
• Content to be executed in and out of @After @AfterReturning priority @Order(10) @Order(5)

So we can summarize this:

• Operations in front of pointcuts, by order value from small to large execution
• Operations after pointcuts, executed by order value from large to small

Use AOP to uniformly process Web request logs

in Spring boot