15 suggestions for log printing

Posted by Pozor on Wed, 03 Nov 2021 01:30:08 +0100

preface

Log is a good helper for quickly locating problems, tearing and throwing the pot   My weapon! It is very important to print a good log. Today, let's talk about log printing   15 good suggestions~

I would like to recommend my own Spring Boot project:

https://github.com/YunaiV/ruoyi-vue-pro

1. Select the appropriate log level

There are five common log levels: error, warn, info, debug and trace. In daily development, we need to select the appropriate log level. Don't backhand or print info~

  • Error: error log, which refers to serious errors that affect normal business and require operation and maintenance configuration monitoring  ;

  • warn: the warning log is a general error, which has little impact on the business, but needs development attention  ;

  • info: information log, which records the key information of troubleshooting problems, such as call time, input and output parameters, etc;

  • Debug: the runtime data in the key logic used to develop debug;

  • trace: the most detailed information. Generally, this information is only recorded in the log file.

Recommend your own actual Spring Cloud project:

https://github.com/YunaiV/onemall

2. The log shall print the input and output parameters of the method

We don't need to print many logs, we just need to print effective logs that can quickly locate problems  . An effective log is a sharp tool for throwing the pot!

What are the most effective keys   What about your log? For example, when the method comes in, print in the parameters  . Then, when the method returns, it prints out the parameter and return value  . Generally, the key parameters are userId or bizSeq   Information. Positive examples are as follows:

public String testLogMethod(Document doc, Mode mode){
   log.debug("method enter param: {}",userId);
   String id = "666";
   log.debug("method exit param: {}",id);
   return id;
}

3. Select the appropriate log format

The ideal log format should include the most basic information, such as the current timestamp   (general millisecond accuracy), log level  , Thread name   wait. The logback log can be configured as follows:

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} %-5level [%thread][%logger{0}] %m%n</pattern>
    </encoder>
</appender> 

If our log format doesn't even record the current time, we don't even know the requested time point  ?

4. In case of if...else... And other conditions, try to print the log on the first line of each branch

When you meet if...else... Or switch   Under such conditions, the log can be printed on the first line of the branch, so that when troubleshooting problems, you can determine which branch you enter through the log, which makes the code logic clearer and easier to troubleshoot problems.

Positive example:

if(user.isVip()){
  log.info("The user is a member,Id:{},Start processing member logic",user,getUserId());
  //Membership logic
}else{
  log.info("The user is a non member,Id:{},Start processing non member logic",user,getUserId())
  //Non member logic
}

5. When the log level is relatively low, judge the log switch

For low log levels such as trace/debug, you must judge the switch of log level.

Positive example:

User user = new User(666L, "Little boy picking snails");
if (log.isDebugEnabled()) {
    log.debug("userId is: {}", user.getId());
}

Because there are the following log Codes:

logger.debug("Processing trade with id: " + id + " and symbol: " + symbol);

If the configured log level is warn   If yes, the above log will not be printed, but string splicing will be performed. If symbol is an object, toString() method will be executed, which wastes system resources. After the above operations, the final log will not be printed. Therefore, it is recommended to add log switch for judgment.

6. Instead of directly using the API in the logging system (Log4j, Logback), use the API in the logging framework SLF4J.

SLF4J is a facade mode log framework, which is conducive to the unification of maintenance and log processing methods of various classes, and can easily replace the underlying log framework without modifying the code.

Positive example:

import org.slf4j.Logger; 
import org.slf4j.LoggerFactory;

private static final Logger logger = LoggerFactory.getLogger(TianLuoBoy.class);

7. It is recommended to use parameter placeholder {} instead of + splicing.

Counterexample:

logger.info("Processing trade with id: " + id + " and symbol: " + symbol);

In the above example, using the + operator to splice strings has a certain performance loss  .

Positive examples are as follows:

logger.info("Processing trade with id: {} and symbol : {} ", id, symbol); 

We use braces {} as placeholders in the log, which is more elegant and concise than using the + operator. And, compared with the counterexample  , Using placeholders is only a replacement action, which can effectively improve performance.

8. It is recommended to output logs asynchronously.

  • Logs will eventually be output to files or other output streams, and IO performance will be required. If asynchronous, you can significantly improve IO performance.

  • Unless there are special requirements, it is recommended to output logs asynchronously. Take logback as an example. To configure asynchrony, it's easy to use AsyncAppender

<appender name="FILE_ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="ASYNC"/>
</appender>

9. Do not use e.printStackTrace()

Counterexample:

try{
  //  Business code processing
}catch(Exception e){
  e.printStackTrace();
}

Positive example:

try{
  //  Business code processing
}catch(Exception e){
  log.error("Your program is abnormal",e);
}

reason:

  • e. The stack log printed by printstacktrace() is interleaved with the business code log. It is usually inconvenient to check the exception log.

  • e. The string generated by printstacktrace() statement records stack information. If the information is too long and too much, the memory block where the string constant pool is located has no space, that is, the memory is full, then the user's request is stuck~

10. Do not only print half of the exception log, but output all error messages

Counterexample 1:

try {
    //Business code processing
} catch (Exception e) {
    //  error
    LOG.error('Your program is abnormal');
} 
  • Exceptions e are not printed out, so I don't know what type of exception is found.

Counterexample 2:

try {
    //Business code processing
} catch (Exception e) {
    //  error
    LOG.error('Your program is abnormal', e.getMessage());
} 
  • e.getMessage() does not record detailed stack exception information, but only the basic description of the error, which is not conducive to troubleshooting.

Positive example:

try {
    //Business code processing
} catch (Exception e) {
    //  error
    LOG.error('Your program is abnormal', e);
} 

11. It is forbidden to enable debug in the online environment

It is very important to disable debug ging in the online environment.

Because there are many debug logs in general systems, and debug logs are widely used in various frameworks, opening debug online may fill the disk soon, affecting the normal operation of the business system.

12. Don't throw an exception after recording an exception

Counter examples are as follows:

log.error("IO exception", e);
throw new MyException(e);
  • In this way, the stack information is usually printed twice. This is because where the MyException exception is caught, it will be printed again.

  • Such log records, or throw them out after packaging, do not use them at the same time! Otherwise your log will look confusing.

13. Avoid printing logs repeatedly

Avoid printing logs repeatedly, which will waste disk space. If you already have a line of log that clearly expresses your meaning, avoid redundant printing  , Counter examples are as follows:

if(user.isVip()){
  log.info("The user is a member,Id:{}",user,getUserId());
  //Redundant, which can be merged with the previous logs
  log.info("Start processing member logic,id:{}",user,getUserId());
  //Membership logic
}else{
  //Non member logic
}

If you are using log4j logging framework, be sure to set additivity=false in log4j.xml, because you can avoid printing logs repeatedly

Positive example:

<logger name="com.taobao.dubbo.config" additivity="false" /> 

14. Log file separation

  • We can separate different types of logs, such as access.log or error.log, which can be printed into a file separately.

  • Of course, it can also be printed into different log files according to different business modules, so that it will be more convenient for us to troubleshoot problems and make data statistics.

15. Core function module. It is recommended to print a complete log

  • In our daily development, if the core or logic is complex, it is recommended to add detailed comments and detailed logs.

  • How detailed should the log be? Brain hole. If your core program fails in any step, you can locate it through the log.

Topics: Java Back-end