How to record operation logs gracefully?

Operation logs exist in almost every system, and these systems have a set of API s for recording operation logs. The operation log is different from the system log. The operation log must be simple and easy to understand. Therefore, how to make the operation log not coupled with business logic, how to make the content of the operation log easy to understand, and how to make the access of the operation log easier? These are the questions to be answered in this article, mainly focusing on how to "gracefully" record operation logs.

1. Usage scenario of operation log

example

Difference between system log and operation log

System log: the system log is mainly used to provide a basis for development and troubleshooting, and is generally printed in the log file; The readability requirements of the system log are not so high. The log will contain code information, such as printing a log in a certain line of a class.

Operation log: it is mainly used to record the addition or modification of an object after it is added or modified. The operation log requires strong readability, because it is mainly for users to see, such as the logistics information of orders. Users need to know what happened at what time. For another example, the customer service records the processing information of the work order.

The record formats of operation logs are roughly divided into the following: * simple text records, such as order creation at 10:00 on September 16, 2021* Simple dynamic text records, such as: 2021-09-16 10:00 order creation, order No.: NO.11089999, involving variable order No. "NO.11089999"* The text of the modification type contains the values before and after modification. For example, at 10:00 on September 16, 2021, user Xiaoming modified the delivery address of the order from "jincancan community" to "yinzhanzhan community", which involves the original address "jincancan community" and the new address "yinzhanzhan community" of variable delivery* Modifying a form will modify multiple fields at a time.

2. Implementation mode

2.1 use Canal to listen to the database and record the operation log

Canal is an open source component that provides incremental data subscription and consumption based on MySQL database incremental log analysis. By listening to the database Binlog, you can know which data has been modified from the bottom, and then record the operation log according to the changed data.

The advantage of this approach is that it is completely separated from business logic. The disadvantages are also obvious. The limitations are too high. You can only make operation log records for database changes. If the modification involves RPC calls from other teams, you can't listen to the database. For example, sending notifications to users is generally a public component within the company, At this time, you can only manually record the operation log of sending notifications when calling RPC.

  Scan VX for Java data, front-end, test, python and so on

2.2 record by log file

log.info("Order creation")
log.info("Order created, order No:{}", orderNo)
log.info("Modified shipping address of order: from“{}"Modify to“{}", "Jincancan community", "Yinzhan community")

Three problems need to be solved for operation recording in this way.

Question 1: how does the operator record

With the help of the MDC tool class in SLF4J, Put the operator in the log, and then print it uniformly in the log. First, Put the user ID into the MDC in the user's interceptor.

@Component
public class UserInterceptor extends HandlerInterceptorAdapter {
  @Override
  public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
    //Get user ID
    String userNo = getUserNo(request);
    //Put the user ID in the MDC context
    MDC.put("userId", userNo);
    return super.preHandle(request, response, handler);
  }

  private String getUserNo(HttpServletRequest request) {
    // Obtain the currently logged in user information through SSO, Cookie or Auth information
    return null;
  }
}

Secondly, format the userId into the log, and use% X{userId} to get the user ID in the MDC.

<pattern>"%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %X{userId} %logger{30}.%method:%L - %msg%n"</pattern>

Question 2: how to distinguish operation logs from system logs

By configuring the Log configuration file, the Log related to the operation Log is placed in a separate Log file.

//Different business logs are recorded to different files
<appender name="businessLogAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <File>logs/business.log</File>
    <append>true</append>
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
        <level>INFO</level>
        <onMatch>ACCEPT</onMatch>
        <onMismatch>DENY</onMismatch>
    </filter>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>logs/business A.%d.%i.log</fileNamePattern>
        <maxHistory>90</maxHistory>
        <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
            <maxFileSize>10MB</maxFileSize>
        </timeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
        <pattern>"%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %X{userId} %logger{30}.%method:%L - %msg%n"</pattern>
        <charset>UTF-8</charset>
    </encoder>
</appender>
        
<logger name="businessLog" additivity="false" level="INFO">
    <appender-ref ref="businessLogAppender"/>
</logger>

Then record the business log separately in the Java code.

//A statement that records a specific log
private final Logger businessLog = LoggerFactory.getLogger("businessLog");
 
//Log storage
businessLog.info("Modified shipping address");

Question 3: how to generate readable log copy

Log templates can be generated in the form of LogUtil or aspect, which will be described later. In this way, the logs can be saved in a separate file, and then the logs can be saved in Elasticsearch or database through log collection. Next, let's see how to generate readable operation logs.

2.3 log through LogUtil

  LogUtil.log(orderNo, "Order creation", "Xiao Ming")Template
  LogUtil.log(orderNo, "Order creation, order number"+"NO.11089999",  "Xiao Ming")
  String template = "user%s Modified shipping address of order: from“%s"Modify to“%s""
  LogUtil.log(orderNo, String.format(tempalte, "Xiao Ming", "Jincancan community", "Yinzhan community"),  "Xiao Ming")

Here we explain why an OrderNo is bound when recording the operation log, because the operation log records what "things" are done by a "time" and "who" to "what" . when querying the business operation log, all operations for this order will be queried, so OrderNo is added to the code. When recording the operation log, the operator needs to be recorded, so it is passed to the operator "Xiao Ming".

It seems that the above problem is not serious. In the business logic method of modifying the address, a line of code is used to record the operation log. Next, let's take a more complex example:

private OnesIssueDO updateAddress(updateDeliveryRequest request) {
    DeliveryOrder deliveryOrder = deliveryQueryService.queryOldAddress(request.getDeliveryOrderNo());
    // Update delivery information, phone, recipient, address
    doUpdate(request);
    String logContent = getLogContent(request, deliveryOrder);
    LogUtils.logRecord(request.getOrderNo(), logContent, request.getOperator);
    return onesIssueDO;
}

private String getLogContent(updateDeliveryRequest request, DeliveryOrder deliveryOrder) {
    String template = "user%s Modified shipping address of order: from“%s"Modify to“%s"";
    return String.format(tempalte, request.getUserName(), deliveryOrder.getAddress(), request.getAddress);
}

You can see that the above example uses two method codes and a getLogContent function to record the operation log. When the business becomes complex, putting the recorded operation log in the business code will lead to complex business logic. Finally, the call of LogUtils.logRecord() method exists in many business codes, which is similar to getLogContent() Such methods are also scattered in various business classes, which is a disaster for the readability and maintainability of the code. The following describes how to avoid this disaster.

2.4 method annotation implementation operation log

In order to solve the above problems, AOP is generally used to record logs to decouple operation logs from business logic. Next, let's take a simple example of AOP logs.

@LogRecord(content="Modified shipping address")
public void modifyAddress(updateDeliveryRequest request){
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

We can record the fixed copy in the annotated operation log, so that the business logic and business code can be decoupled and our business code can be purified. Some students may notice that although the above method decouples the code of the operation log, the recorded copy does not meet our expectations. The copy is static and does not include dynamic copy, because the operation log we need to record is that user% s modified the shipping address of the order from "% s" to "% s". Next, let's introduce how to gracefully use AOP to generate dynamic operation logs.

3. Gracefully support AOP to generate dynamic operation logs

3.1 dynamic formwork

When it comes to dynamic templates, it involves allowing variables to parse templates through placeholders, so as to record operation logs through annotations. There are many ways to parse templates, which are implemented using Spring Expression Language (SpEL). We can first write down the desired way of logging, and then see if we can achieve this function.

@LogRecord(content = "Modified shipping address of order: from“#oldAddress", Modify to“#request.address"")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

By referencing the parameters on the method through the spiel expression, variables can be filled into the template to achieve dynamic operation log text content. However, there are still several problems to be solved: * the operation log needs to know which operator modified the order shipping address. * the operation log modifying the order shipping address needs to be bound to the shipping order, so it can be ordered according to the shipping address Query all operations on this delivery order according to the document number. * in order to record the previous delivery address on the annotation, add a business independent oldAddress variable to the method signature, which is not elegant.

To solve the first two problems, we need to change the expected form of operation log to the following:

@LogRecord(
     content = "Modified shipping address of order: from“#oldAddress", Modify to“#request.address"",
     operator = "#request.userName", bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

The modified code adds two parameters to the annotation, one is the operator and the other is the object to be bound to the operation log. However, in ordinary Web applications, user information is stored in a static method of thread context, so the operator is generally written in this way (assuming that the method to obtain the current login user is UserContext.getCurrentUser()).

operator = "#{T(com.meituan.user.UserContext).getCurrentUser()}"

  Scan VX for Java data, front-end, test, python and so on

In this way, the operators on each @ LogRecord annotation are such a long string. In order to avoid too many repeated codes, we can set the operator parameter on the annotation to non mandatory, so that users can fill in the operators. However, if users do not fill in, we will take the user of UserContext (how to get the user will be described below) . finally, the simplest log becomes the following form:

@LogRecord(content = "Modified shipping address of order: from“#oldAddress", Modify to“#request.address"", 
           bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

Next, we need to solve the third problem: adding an oldAddress variable to record business operation records is not a good implementation anyway, so next, we need to remove the oldAddress variable from the method signature for modifying the address. But the operation log does need an oldAddress variable. What should we do?

Or have a PK with the product manager and ask the product manager to change the copy from "modified order delivery address: from xx to yy" to "modified order delivery address: yy" However, from the perspective of user experience, the first document is more user-friendly. Obviously, we will not succeed in PK. Then we must query this oldAddress and use it for the operation log. Another solution is to put this parameter in the thread context of the operation log for the template on the annotation. We will change it according to this idea Implementation code for logging.

@LogRecord(content = "Modified shipping address of order: from“#oldAddress", Modify to“#request.address"",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // Find out what the original address is
    LogRecordContext.putVariable("oldAddress", DeliveryService.queryOldAddress(request.getDeliveryOrderNo()));
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

At this time, it can be seen that LogRecordContext solves the problem of using variables other than method parameters on the operation log template, and avoids the design of modifying method signatures to record operation logs. Although it is better than the previous code, it still needs to add a line of code unrelated to business logic in the business code. If there is "obsessive-compulsive disorder" Students can continue to read. Next, we will explain the solution of user-defined functions. Let's take another example:

@LogRecord(content = "Distributor who modified the order: from“#oldDeliveryUserId", Modify to“#request.userId"",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // Find out what the original address is
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

The last content recorded in the template of this operation log is in this format: the order distributor is modified from "10090" to "10099". Obviously, the user does not understand this operation log. The user does not know whether the user ID is 10090 or 10099. What the user expects to see is: the order distributor is modified from "Zhang San (18910008888)" , it is modified to "Xiao Ming (13910006666)". The user cares about the name and telephone number of the distributor. However, the parameters passed in our method only have the ID of the distributor, and there is no name of the distributor to call. We can query the user's name and telephone number through the above method, and then implement it through LogRecordContext.

However, "obsessive compulsive disorder" does not expect the code of the operation log to be embedded in the business logic. Next, we consider another implementation method: user-defined function. If we can convert the user ID into the user name and phone through the user-defined function, we can solve this problem. According to this idea, we modify the template to the following form:

@LogRecord(content = "Distributor who modified the order: from“{deliveryUser{#oldDeliveryUserId}}", Modify to“{deveryUser{#request.userId}}"",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // Find out what the original address is
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

deliveryUser is a user-defined function, which uses braces to wrap Spring's SpEL expression. The advantages of this are: first, it uses Spring Expression Language (Spring Expression Language) It can be distinguished from user-defined functions for easy parsing. Second, if there is no need for SpEL expression parsing in the template, it can be easily identified to reduce SpEL parsing and improve performance. At this time, we find that the above code can also be optimized into the following form:

@LogRecord(content = "Distributor who modified the order: from“{queryOldUser{#request.deliveryOrderNo()}}", Modify to“{deveryUser{#request.userId}}"",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

In this way, there is no need to set the old courier through LogRecordContext.putVariable() in the modifyAddress method. By directly adding a new user-defined function queryOldUser() parameter to pass in the delivery order, we can find the previous distributor. We just need to run the resolution of the method before the modifyAddress() method is executed. In this way, we make the business code pure again, and make the "obsessive-compulsive disorder" no longer feel uncomfortable.

4. Code implementation analysis

4.1 code structure

The above operation log is mainly realized through an AOP interceptor. It is mainly divided into AOP module, log parsing module, log saving module and Starter module; The component provides four extension points: user defined function, default handler, business saving and query; Businesses can customize their own business logic according to their own business characteristics.

4.2 module introduction

With the above analysis, we have obtained a desired way of operation logging. Next, let's see how to implement the above logic. The implementation is mainly divided into the following steps: * AOP interception logic * parsing logic * template parsing * LogContext logic * default operator logic * custom function logic * default log persistence logic * Starter encapsulation logic

4.2.1 AOP interception logic

This logic is mainly an interceptor, which analyzes the operation log to be recorded for the @ LogRecord annotation, and then persists the operation log. Here, the annotation is named @ LogRecordAnnotation. Next, let's look at the definition of annotation:

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Inherited
@Documented
public @interface LogRecordAnnotation {
    String success();

    String fail() default "";

    String operator() default "";

    String bizNo();

    String category() default "";

    String detail() default "";

    String condition() default "";
}

In addition to the parameters mentioned above, the annotation also adds parameters such as fail, category, detail and condition to meet specific scenarios. Specific examples will be given later.

Parameter namedescribeRequired
successText template for operation logyes
failText version of operation log failureno
operatorExecutor of the operation logno
bizNoBusiness object ID of operation log bindingyes
categoryType of operation logno
detailExtend the parameter to record the modification details of the operation logno
conditionConditions for loggingno

To keep things simple, there are only two required parameters for the component. Most of the AOP logic in the business is implemented using @ Aspect annotation, but the compatibility of annotation based AOP in Spring boot 1.5 is problematic. In order to be compatible with the version of Spring boot 1.5, we manually implement the AOP logic of Spring.

Section selection   AbstractBeanFactoryPointcutAdvisor   The pointcut is achieved by   StaticMethodMatcherPointcut   Match contains   LogRecordAnnotation   Annotation method. Through implementation   MethodInterceptor   The interface implements the enhanced logic of the operation log.

The following is the cut-off point logic of the Interceptor:

public class LogRecordPointcut extends StaticMethodMatcherPointcut implements Serializable {
    // Resolution class of LogRecord
    private LogRecordOperationSource logRecordOperationSource;
    
    @Override
    public boolean matches(@NonNull Method method, @NonNull Class<?> targetClass) {
          // Resolve whether there is @ LogRecordAnnotation annotation on this method, and if so, resolve the parameters on the annotation
        return !CollectionUtils.isEmpty(logRecordOperationSource.computeLogRecordOperations(method, targetClass));
    }

    void setLogRecordOperationSource(LogRecordOperationSource logRecordOperationSource) {
        this.logRecordOperationSource = logRecordOperationSource;
    }
}

The main codes of the enhanced logic of the section are as follows:

@Override
public Object invoke(MethodInvocation invocation) throws Throwable {
    Method method = invocation.getMethod();
    // Log
    return execute(invocation, invocation.getThis(), method, invocation.getArguments());
}

private Object execute(MethodInvocation invoker, Object target, Method method, Object[] args) throws Throwable {
    Class<?> targetClass = getTargetClass(target);
    Object ret = null;
    MethodExecuteResult methodExecuteResult = new MethodExecuteResult(true, null, "");
    LogRecordContext.putEmptySpan();
    Collection<LogRecordOps> operations = new ArrayList<>();
    Map<String, String> functionNameAndReturnMap = new HashMap<>();
    try {
        operations = logRecordOperationSource.computeLogRecordOperations(method, targetClass);
        List<String> spElTemplates = getBeforeExecuteFunctionTemplate(operations);
        //User defined function parsing before business logic execution
        functionNameAndReturnMap = processBeforeExecuteFunctionTemplate(spElTemplates, targetClass, method, args);
    } catch (Exception e) {
        log.error("log record parse before function exception", e);
    }
    try {
        ret = invoker.proceed();
    } catch (Exception e) {
        methodExecuteResult = new MethodExecuteResult(false, e, e.getMessage());
    }
    try {
        if (!CollectionUtils.isEmpty(operations)) {
            recordExecute(ret, method, args, operations, targetClass,
                    methodExecuteResult.isSuccess(), methodExecuteResult.getErrorMsg(), functionNameAndReturnMap);
        }
    } catch (Exception t) {
        //Log errors should not affect business
        log.error("log record parse exception", t);
    } finally {
        LogRecordContext.clear();
    }
    if (methodExecuteResult.throwable != null) {
        throw methodExecuteResult.throwable;
    }
    return ret;
}

Process of interception logic:

It can be seen that the record persistence of the operation log is executed after the method is executed. When the method throws an exception, the exception will be caught first, and then the exception will be thrown after the operation log persistence is completed. Before the business method is executed, the user-defined functions parsed in advance will be evaluated, which solves the problems mentioned above before query and modification.

4.2.2 parsing logic

Template parsing

Spring 3 provides a very powerful function: Spring EL, which is the core basic module of expression evaluation in spring products. It can be used independently of spring. for instance:

public static void main(String[] args) {
        SpelExpressionParser parser = new SpelExpressionParser();
        Expression expression = parser.parseExpression("#root.purchaseName");
        Order order = new Order();
        order.setPurchaseName("Zhang San");
        System.out.println(expression.getValue(order));
}

This method will print "Zhang San". The class diagram of LogRecord parsing is as follows:

Parsing core class: LogRecordValueParser   It encapsulates custom functions and spiel parsing classes   LogRecordExpressionEvaluator.

public class LogRecordExpressionEvaluator extends CachedExpressionEvaluator {

    private Map<ExpressionKey, Expression> expressionCache = new ConcurrentHashMap<>(64);

    private final Map<AnnotatedElementKey, Method> targetMethodCache = new ConcurrentHashMap<>(64);

    public String parseExpression(String conditionExpression, AnnotatedElementKey methodKey, EvaluationContext evalContext) {
        return getExpression(this.expressionCache, methodKey, conditionExpression).getValue(evalContext, String.class);
    }
}

LogRecordExpressionEvaluator   Inherited from   CachedExpressionEvaluator   Class. There are two maps in this class, one is expressionCache and the other is targetMethodCache. As can be seen from the above example, SpEL will be parsed into an Expression expression Expression, and then the corresponding value will be obtained according to the incoming Object. Therefore, expressionCache is to cache the corresponding relationship between methods, expressions and SpEL Expression, so that the SpEL Expression added on the method annotation can be parsed only once. The following targetMethodCache is used to cache the objects passed into the Expression expression Expression. The core parsing logic is the last line of code above.

getExpression(this.expressionCache, methodKey, conditionExpression).getValue(evalContext, String.class);

getExpression   The method will get an instance of the parsing Expression of the expression on the @LogRecordAnnotation annotation from expressionCache and then call it.   getValue   Method, getValue   Pass in an evalContext, which is similar to the order object in the above example. The implementation of Context will be described below.

Log context implementation

  Scan VX for Java data, front-end, test, python and so on

In the following example, the variables are placed in the LogRecordContext, and then the SpEL expression can smoothly resolve the parameters that do not exist in the method. As can be seen from the above SpEL example, the method parameters and the variables in the LogRecordContext should be placed in the SpEL   getValue   Method can successfully parse the value of the expression. Here's how to implement it:

@LogRecord(content = "Distributor who modified the order: from“{deveryUser{#oldDeliveryUserId}}", Modify to“{deveryUser{#request.getUserId()}}"",
            bizNo="#request.getDeliveryOrderNo()")
public void modifyAddress(updateDeliveryRequest request){
    // Find out what the original address is
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

An EvaluationContext is created in LogRecordValueParser to parse method parameters and variables in Context for spiel. The relevant codes are as follows:

EvaluationContext evaluationContext = expressionEvaluator.createEvaluationContext(method, args, targetClass, ret, errorMsg, beanFactory);

Called when parsing   getValue   The parameter evalContext passed in by the method is the above EvaluationContext object. The following is the inheritance system of LogRecordEvaluationContext object:

LogRecordEvaluationContext does three things: * put the parameters of the method into the RootObject parsed by spiel. * put the variables in LogRecordContext into RootObject. * put the return value of the method and ErrorMsg into RootObject.

The code of LogRecordEvaluationContext is as follows:

public class LogRecordEvaluationContext extends MethodBasedEvaluationContext {

    public LogRecordEvaluationContext(Object rootObject, Method method, Object[] arguments,
                                      ParameterNameDiscoverer parameterNameDiscoverer, Object ret, String errorMsg) {
       //Put the parameters of the method into the RootObject parsed by spiel
       super(rootObject, method, arguments, parameterNameDiscoverer);
       //Put all variables in LogRecordContext into RootObject
        Map<String, Object> variables = LogRecordContext.getVariables();
        if (variables != null && variables.size() > 0) {
            for (Map.Entry<String, Object> entry : variables.entrySet()) {
                setVariable(entry.getKey(), entry.getValue());
            }
        }
        //Put the return value of the method and ErrorMsg into RootObject
        setVariable("_ret", ret);
        setVariable("_errorMsg", errorMsg);
    }
}

The following is the implementation of LogRecordContext. In this class, a stack is maintained through a ThreadLocal variable. In the stack is a Map, which corresponds to the name and value of the variable.

public class LogRecordContext {

    private static final InheritableThreadLocal<Stack<Map<String, Object>>> variableMapStack = new InheritableThreadLocal<>();
   //Other omissions
}

InheritableThreadLocal is used above, so there will be problems when using LogRecordContext in the scenario of thread pool. If thread pool is supported, Alibaba's open source TTL framework can be used. Then why not set a ThreadLocal > object directly here, but a Stack structure? Let's see why.

@LogRecord(content = "Distributor who modified the order: from“{deveryUser{#oldDeliveryUserId}}", Modify to“{deveryUser{#request.getUserId()}}"",
        bizNo="#request.getDeliveryOrderNo()")
public void modifyAddress(updateDeliveryRequest request){
    // Find out what the original address is
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // Update delivery information telephone, recipient and address
    doUpdate(request);
}

The execution process of the above code is as follows:

There seems to be no problem, but when another LogRecordAnnotation method is nested in the LogRecordAnnotation method, the process becomes the following form:

It can be seen that after method 2 releases the variable, continue to execute the logRecord logic of method 1. At this time, the Map of ThreadLocal > has been released when parsing, so method 1 cannot obtain the corresponding variable. Method 1 and method 2 share a variable Map. Another problem is: if method 2 sets the same variable as method 1, the variables of the two methods Therefore, the life cycle of the final LogRecordContext variable needs to be in the following form:

Every time LogRecordContext executes a method, it will stack a Map. After the method is executed, it will Pop the Map, so as to avoid the problem of variable sharing and overwriting.

Default operator logic

In LogRecordInterceptor, IOperatorGetService interface, which can obtain the current user. The following is the definition of the interface:

public interface IOperatorGetService {

    /**
     * You can get the currently logged in user inside and outside, such as UserContext.getCurrentUser()
     *
     * @return Convert to Operator return
     */
    Operator getUser();
}

An example of obtaining a user from a user context is given below:

public class DefaultOperatorGetServiceImpl implements IOperatorGetService {

    @Override
    public Operator getUser() {
    //UserUtils is the method to get the user context
         return Optional.ofNullable(UserUtils.getUser())
                        .map(a -> new Operator(a.getName(), a.getLogin()))
                        .orElseThrow(()->new IllegalArgumentException("user is null"));
        
    }
}

When the component parses the operator, it determines whether the operator on the annotation is empty. If it is not specified in the annotation, we get it from the getUser method of IOperatorGetService. If we can't get it, an error will be reported.

String realOperatorId = "";
if (StringUtils.isEmpty(operatorId)) {
    if (operatorGetService.getUser() == null || StringUtils.isEmpty(operatorGetService.getUser().getOperatorId())) {
        throw new IllegalArgumentException("user is null");
    }
    realOperatorId = operatorGetService.getUser().getOperatorId();
} else {
    spElTemplates = Lists.newArrayList(bizKey, bizNo, action, operatorId, detail);
}

Custom function logic

The class diagram of user-defined functions is as follows:

The following is the interface definition of IParseFunction: executebeefore   The function represents whether the user-defined function is parsed before the business code is executed. The content before query modification mentioned above.

public interface IParseFunction {

  default boolean executeBefore(){
    return false;
  }

  String functionName();

  String apply(String value);
}

The code of ParseFunctionFactory is relatively simple. Its function is to inject all iparsefunctions into the function factory.

public class ParseFunctionFactory {
  private Map<String, IParseFunction> allFunctionMap;

  public ParseFunctionFactory(List<IParseFunction> parseFunctions) {
    if (CollectionUtils.isEmpty(parseFunctions)) {
      return;
    }
    allFunctionMap = new HashMap<>();
    for (IParseFunction parseFunction : parseFunctions) {
      if (StringUtils.isEmpty(parseFunction.functionName())) {
        continue;
      }
      allFunctionMap.put(parseFunction.functionName(), parseFunction);
    }
  }

  public IParseFunction getFunction(String functionName) {
    return allFunctionMap.get(functionName);
  }

  public boolean isBeforeFunction(String functionName) {
    return allFunctionMap.get(functionName) != null && allFunctionMap.get(functionName).executeBefore();
  }
}

The logic of DefaultFunctionServiceImpl is to find the corresponding IParseFunction according to the passed in function name, functionName, and then pass the parameters into the IParseFunction   apply   The value of the last function returned on the method.

public class DefaultFunctionServiceImpl implements IFunctionService {

  private final ParseFunctionFactory parseFunctionFactory;

  public DefaultFunctionServiceImpl(ParseFunctionFactory parseFunctionFactory) {
    this.parseFunctionFactory = parseFunctionFactory;
  }

  @Override
  public String apply(String functionName, String value) {
    IParseFunction function = parseFunctionFactory.getFunction(functionName);
    if (function == null) {
      return value;
    }
    return function.apply(value);
  }

  @Override
  public boolean beforeFunction(String functionName) {
    return parseFunctionFactory.isBeforeFunction(functionName);
  }
}

4.2.3 log persistence logic

Similarly, ILogRecordService is referenced in the code of LogRecordInterceptor. This Service mainly includes the interface of logging.

public interface ILogRecordService {
    /**
     * Save log
     *
     * @param logRecord Log entity
     */
    void record(LogRecord logRecord);

}

The business can implement this save interface and save the log on any storage medium. Here is an example of saving the log in the log file through log.info introduced in Section 2.2. The business can set the save to asynchronous or synchronous, and can be placed in a transaction with the business to ensure the consistency between the operation log and the business, or a new transaction can be opened to ensure the log Business can be saved in Elasticsearch, database or file. Users can implement corresponding query logic according to log structure and log storage.

@Slf4j
public class DefaultLogRecordServiceImpl implements ILogRecordService {

    @Override
//    @Transactional(propagation = Propagation.REQUIRES_NEW)
    public void record(LogRecord logRecord) {
        log.info("[logRecord]log={}", logRecord);
    }
}

4.2.4 Starter logic package

The above logic code has been introduced. Next, you need to assemble these components and let users use them. When using this component, you only need to add an annotation @ EnableLogRecord(tenant = "com.mzt.test") on the entry of Springboot. Tenant represents tenants and is used for multi tenants.

@SpringBootApplication(exclude = DataSourceAutoConfiguration.class)
@EnableTransactionManagement
@EnableLogRecord(tenant = "com.mzt.test")
public class Main {

    public static void main(String[] args) {
        SpringApplication.run(Main.class, args);
    }
}

Take another look at the code of EnableLogRecord, which is imported   LogRecordConfigureSelector.class, in   LogRecordConfigureSelector   Exposed in class   LogRecordProxyAutoConfiguration   Class.

@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Documented
@Import(LogRecordConfigureSelector.class)
public @interface EnableLogRecord {

    String tenant();
    
    AdviceMode mode() default AdviceMode.PROXY;
}

LogRecordProxyAutoConfiguration   This is the core class for assembling the above components. The code is as follows:

@Configuration
@Slf4j
public class LogRecordProxyAutoConfiguration implements ImportAware {

  private AnnotationAttributes enableLogRecord;


  @Bean
  @Role(BeanDefinition.ROLE_INFRASTRUCTURE)
  public LogRecordOperationSource logRecordOperationSource() {
    return new LogRecordOperationSource();
  }

  @Bean
  @ConditionalOnMissingBean(IFunctionService.class)
  public IFunctionService functionService(ParseFunctionFactory parseFunctionFactory) {
    return new DefaultFunctionServiceImpl(parseFunctionFactory);
  }

  @Bean
  public ParseFunctionFactory parseFunctionFactory(@Autowired List<IParseFunction> parseFunctions) {
    return new ParseFunctionFactory(parseFunctions);
  }

  @Bean
  @ConditionalOnMissingBean(IParseFunction.class)
  public DefaultParseFunction parseFunction() {
    return new DefaultParseFunction();
  }


  @Bean
  @Role(BeanDefinition.ROLE_INFRASTRUCTURE)
  public BeanFactoryLogRecordAdvisor logRecordAdvisor(IFunctionService functionService) {
    BeanFactoryLogRecordAdvisor advisor =
            new BeanFactoryLogRecordAdvisor();
    advisor.setLogRecordOperationSource(logRecordOperationSource());
    advisor.setAdvice(logRecordInterceptor(functionService));
    return advisor;
  }

  @Bean
  @Role(BeanDefinition.ROLE_INFRASTRUCTURE)
  public LogRecordInterceptor logRecordInterceptor(IFunctionService functionService) {
    LogRecordInterceptor interceptor = new LogRecordInterceptor();
    interceptor.setLogRecordOperationSource(logRecordOperationSource());
    interceptor.setTenant(enableLogRecord.getString("tenant"));
    interceptor.setFunctionService(functionService);
    return interceptor;
  }

  @Bean
  @ConditionalOnMissingBean(IOperatorGetService.class)
  @Role(BeanDefinition.ROLE_APPLICATION)
  public IOperatorGetService operatorGetService() {
    return new DefaultOperatorGetServiceImpl();
  }

  @Bean
  @ConditionalOnMissingBean(ILogRecordService.class)
  @Role(BeanDefinition.ROLE_APPLICATION)
  public ILogRecordService recordService() {
    return new DefaultLogRecordServiceImpl();
  }

  @Override
  public void setImportMetadata(AnnotationMetadata importMetadata) {
    this.enableLogRecord = AnnotationAttributes.fromMap(
            importMetadata.getAnnotationAttributes(EnableLogRecord.class.getName(), false));
    if (this.enableLogRecord == null) {
      log.info("@EnableCaching is not present on importing class");
    }
  }
}

This class inherits ImportAware to get the tenant attribute on EnableLogRecord. This class uses the variables logRecordAdvisor and logRecordInterceptor to assemble AOP, and injects the custom function into logRecordAdvisor.

External extension classes: IOperatorGetService, ILogRecordService and IParseFunction respectively. Businesses can implement corresponding interfaces by themselves. Because @ ConditionalOnMissingBean is configured, the user's implementation class will override the default implementation in the component.

5. Summary

This article introduces the common writing methods of operation log and how to make the implementation of operation log simpler and easier to understand. It introduces the specific implementation of the component through the four modules of the component. If you have any questions about the above component introduction, you are welcome to leave a message at the end of the article and we will answer them.

  Scan VX for Java data, front-end, test, python and so on

Tags: Java Back-end

Posted on Tue, 30 Nov 2021 20:09:12 -0500 by 156418