Registration in Java and in general: best practices?

Question

Sometimes, when I see my registration code, I wonder if I am doing this correctly. There may not be a definitive answer to this, but I have the following problems:

Library classes

I have several library classes that can log some INFO messages. The exception is fatal errors. I currently have a static log instance in my classes with the class name as the log name. (Log4j's: Logger.getLogger(MyClass.class) )

Is it correct? Perhaps the user of this class of the library does not want to send any messages from my implementation or wants to redirect them to a specific application log. Should I allow the user to install the registrar from the "outside world"? How do you deal with such cases?

General magazines

In some applications, my classes may want to write a log message to a specific log that is not identified by the class name. (Ie: HTTP Request log ) What is the best way to do such a thing? A search service comes to mind ...

Answer 1

Your conventions are pretty standard and pretty good (imho).

The only thing to look at is memory fragmentation from excessive pending debugging calls, so with Log4J (and most other Java frameworks) you get something like this:

 if (log.isDebugEnabled()) { log.debug("..."); } 

since building this log message (which you probably aren't using) can be expensive, especially if it is done thousands or millions of times.

The level of registration of the INFO level should not be too "frequent" (and, as you say, it seems that this is not so). INFO messages should be generally meaningful and significant, such as starting and stopping an application. Things you might want to know if you have a problem. Debug / exact level logging is more used when you really have a problem that you are trying to diagnose. Debugging / accurate logging is usually enabled only when necessary. Information is usually kept constant.

If someone does not want to receive special INFO messages from your classes, they, of course, can change your log4j configuration so as not to receive them. Log4j is well versed in this section (as opposed to registering Java 1.4).

As for your HTTP stuff, I usually did not find that this is a problem with Java logging, because usually one class is responsible for what interests you, so you only need to place it in one place. In (in my experience), when you need generic log messages through seemingly unrelated classes, just put some token that can be easily grepped for.

Answer 2

Below are the recommendations that I follow in all my projects to ensure good performance. I came to form this set of guidelines based on materials from various sources on the Internet.

As of today, I believe that Log4j 2 is the best option for entering Java.

Tests are available here . The practice that I follow in order to achieve maximum performance is as follows:

1. I avoid using SLF4J for the moment for the following reasons:
   • It has some concurrency issues with markers that I want to use to control the registration of SQL statements ( markers are not as powerful as slf4j - see Ralph Goers first comment)
   • It does not support Java 8 Lambda, which, again, I want to use to improve performance ( support for lambda expressions in Logger )
2. Do all normal logs using an asynchronous logger for better performance.
3. Log error messages in a separate file using the synchronous logger, because we want to see error messages as soon as they appear
4. Do not use location information such as file name, class name, method name, line number in regular registration, because the platform takes a snapshot of the stack and looks at it to get this information. This affects performance. Therefore, use location information only in the error log, not in the regular log
5. To track individual requests handled by individual threads, consider using a thread context and random UUIDs, as described here
6. Since we record errors in a separate file, it is very important that we also record contextual information in the error log. For example, if the application detected an error while processing the file, type the file name and the file being processed into the error log file along with the stack trace.
7. The log file must be clear and understandable. For example, if an application processes client records in multiple files, each log message should be as shown below:

 12:01:00,127 INFO FILE_NAME=file1.txt - Processing starts 12:01:00,127 DEBUG FILE_NAME=file1.txt, CUSTOMER_ID=756 12:01:00,129 INFO FILE_NAME=file1.txt - Processing ends 

8. Log all SQL statements using the SQL token, as shown below, and use the filter to enable or disable it:

 private static final Marker sqlMarker = MarkerManager.getMarker("SQL"); private void method1() { logger.debug(sqlMarker, "SELECT * FROM EMPLOYEE"); } 

9. Register all parameters using Java 8 Lambdas. This will save the application from formatting the message when this log level is disabled:

 int i=5, j=10; logger.info("Sample output {}, {}", ()->i, ()->j); 

10. Do not use string concatenation. Use a parameterized message as shown above

11. Use dynamic reloading of the logging configuration so that the application automatically reloads changes to the logging configuration without having to restart the application.

12. Do not use printStackTrace() or System.out.println()

13. The application should close the registrar before exiting:

 LogManager.shutdown(); 

14. Finally, for each link, I use the following configuration:

 <?xml version="1.0" encoding="UTF-8"?> <Configuration monitorinterval="300" status="info" strict="true"> <Properties> <Property name="filePath">${env:LOG_ROOT}/SAMPLE</Property> <Property name="filename">${env:LOG_ROOT}/SAMPLE/sample </Property> <property name="logSize">10 MB</property> </Properties> <Appenders> <RollingFile name="RollingFileRegular" fileName="${filename}.log" filePattern="${filePath}/sample-%d{yyyy-dd-MM}-%i.log"> <Filters> <MarkerFilter marker="SQL" onMatch="DENY" onMismatch="NEUTRAL" /> </Filters> <PatternLayout> <Pattern>%d{HH:mm:ss,SSS} %m%n </Pattern> </PatternLayout> <Policies> <TimeBasedTriggeringPolicy interval="1" modulate="true" /> <SizeBasedTriggeringPolicy size="${logSize}" /> </Policies> </RollingFile> <RollingFile name="RollingFileError" fileName="${filename}_error.log" filePattern="${filePath}/sample_error-%d{yyyy-dd-MM}-%i.log" immediateFlush="true"> <PatternLayout> <Pattern>%d{HH:mm:ss,SSS} %p %c{1.}[%L] [%t] %m%n </Pattern> </PatternLayout> <Policies> <TimeBasedTriggeringPolicy interval="1" modulate="true" /> <SizeBasedTriggeringPolicy size="${logSize}" /> </Policies> </RollingFile> </Appenders> <Loggers> <AsyncLogger name="com" level="trace"> <AppenderRef ref="RollingFileRegular"/> </AsyncLogger> <Root includeLocation="true" level="trace"> <AppenderRef ref="RollingFileError" level="error" /> </Root> </Loggers> </Configuration> 

15. The required Maven dependencies are here:

 <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> <version>2.8.1</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.8.1</version> </dependency> <dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>3.3.6</version> </dependency> <!-- (Optional)To be used when working with the applications using Log4j 1.x --> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-1.2-api</artifactId> <version>2.8.1</version> </dependency> 

Answer 3

In @cletus answer , he wrote about the problem

 if (log.isDebugEnabled()) { log.debug("val is " + value); } 

which can be overcome using the SL4J . It provides formatting help.

 log.debug("val is {}", value); 

where the message is created only if the level is being debugged.

So now, using SL4J and its companion registrar, Logback, is recommended for reasons of performance and stability.

Answer 4

Regarding the registrar instances, I had some success using the Java Eclipse template to configure my registrars:

 private static Logger log = Logger.getLogger(${enclosing_type}.class); 

This avoids the problem of removing the JVM with its stack trace and, ultimately, reduces (trivially, possibly) the overhead of creating a stack trace.

The great thing about using such a template is that you can share it with your team if you want to set a consistent standard across all fields for magazines.

IntelliJ seems to support the same concept for a template variable representing the name of the closing type. I do not see a way to do this easily in NetBeans.

Answer 5

The preferred option for the log4j configuration that you describe is to use the log4j configuration file. This allows users of your implementation to do exactly what you are asking for, as they can redefine your configuration later with something more suitable for their own implementation. See here for a very thorough primer.

Answer 6

I probably stole it somewhere, but it's nice.

This reduces the risk of mixing recorders when copying and rearranging pasti ^ h ^ h ^ h, and it is less than type.

In your code:

 private final static Logger logger = LoggerFactory.make(); 

... and in LoggerFactory:

 public static Logger make() { Throwable t = new Throwable(); StackTraceElement directCaller = t.getStackTrace()[1]; return Logger.getLogger(directCaller.getClassName()); } 

(Note that stackdump executes during initialization. Stacktrace will probably not be optimized by the JVM, but there really is no guarantee)

Answer 7

I am looking at the log levels of an application, and currently I am discovering a pattern:

 private static final Logger logger = Logger.getLogger(Things.class) public void bla() { logger.debug("Starting " + ...) // Do stuff ... logger.debug("Situational") // Algorithms for(Thing t : things) { logger.trace(...) } // Breaking happy things if(things.isEmpty){ logger.warn("Things shouldn't be empty!") } // Catching things try { ... } catch(Exception e) { logger.error("Something bad happened") } logger.info("Completed "+...) } 

The log4j2 file defines a socket-appender with a fail-over application file. And the console application. Sometimes I use log4j2 markers when the situation requires it.

Thought an extra perspective could help.

Answer 8

In addition, I find it important to understand the Simple Logging Facade for Java (SLF4J) ( http://www.slf4j.org/ ). Due to some problems using different logging protocols in the most diverse parts of a large project, SLF4J is the de facto standard for solving the problem of successfully managing these parts, isn't it?

Second: it seems that some tasks of the old school can be replaced by Aspect-oriented programming , Spring frmwrk has an implementation , the AOP approach for logging is considered here in StackOverflow and here in the Spring blog.