Interface logs are useful

In our daily development process, we can view some details of the interface through the interface log. For example, the IP address of the client, the type of the client, the response time, the type of the request, the interface method of the request and so on, we can conduct statistical analysis on these data and extract the information we want.

How do I get interface logs

Here, we use Spring’s two killer AOP by defining pointcuts at the Controller layer, then analyzing the request object for interface information, and turning on a ThreadLocal to record response times.

Notes on AOP

  • @Aspect: Defines a class as an aspect class.
  • @Pointcut: Defines a pointcut.
  • @Before: Cut content at the beginning of the pointcut.
  • @After: Cuts content at the end of the pointcut.
  • @AfterReturningEnter the content after the pointcut returns the content (this can be used to do some processing on the return value of the processing.
  • @Around: Access content before and after the pointcut, and control when the content of the pointcut itself executes
  • @AfterThrowing: used to handle the processing logic after an exception is thrown in the content section.
  • @Order: Operations before the pointcut are performed in ascending order values; Operations after the pointcut are performed in ascending order.

Practical application

One: Introduce dependencies

First, we need to add the dependency to introduce AOP, as well as the UserAgentUtils package for analyzing client information, and the Lombok package for @slf4J to print logs:

		<dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>
        <dependency>
            <groupId>eu.bitwalker</groupId>
            <artifactId>UserAgentUtils</artifactId>
            <version>1.20</version>
        </dependency>
Copy the code

Define a ResponseAop section class

We already defined this class in the uniform return value and exception handling section, and here we refine it. So let me write the code again:

@Aspect
@Order(5)
@Component
@Slf4j
public class ResponseAop
Copy the code

Define a ThreadLocal variable

Defining basic types directly here would have synchronization problems, so we define a ThreadLocal object to keep track of the elapsed time.

ThreadLocal<Long> startTime = new ThreadLocal<>();
Copy the code

Four: define the tangent point

Note here is the cut point writing method, must be correct to ensure that AOP works! Here are some simple ways to write an execution expression, which will be covered in a separate chapter.

  • Any public method:execution(public * *(..) )
  • Execution of any method starting with “set” :execution(* set*(..) )
  • Execution of any method on the Service interface:execution(* com.xyz.service.Service.*(..) )
  • Execution of arbitrary methods defined in the service package:execution(* com.xyz.service.*.*(..) )
  • Defines the execution of any method of any class in the service package and all subpackages: execution(* com.xyz.service.. *. * (..) )
	/** ** cut point */
    @Pointcut("execution(public * indi.viyoung.viboot.*.controller.. * (..) )")
    public void httpResponse(a) {}Copy the code

Five: Get the request information in @before

@Before("httpResponse()")
    public void doBefore(JoinPoint joinPoint){
    	// Start the timer
        startTime.set(System.currentTimeMillis());
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        // Print the requested content
        UserAgent userAgent = UserAgent.parseUserAgentString(request.getHeader("User-Agent"));// Get the user-agent in the request header
        log.info("Interface path: {}" , request.getRequestURL().toString());
        log.info("Browser: {}", userAgent.getBrowser().toString());
        log.info("Browser version: {}",userAgent.getBrowserVersion());
        log.info("Operating system: {}", userAgent.getOperatingSystem().toString());
        log.info("IP : {}" , request.getRemoteAddr());
        log.info("Request type: {}", request.getMethod());
        log.info("Class method:" + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
        log.info("Request parameters: {}" + Arrays.toString(joinPoint.getArgs()));
    }
Copy the code

Get the return value and execution time of a method in @afterRETURNING

	@AfterReturning(returning = "ret" , pointcut = "httpResponse()")
    public void doAfterReturning(Object ret){
        // After the request is processed, the content is returned
        log.info(Method return value: {} , ret);
        log.info("Method execution time: {} ms", (System.currentTimeMillis() - startTime.get()));
    }
Copy the code

Seven: test results

Here, we access an interface:

2019-02-21 21:03:31.358  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: interface path: HTTP://localhost:8090/users
2019-02-21 21:03:31.359  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: the browser: CHROME2019-02-21 21:03:31.359  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: browser version:72.03626.109.2019-02-21 21:03:31.360  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: operating system: MAC_OS_X2019-02-21 21:03:31.360  INFO 11788 --- [nio-8090-exec-5] indi.viyoung.viboot.aop.ResponseAop      : IP : 0:0:0:0:0:0:0:1
2019-02-21 21:03:31.360  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: request type: a GET2019-02-21 21:03:31.360  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: class methods: indi. Viyoung. Viboot. Apilog. Controller. The UserController. The.findall2019-02-21 21:03:31.360  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: request parameters: {} []...2019-02-21 21:03:31.393  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: method return values: ReturnVO {code ='2000', message='Operation successful', data=[User(id=10000001, password=123456, userName=vi-young), User(id=10000002, password=123456, userName=vi-young), User(id=10000003, password=123123, userName=lxt), User(id=10000004, password=123456, userName=yangwei)]}
2019-02-21 21:03:31.393  INFO 11788 --- [nio-8090-exec-5] indi. Viyoung. Viboot. Aop. ResponseAop: method execution time:36msCopy the code

As you can see, we’ve got the information we want

In the practical application, we will save the information in the database and use some data analysis tools for analysis.

The public,

Your recommendation is the greatest help to me!