How to record the operation log gracefully?

Time:2022-5-4

Operation logs widely exist in various b-end and some C-end systems. For example, customer service can quickly know who has done what to the work order according to the operation log of the work order, and then quickly locate the problem. 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

How to record the operation log gracefully?

The difference between system log and operation log

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

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

The recording formats of operation logs are roughly divided into the following types:

  • 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 includes 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 monitor 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 method 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 monitor 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.

2.2 record by log file

log. Info ("order creation")
log. Info ("order has been created, order No.: {}", orderNo)
log. Info ("modified the shipping address of the order: from" {} "to" {} "," jincancan community "," Yinzhan community ")

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

Question 1: how does the operator record

With the help of MDC tool class in slf4j, put the operator in the log, and then print it uniformly in the log. First, put the user’s identity 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 into 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 the operation log from the system log

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">
    <File>logs/business.log</File>
    <append>true</append>
    <filter>
        <level>INFO</level>
        <onMatch>ACCEPT</onMatch>
        <onMismatch>DENY</onMismatch>
    </filter>
    <rollingPolicy>
        < filenamepattern > logs / business A.% d.% i.log < / filenamepattern >
        <maxHistory>90</maxHistory>
        <timeBasedFileNamingAndTriggeringPolicy>
            <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 faceted. The following contents will be introduced. In this way, you can save the log in a separate file, and then save the log in elasticsearch or database through log collection. Next, let’s see how to generate a readable operation log.

2.3 log through logutil

LogUtil. Log (orderNo, "order creation", "Xiaoming") template
  LogUtil. Log (orderNo, "order creation, order number" + "no.11089999", "Xiaoming")
  String template = "user% s modified the shipping address of the order: from '% s' to'% s'"
  LogUtil. Log (orderNo, string. Format (temporary, "Xiaoming", "jincancan community", "yinzhanzhan community"), "Xiaoming")

Here we explain why an orderNo is bound when recording the operation log, because the operation log records what “things” a “time” and “who” did to “what”. When querying the operation log of the business, all operations for this order will be queried. Therefore, 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, telephone, recipient and 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 the shipping address of the order: from"% s "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, recording the operation log in the business code will lead to complex business logic, and finally lead to logutils The call of LogRecord () method exists in the code of many businesses, and methods such as getlogcontent () are also scattered in various business classes, which is a disaster for the readability and maintainability of the code. Here’s 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 use AOP gracefully 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 achieve the purpose of recording operation logs through annotations. There are many ways to parse templates, which are implemented by using spring expression language (spel). We can first write down the desired way of logging, and then see if we can realize this function.

@LogRecord (content = "the shipping address of the order has been modified: from" #oldaddress "to" #request. Address ")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    //Update delivery information telephone, recipient and address
    doUpdate(request);
}

By referring to the parameters on the method through the spiel expression, the variables can be filled into the template to achieve the 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 delivery address.

  • The operation log of modifying the order delivery address needs to be bound to the delivery order, so all operations on the delivery order can be queried according to the delivery order number.

  • In order to record the previous shipping address on the annotation, a business independent oldaddress variable is added to the method signature, which is not elegant.

In order to solve the first two problems, we need to change the expected form of operation log into the following way:

@LogRecord(
     Content = "the shipping address of the order is modified from" #oldaddress "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 way to obtain the current login user is usercontext. Getcurrentuser()).

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

In this case, the operators on each @ LogRecord annotation are such a long string. In order to avoid too many duplicate codes, we can set the operator parameter on the annotation to non mandatory, so that users can fill in the operator. However, if the user does 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 = "the shipping address of the order is modified from" #oldaddress "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: in order to record the business operation records, we add an oldaddress variable, which is not a good implementation anyway. Therefore, next, we need to remove the oldaddress variable from the method signature of modifying the address. But the operation log does need the oldaddress variable. What should I 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”. But from the perspective of user experience, the first kind of copywriting is more humanized. Obviously, we won’t succeed in PK. Then we must query the 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. Let’s change the implementation code of operation log according to this idea.

@LogRecord (content = "the shipping address of the order is modified from" #oldaddress "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 the method signature to record the operation log. Although it is better than the previous code, we still need to add a line of code unrelated to business logic to the business code. If you have “obsessive-compulsive disorder”, you can continue to look down. Next, we will explain the solution of custom function. Here is another example:

@LogRecord (content = "the order's deliveryman is modified from" #olddeliveryuserid "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 recorded content of the template of this operation log is in this format: the order distributor is modified from “10090” to “10099”. Obviously, users do not understand this operation log. The user doesn’t know whether the user ID is 10090 or 10099. What the user expects to see is that the delivery clerk who has modified the order is changed from “Zhang San (18910008888)” to “Xiao Ming (13910006666)”. Users are concerned about the name and telephone number of the delivery clerk. However, the parameters passed in our method are only the ID of the distributor, and there is no name of the distributor to call. We can query the user’s name and phone number through the above method, and then implement it through logrecordcontext.

However, OCD does not expect the code of operation log to be embedded in business logic. Next, let’s consider another implementation: custom functions. If we can convert user ID into user name and phone number through user-defined functions, we can solve this problem. According to this idea, we modify the template to the following form:

@LogRecord (content = "the delivery clerk of the order has been modified: from" {deliveryuser {#olddeliveryuserid}} "to" {developeyuser {#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 curly braces to wrap spring’s spiel expression. The advantages of this are: first, it distinguishes spiel (spring expression language) from user-defined functions for easy parsing; Second, if the template does not require spel expression parsing, it can be easily identified, reducing spel parsing and improving performance. At this time, we found that the above code can also be optimized into the following form:

@LogRecord (content = "the delivery clerk of the order has been modified: from" {queryolduser {#request. Deliveryordno()}} "to" {deveryuser {#request. Userid}} ",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    //Update delivery information telephone, recipient and address
    doUpdate(request);
}

In this way, you don’t need to pass logrecordcontext in the modifyaddress method Putvariable() sets the old courier. By directly adding a new user-defined function queryolduser() parameter to pass in the delivery order, you can find the previous deliverer. You only need to run the analysis 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

How to record the operation log gracefully?

The above operation log is mainly realized through an AOP interceptor, which 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

  • Analytic logic

  • Template parsing

  • Logcontext logic

  • Default operator logic

  • Custom function logic

  • Default log persistence logic

  • Starter package logic

4.2.1 AOP interception logic

This logic is mainly an interceptor, which analyzes the operation log to be recorded according to 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, fail, category, detail, condition and other parameters are added in the annotation. These parameters are to meet specific scenarios, and specific examples will be given later.

How to record the operation log gracefully?

To keep it simple, there are only two required parameters for the component. Most of the AOP logic in 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 spring boot 1 In version 5, we manually implement the AOP logic of spring.

How to record the operation log gracefully?

The aspect is implemented by abstractbeanfactorypointcuttadvisor. The tangent point is the method that matches the annotation containing logrecordannotation through staticmethodmatcherpointcut. The enhanced logic of operation log is realized by implementing the methodinterceptor interface.

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

public class LogRecordPointcut extends StaticMethodMatcherPointcut implements Serializable {
    //Parsing class of LogRecord
    private LogRecordOperationSource logRecordOperationSource;
    
    @Override
    public boolean matches(@NonNull Method method, @NonNull Class<?> targetClass) {
          //Analyze whether there is @ logrecordannotation annotation on this method, and if so, analyze 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 analysis 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:

How to record the operation log gracefully?

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 implementation of the business method, the user-defined function parsed in advance will be evaluated, which solves the content before query and modification mentioned above.

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:

How to record the operation log gracefully?

Parsing core classes: the logrecordvalueparser encapsulates the custom function and the spiel parsing class 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 inherits from the cachedexpressionevaluator class, which has two maps, 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 the method, expression 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);

The getexpression method will get the expression parsing expression instance on the @logrecordannotation annotation annotation from the expressioncache, and then call the getValue method. The getValue passes in an evalcontext, which is an order object similar to the above example. The implementation of context will be described below.

Log context implementation

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 example of spel, the value of the expression can be smoothly resolved only when the parameters of the method and the variables in the logrecordcontext are placed in the object of the getValue method of spel. Let’s see how to implement it:

@LogRecord (content = "the order's delivery clerk has been modified: from" {deveryuser {#olddeliveryuserid} "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. Relevant codes are as follows:


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

When parsing, the parameter evalcontext passed in by calling getValue method is the evaluationcontext object above. The following is the inheritance system of logrecordevaluationcontext object:

How to record the operation log gracefully?

Logrecordevaluationcontext does three things:

  • Put the parameters of the method into the rootobject parsed by spiel.
  • Put all 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 < map < string, Object > > object directly here, but a stack structure? Let’s see why.

@LogRecord (content = "the order's delivery clerk has been modified: from" {deveryuser {#olddeliveryuserid} "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:

How to record the operation log gracefully?

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

How to record the operation log gracefully?

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 < map < string, Object > > has been released when parsing, so method 1 cannot obtain the corresponding variable. Method 1 and method 2 share the same variable map. Another problem is that if method 2 sets the same variable as method 1, the variables of the two methods will be overwritten with each other. Therefore, the life cycle of the variable of the final logrecordcontext needs to be in the following form:

How to record the operation log gracefully?

Each time logrecordcontext executes a method, it will stack a map. After the method is executed, it will pop < type data origin = “off” ignoretag = “true” > drop the map < / type >, so as to avoid the problem of variable sharing and overwriting.

Default operator logic

In logrecordinterceptor, ioperatorgetservice interface can be used to get 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();
}

The following is an example of obtaining a user from a user context:

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 you 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:

How to record the operation log gracefully?

The following is the interface definition of iparsefunction: the executebeefore function represents whether the user-defined function is parsed before the execution of business code. 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 function name functionname, then pass the parameter to the apply method of iparsefunction, and finally return the value of the function.

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 service can implement this save interface and save the log on any storage medium. Here is an example of log For the example of info saving in log file, the business can set the saving to be asynchronous or synchronous. It can be placed in a transaction with the business to ensure the consistency between the operation log and the business. It can also open a new transaction to ensure that the log errors do not affect the business transactions. The business can be saved in elastic search, database or file. Users can realize the corresponding query logic according to the 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 stands for tenant, which is used by multiple 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 imports logrecordconfigureselector Class, the logrecordproxyautoconfiguration class is exposed in the logrecordconfigureselector class.

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

    String tenant();

    AdviceMode mode() default AdviceMode.PROXY;
}

Logrecordproxyautoconfiguration 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 class: ioperatorgetservice, ilogrecordservice and iparsefunction respectively. The business can implement the corresponding interface by itself. 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; Through the four modules of the component, the specific implementation of the component is introduced.

6. References

  • Canal
  • spring-framework
  • Spring Expression Language (SpEL)
  • Differences among ThreadLocal, inheritablethreadlocal and transmittablethreadlocal