Java programmer's cultivation path: Logging (2/3)-How to Write logs

Java programmer's cultivation path: Logging (2/3)-How to Write logs
1. A basic example of using the Logging framework to write logs is basically three steps.
Introduce the loggerg class and logger factory class declaration logger record logs

The following is an example.

// 1. introduce the Logger and LoggerFactoryimport org of the slf4j interface. slf4j. logger; import org. slf4j. loggerFactory; public class UserService {// 2. declare a Logger. This is a static method. Private final static Logger logger = LoggerFactory. getLogger (UserService. class); public boolean verifyLoginInfo (String userName, String password) {// 3. log it, the output log information will be: "Start to verify User [Justfly] logger.info (" Start to verify User [{}] ", userName); return false ;}}

In the second step, there is some discussion about whether the Logger object should be declared as static. The author of Logback first recommends using object variables for declaration, later, he changed his mind. Would like to learn more can look at the students: http://slf4j.org/faq.html#declared_static

The advantages and disadvantages of the two methods are as follows:
Static Logger objects are more semantic-compliant, saving CPU and memory, and cannot be injected with the object variable Logger, for multiple applications running in one JVM that reference the same class library, you can configure Logger of the same class in different applications. For example, two applications are deployed on Tomcat, both of which reference the same lib. 2. Logger interface method the Logger interface is divided into two versions, one with the Marker version and the other without the Marker version. I will not introduce the version with Marker. Interface methods without the Marker version can be divided into the following two groups:
2.1 public boolean isTraceEnabled (); public boolean isDebugEnabled (); public boolean isInfoEnabled (); public boolean isWarnEnabled (); public boolean isErrorEnabled ();

This method is mainly used to prevent unnecessary log information objects, especially for Log frameworks (Log4j 1, commons-logging) that do not support parameterized information ). As shown in the following example, if the debug level is not added, the code in the second line does not need to generate multiple String objects in the environment (production environment) where the Debug level is disabled.

if(logger.isDebugEnabled()){  logger.debug("["+resultCount+"]/["+totalCount+"] of users are returned");}

If the parameter information method is used, even if the debug level (the first line) is not added to the judgment in the following code, the second line of code will generate only one String object in the production environment.

if(logger.isDebugEnabled()){  logger.debug("[{}]/[{}] of users in group are returned", resultCount,totalCount);}

Therefore, for the sake of code readability, I usually use parameterized information methods without determining whether to enable Logger-level information. In other words, I usually do not use this set of methods.
2.2 Method 2.2.1 of log information the Logger has five levels: track, debug, info, warn, and error. For each level, there are five log methods, taking the info level as an example:
Public void info (String msg );

The log method without parameters, for example:

Logger.info ("START initializing the configuration file read module ");

Output

23:36:17, 783 [main] INFO c. j. training. logging. service. UserService-start initializing the configuration file read Module

Public void info (String format, Object arg );

Supports a parameter parametric log method, for example:

Logger.info ("start to import the configuration file [{}]", "/somePath/config. properties ");

Output

23:36:17, 787 [main] INFO c. j. training. logging. service. UserService-start to import the configuration file [/somePath/config. properties]

Public void info (String format, Object arg1, Object arg2 );

The parameterized log method of the two parameters is supported, for example:

Logger.info ("starting to read the value of configuration item [{}] From the configuration file [{}]", "/somePath/config. properties", "maxSize ");

Output

23:36:17, 789 [main] INFO c. j. training. logging. service. UserService-start to read the value of the configuration item [maxSize] From the configuration file [/somePath/config. properties]

Public void info (String format, Object... arguments );

The parameterized log method supports multiple parameters. Compared with the preceding two methods, the overhead of constructing an Object [] is increased. Example:

Logger.info ("the value of the configuration item [{}] Read in the configuration file [{}] is [{}]", "/somePath/config. properties "," maxSize ", 5 );

Output

2014-08-11 23:36:17, 789 [main] INFO c. j. training. logging. service. userService-in the configuration file [/somePath/config. the value of the configuration item [maxSize] Read in properties] is [5].

Public void info (String msg, Throwable t );

No parameterized log exception information

Logger.info ("exception occurred when reading the configuration File", new FileNotFoundException ("File not exists "));

Output

2014-08-11 23:36:17, 794 [main] INFO c. j. training. logging. service. userService-exception occurs when reading the configuration file java. io. fileNotFoundException: File not exists at cn. justfly. training. logging. service. userServiceTest. testLogResult (UserServiceTest. java: 31 )~ [Test-classes/: na] at sun. reflect. NativeMethodAccessorImpl. invoke0 (Native Method )~ [Na: 1.6.0 _ 45] at sun. reflect. NativeMethodAccessorImpl. invoke (NativeMethodAccessorImpl. java: 39 )~ [Na: 1.6.0 _ 45] at sun. reflect. DelegatingMethodAccessorImpl. invoke (DelegatingMethodAccessorImpl. java: 25 )~ [Na: 1.6.0 _ 45] at java. lang. reflect. Method. invoke (Method. java: 597 )~ [Na: 1.6.0 _ 45]

Parameter description
In the above example, we can see that the {} in the log information will be replaced by the following parameters in order. This brings about a benefit: if you do not need to print the Log at runtime, the String object will not be repeatedly generated.
2.2.2 how to Log Exception2.2.2.1 use Exception as the last parameter of the Log Method

If the last parameter in the parameterized Log method described above is an Exception-type object, logback prints the StackTrace information of the Exception. Let's look at the example below:

An error occurred while reading the configuration file. ","/SomePath/config. properties ", new FileNotFoundException (" File not exists "));

The above code will output the following content during execution:

00:22:49, 167 [main] INFO c. j. training. logging. service. UserService-An error occurred while reading the configuration file [/somePath/config. properties. Java. io. fileNotFoundException: File not exists at cn. justfly. training. logging. service. userServiceTest. testLogResult (UserServiceTest. java: 30) [test-classes/: na] at sun. reflect. nativeMethodAccessorImpl. invoke0 (Native Method )~ [Na: 1.6.0 _ 45] at sun. reflect. NativeMethodAccessorImpl. invoke (NativeMethodAccessorImpl. java: 39 )~ [Na: 1.6.0 _ 45] at sun. reflect. DelegatingMethodAccessorImpl. invoke (DelegatingMethodAccessorImpl. java: 25 )~ [Na: 1.6.0 _ 45] at java. lang. reflect. Method. invoke (Method. java: 597 )~ [Na: 1.6.0 _ 45] at org. junit. runners. model. frameworkMethod $1. runReflectiveCall (FrameworkMethod. java: 47) [junit. jar: na] at org. junit. internal. runners. model. reflectiveCallable. run (ReflectiveCallable. java: 12) [junit. jar: na] at org. junit. runners. model. frameworkMethod. invokeExplosively (FrameworkMethod. java: 44) [junit. jar: na] at org. junit. internal. runners. statements. invokeMethod. evaluate (InvokeMethod. java: 17) [junit. jar: na] at org. junit. runners. parentRunner. runLeaf (ParentRunner. java: 271) [junit. jar: na]

2.2.2.2 Exception does not replace the parameters in log information

In addition, this Exception will not be replaced by parameters in the parameterized content. For example, the following code:

An error occurred while reading the configuration file. Exception: [{}] ","/somePath/config. properties ", new FileNotFoundException (" File not exists "));

The execution result is as follows. The second parameter is not replaced.

00:25:37, 994 [main] INFO c. j. training. logging. service. UserService-An error occurred while reading the configuration file [/somePath/config. properties. Exception: [{}] java. io. fileNotFoundException: File not exists at cn. justfly. training. logging. service. userServiceTest. testLogResult (UserServiceTest. java: 30) [test-classes/: na] at sun. reflect. nativeMethodAccessorImpl. invoke0 (Native Method )~ [Na: 1.6.0 _ 45] at sun. reflect. NativeMethodAccessorImpl. invoke (NativeMethodAccessorImpl. java: 39 )~ [Na: 1.6.0 _ 45] at sun. reflect. DelegatingMethodAccessorImpl. invoke (DelegatingMethodAccessorImpl. java: 25 )~ [Na: 1.6.0 _ 45] at java. lang. reflect. Method. invoke (Method. java: 597 )~ [Na: 1.6.0 _ 45]

2.2.2.3 parameterized Exception if you just don't want to print StackTrace, you just want to parameterize it. How can this problem be solved? Generally, this is not recommended because you have eaten the useful items in the Exception. But if you have to do this, it's not impossible. There are two methods:
Use the return value of the toString () method of Exception as the parameter.

The example is as follows. Note that we do not need to use ex. getMessage () uses the toString () method, because not every Message instance has a Message, but the default toString () method contains a Message:

An error occurred while reading the configuration file. Exception: [{}] ","/somePath/config. properties ", new FileNotFoundException (" File not exists "). toString ());

The execution result is:

00:29:24, 018 [main] INFO c. j. training. logging. service. UserService-An error occurred while reading the configuration file [/somePath/config. properties. Exception: [java. io. FileNotFoundException: File not exists]

Do not make Exception the last parameter.

Example:

Logger.info ("An error occurred while reading the parameter [{}]: [{}]. Please check your configuration file [{}]", "maxSize ", new FileNotFoundException ("File not exists"), "/somePath/config. properties ");

The execution result is:

2014-08-12 00:35:11, 125 [main] INFO c. j. training. logging. service. userService-error when reading the [maxSize] parameter: [java. io. fileNotFoundException: File not exists]. Check your configuration File [/somePath/config. properties]

3. What is Log? I talked about how to use the Loggger method log. Next I will continue to talk about what level of log should be recorded and what needs to be recorded.
3.1 How to use different levels of LogSLF4J to divide logs into five levels: Error, Warn, Info, Debug, and Trace. We can divide the two levels into two groups.
3.1.1 logs of user-level Error, Warn, and Info may appear in the production environment. They must be readable by O & M personnel.
3.1.1.1 errors affect the normal operation of the program and the normal operation of the current request. For example, if a third-party application network connection exception occurs when opening the configuration file, SQLException should not occur. For example: when an element in the List returned by a Service method is missing, an empty List is obtained for character conversion. An error is reported: No GBK character set 3.1.1.2 Warn should not appear, but it does not affect the program. The current request is normal. running exception, for example, if a configuration file cannot be found due to an error in the fault tolerance mechanism, but the system can automatically create a configuration file that is close to the critical value, for example: cache pool usage reaches warning line 3.1.1.3 Info system operation information Service method in the main logic of the sub-step external interface part of the client request parameters and the results returned to the client call third-party call parameters and call results
3.1.2 The development-level Debug and Trace levels are mainly used during development or when the developer is involved in debugging after system problems occur. They need to provide detailed information.
3.1.2.1 Debug is used to record program variables. For example, variables in multiple iterations are used to replace comments in the code.

If you are used to writing in code implementation:

// 1. Get the basic salary of the user... // 2. Get the user's vacation status... // 3. Calculate the salary that the user deserves...

Try writing it like this.

Logger. debug ("start to get employee [{}] [{}] annual basic salary", employee, year );... logger. debug ("Get the basic salary of employee [{}] [{}] for [{}]", employee, year, basicSalary); logger. debug ("start to get the employee's [{}] [{}] annual [{}] monthly vacation situation", employee, year, month );... logger. debug ("Employee [{}] [{}] annual leave/sick leave [{}]/[{}]/[{}]/[{}]", employee, year, month, annualLeaveDays, sickLeaveDays, noPayLeaveDays); logger. debug ("start to calculate the employee's salary for [{}] [{}] [{}] months", employee, year, month );... logger. debug ("the employee's [{}] [{}] year [{}] monthly salary is [{}]", employee, year, month, actualSalary );

3.1.2.2 Trace is mainly used to record the complete information during system operation, such as the complete HTTP Request and Http Response
3.2 key points in Log 3.2.1 The Log context must bring context information into Log as much as possible. Compared with the following two Log information, the latter is more effective than the former.
"Start to import the configuration file" "start to import the configuration file [/etc/myService/config. properties] "3.2.2 for user-level logs, the readers of Log may be other developers using your framework, maintenance personnel, or common users. You need to organize Log information in a language that they can understand as much as possible. It is better if your Log can provide useful help for their use.
In the following two logs, the former is of little help to non-code maintenance personnel, and the latter is easier to understand.
"Start to execute the getUserInfo method, user name [jimmy]" "start to get user information, user name [jimmy]" The Log below provides great help for framework users
"Parameter [12 03,201 3] cannot be parsed, the birthDay parameter must comply with the format [yyyy-MM-dd] "3.2.3 the variables in Log should be separated from common text [].
When you read the Log, it is easy to capture useful information. When you use a tool to analyze the Log, it is easier to capture and compare the following two logs in some cases, obfuscation of the former:
"Get user lj mail record count in September" "Get user [lj1] [2] monthly mail record count" 3.2.4 Error or Exception encountered in Warn level try to log complete Exception information the Error and Warn levels are serious, this means that the system is faulty or dangerous. We need more information to help analyze the cause. At this time, more information is helpful. The best practice at this time is to Log all the following content:
When you are doing something wrong, when you are doing this thing, when you are using what data to do this thing wrong information is compared with the following three Log statements, the first provides detailed information, the second only provides partial information, the Exception Message does not necessarily contain useful information, and the third only tells you that an error has occurred, and you do not know anything about others.
Log. error ("An error occurred while obtaining user information for user [{}]", userName, ex); log. error ("an error is returned when retrieving user information [{}]. error message: [{}]", userName, ex. getMessage (); log. error ("an error occurred when retrieving user information"); 3.2.5 do I need to Log StackTrace every time for Exception?

In some Exception processing mechanisms, each layer or Service corresponds to a RuntimeException class and throws them to the Exception Processing Layer at the outermost layer. The typical code is as follows:

try{...}catch(Exception ex){  String errorMessage=String.format("Error while reading information of user [%s]",userName);  logger.error(errorMessage,ex);  throw new UserServiceException(errorMessage,ex);}

At this point, the problem arises. The exception StackTrace is logged in the bottom-layer error. when you throw the outer-layer exception, in the exception handling layer of the outermost layer, the stack trace of an exception will be logged again, so that there will be large duplicate information in your Log.
This is generally the case I encountered: Log! The reasons are as follows:
This information is very important. I am not sure whether its StackTrace will be printed normally in the exception handling layer. If this exception information is encapsulated multiple times during the upstream transfer process, the underlying real error cause may not be printed when StackTrace is printed on the outermost layer. If someone changes the configuration of LogbackException printing, this information may be lost when it cannot be completely printed. What if I repeat it? If all errors occur, will Warning save a little space?