Java Programmer's Path to Logging (2/3)-How to write log

1. One of the most basic examples of using the logging framework to write a log is basically three steps

1. Introduction of Loggerg Class and Logger factory class
2. Statement Logger
3. Record log

Let's look at an example

1. Introduction of the SLF4J interface Logger and Loggerfactoryimport Org.slf4j.logger;import Org.slf4j.loggerfactory;public class UserService {  //2. Declare a logger, this is the way of static, I am more accustomed to this writing.  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 [Just Fly]    logger.info ("Start to verify User [{}]", userName);    return false;  }}

In the second step, there has been some discussion about whether the logger object is to be declared static, and the author of the Logback first recommended the use of object variables, and later he changed his mind. To learn more about the students can go to see: http://slf4j.org/faq.html#declared_static

The pros and cons of both approaches are summarized below:

• Static logger objects are relatively semantically compatible, save CPU, save memory, and do not support injection
• The object variable logger supports injection, and for multiple applications running in a JVM that reference the same class library, the logger of the same class can be configured differently in different applications. For example, there are two applications deployed on Tomcat, and they all cite the same lib.

2. The Logger interface method logger interface is divided into two versions, one with marker version and one without marker version. I didn't use the marker version of the article. The interface method without the marker version can be divided into the following two groups:
2.1 How to determine if the logger level is open

• public boolean istraceenabled ();
• public boolean isdebugenabled ();
• public boolean isinfoenabled ();
• public boolean iswarnenabled ();
• public boolean iserrorenabled ();

The main purpose of this set of methods is to avoid the creation of unnecessary log information objects, especially for log frames (log4j 1, commons-logging) that do not support parameterized information. As the following example shows, if the debug level is not determined, the second line of code in the Environment (production environment) that is disabled at the debug level will not produce multiple string objects as necessary.

if (logger.isdebugenabled ()) {  logger.debug ("[" +resultcount+ "]/[" +totalcount+ "] of the users are returned");}

If you use the method of parameter information, in the following code, even if you do not add the debug level (the first row), in the production environment, the second line of code will only produce a string object.

if (logger.isdebugenabled ()) {  Logger.debug ("[{}]/[{}] of users in group is returned", Resultcount,totalcount);}

Therefore, for the readability of the code, I generally use the method of parameterized information, and do not do logger level whether to open the judgment, in other words, this group of methods I generally do not use.
2.2 Log Information Method 2.2.1 Method Description There are five levels in logger: Track,debug,info,warn,error. For each level, there are five log methods, with the info level as an example:

• public void info (String msg);

Parameter-free log method, example:

Logger.info ("Start initialization of profile reading module");

Output

2014-08-11 23:36:17,783 [main] INFO C.j.training.logging.service.userservice-Start initialization of profile reading module

• public void info (String format, Object Arg);

A parameterized log method that supports a parameter, for example:

Logger.info ("Start importing configuration file [{}]", "/somepath/config.properties");

Output

2014-08-11 23:36:17,787 [main] INFO c.j.training.logging.service.userservice-Start import configuration file [/somepath/config.properties]

• public void info (String format, Object arg1, Object arg2);

A parameterized log method that supports both parameters, for example:

Logger.info ("Start reading the value of the configuration item [{}] from the configuration file [{}]", "/somepath/config.properties", "maxSize");

Output

2014-08-11 23:36:17,789 [main] INFO C.j.training.logging.service.userservice-Start from configuration file [/somepath/config.properties] Read the value of the configuration entry [MaxSize] in the

• public void info (String format, Object ... arguments);

A parameterized log method that supports multiple parameters, comparing the two methods above, increases the overhead of constructing a object[]. Example:

Logger.info ("read in configuration file [{}] The value of the configuration entry [{}] is [{}]", "/somepath/config.properties", "MaxSize", 5);

Output

2014-08-11 23:36:17,789 [main] INFO c.j.training.logging.service.userservice-in config file [/somepath/config.properties] The value read to the configuration entry [MaxSize] is [5]

• public void info (String msg, Throwable t);

No parameterized Log exception information

Logger.info ("Exception occurred while reading configuration file", New FileNotFoundException ("File Not Exists"));

Output

2014-08-11 23:36:17,794 [main] INFO C.j.training.logging.service.userservice- An exception occurred while 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]

Parametric Description
In the example above, we can see that {} In the log information will be replaced by the following parameters in order. This brings a benefit: if you do not need to print the log at run time, the string object will not be produced repeatedly.
2.2.2 How log Exception2.2.2.1 takes exception as the last parameter of the log method

The last parameter in the parameterized log method above if it is an object of type exception, Logback will print the StackTrace information for that exception. Take a look at the following example:

Logger.info ("Error reading configuration file [{}]." ","/somepath/config.properties ", New FileNotFoundException (" File Not Exists "));

The above code, when executed, will output the following:

2014-08-12 00:22:49,167 [main] INFO c.j.training.logging.service.userservice-read configuration file [/somepath/config.properties] Error occurs. 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 parameters in the log message

It is also important to note that the exception is not replaced as a parameter in the parameterized content. For example, the following code:

Logger.info ("Error reading configuration file [{}]." Exception is [{}] ","/somepath/config.properties ", New FileNotFoundException (" File Not Exists "));

Its execution results are as follows, and the second parameter is not replaced

2014-08-12 00:25:37,994 [main] INFO c.j.training.logging.service.userservice-read configuration file [/somepath/config.properties] Error occurs. Exception for [{}]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 Parametric exception if you just don't want to print stacktrace, how do you get to parameterize it? In general, this is not recommended because you have eaten something useful in the exception. But if you have to do this, it's not an option, there are two ways:

• Take the return value of the ToString () method of the exception as a parameter

The example below shows that we do not use the ToString () method instead of Ex.getmessage (), because not every message instance has a message, but the default ToString () method includes a message:

Logger.info ("Error reading configuration file [{}]." The exception is [{}], "/somepath/config.properties", and New FileNotFoundException ("File NOT Exists"). ToString ());

The result of the execution is:

2014-08-12 00:29:24,018 [main] INFO c.j.training.logging.service.userservice-read configuration file [/somepath/config.properties] Error occurs. exception is [Java.io.FileNotFoundException:File NOT EXISTS]

• Don't let exception be the last parameter

Examples are as follows:

Logger.info ("read parameter [{}]" error: [{}], please check your profile [{}] "," maxSize ", New FileNotFoundException (" File Not Exists "),"/somepath/ Config.properties ");

The result of the execution is:

2014-08-12 00:35:11,125 [main] INFO C.j.training.logging.service.userservice-Error reading parameter [maxSize]: [ Java.io.FileNotFoundException:File NOT EXISTS], please check your configuration file [/somepath/config.properties]

3. Log what was said earlier about how to use the Loggger method log log, continue to talk about where to log what level of log, and what needs to be recorded.
3.1 How to use different levels of logslf4j to divide a log into error,warn,info,debug and trace five levels. We can divide these two levels into groups.
3.1.1 User level error, warn, and info these three levels of log will appear in the production environment and they must be read and understood by operations personnel
3.1.1.1 Error

• An exception that affects the normal operation of the program and the normal operation of the current request, such as:
  • Failed to open configuration file
  • Third-party Application network connection exception
  • SQLException
• Situations that should not occur, such as:
  • A service method returns a list in which there should be an element when missing an empty list
  • Do the character conversion when actually error said no GBK character set

3.1.1.2 Warn

• Exceptions that should not occur but do not affect the program, the current request is working correctly, for example:
  • Error conditions that occur when there is a fault tolerance mechanism
  • The configuration file could not be found, but the system can create the configuration file automatically
• Approaching the threshold, for example:
  • Cache pool occupancy reaches warning line

3.1.1.3 Info

• System Operation Information
  • Entry and exit of service method
  • Sub-steps in the main logic
• External interface Section
  • Client request parameters and results returned to the client
  • Call parameters and call results when a third party is called

3.1.2 Development level Debug and trace these two levels are primarily used during development or when the developer is involved in debugging after a system problem, and need to help provide detailed information.
3.1.2.1 Debug

• Used to log program variables, for example:
  • Variables in multiple iterations
• Used in place of comments in code

If you are accustomed to writing in code implementations:

1. Get user base pay ...//2. Get user leave ...//3. Calculate the user's due salary ...

Try this.

Logger.debug ("Start getting employee [{}] [{}] Year base salary", employee,year), ... logger.debug ("Get employee [{}] [{}] Year base salary is [{}]", Employee,year, Basicsalary); Logger.debug ("Starting to get employee [{}] [{}] [{}] month leave", Employee,year,month), ... logger.debug ("Employee [{}][{}] year [{}] month annual leave/ Sick leave/leave for [{}]/[{}]/[{}] ", employee,year,month,annualleavedays,sickleavedays,nopayleavedays); Logger.debug (" Start calculating employees [{ }][{}] year [{}] month due salary, employee,year,month), ... logger.debug ("Employee [{}] [{}] year [{}] month due salary is [{}]", Employee,year,month, Actualsalary);

3.1.2.2 Trace is primarily used to record complete information in the operation of the system, such as the full HTTP request and HTTP Response
3.2 Log in 3.2.1 The log context must try to bring in the context information in the log, comparing the following two log messages, which is more useful than the former

• "Start Importing configuration Files"
• "Start importing configuration files [/etc/myservice/config.properties]"

3.2.2 Consider log readers for the user-level log, whose readers may be other developers who use your framework, perhaps ops, and possibly ordinary users. You need to organize the log information in a language that they can understand, even better if your log is helpful for their use.
Of the two logs below, the former does little to help non-code maintainers, which is easier to understand.

• "Start execution of the GetUserInfo method, username [Jimmy]"
• "Start getting user information, user name [Jimmy]"

The following log provides a great help to the user of the framework

• "Argument cannot be resolved [2013],birthday] parameter needs to conform to format [YYYY-MM-DD]"

The variables in the 3.2.3 log are separated from the normal text by the use of [] separating the variables from the normal text.

• It's easy to capture useful information when you're reading log.
• Easier to crawl when using tools to analyze log
• In some cases it is not easy to confuse

In contrast to the following two logs, the former has been confused:

• "Get user LJ12 months sent message records"
• "Gets the number of messages sent by the user [lj1][2] month"

3.2.4 error or warn level encountered exception the situation as far as possible log complete exception information error and warn level is more serious situation, means that the system error or danger, we need more information to help analyze the reason, this time the more information more helpful. The best thing to do at this time is to log all of the following:

• You did something wrong when you were doing something.
• What data do you use to make a mistake when doing this thing?
• What is the error message?

Compare the following three log statements, the first one provides detailed information, the second one provides only partial information, the exception message does not necessarily contain useful information, the third only tells you the error, the others you know nothing about.

• Log.error ("Error obtaining user information for user [{}]", Username,ex);
• Log.error ("Get user information for users [{}] times wrong, error message: [{}]", Username,ex.getmessage ());
• Log.error ("Error getting user information");

3.2.5 for exception, should log stacktrace every time?

In some exception processing mechanisms, we will have each layer or service corresponding to a runtimeexception class, and throw them out, left to the outermost exception processing layer processing. 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);}

This time the problem, at the bottom of the error log the abnormal StackTrace, in the process of throwing this anomaly outside the upper layer, at the outermost level of exception processing, you will also log an abnormal stacktrace, this way your log will have a large piece of duplicate information.
This is how I deal with this: Log! Here are some of the reasons for this:

• This information is important and I am not sure if the StackTrace will print properly in the exception handling layer.
• If this exception message is packed more than once in the process, it is possible that the bottom-most real-useful error causes will not be printed when the outermost print stacktrace.
• If someone changes the configuration of the logbackexception print so that it cannot be fully printed, this information may be lost.
• What if it repeats? It's all warning, and it saves a little space?