跳至主要内容

SLF4J Introduction(2): Output

SLF4J Introduction(2): Output

In this blog, we focus on how SLF4J and related logging system handle the output of logging.

Layout

Layout, which is maybe called pattern, is responsible to transform an log event into string with some format.

The format of the log event is somewhat like printf method. There are many conversion characters to represent things like class name, date, thread, file name, stack trace, message, caller data etc.

Log4j

In log4j, the default conversion pattern is

%r [%t] %p %c %x - %m%n

  • %: the prefix of conversion character. If we want to print a single % sign, we can use %%
  • r: the number of milliseconds elapsed from the construction of the layout until the creation of the logging event.
  • t: name of thread
  • p: logging priority
  • c: the category of the logging event
  • x: NDC (nested diagnostic context)
  • m: the application supplied message associated with the logging event
  • n: the platform dependent line separator character or characters.

More formatting char can be found here.

Logback

Logback has much similar conversion char/word and format modifiers as log4j, but more powerful and easy to use.

  • Except the conversion char, it has more explicit conversion word, which is more easy to understand: e.g. M/method for output method name;
  • xEx: print the stack trace with class packaging information, which is very useful in solving version conflict problem;

What should be noticed is packaging data is disabled by default in 1.14 version and later because calculate the packaging info is very expensive. It can be enabled by:

<configuration packagingData="true">
  ...
</configuration>

or via Java code:

LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
lc.setPackagingDataEnabled(true);

More formatting can be found from logback doc.

Encoder

In logback (a native implementation of SF4J), it introduced another component called encoders, which is responsible for transforming an event into byte array as well as writing out that byte array. It controlls what format of bytes written is, and when bytes are written.

MDC

MDC, the abbreviation of Mapped Diagnostic Context, is designed to deal with complex distributed applications. In a Java distributed system, multiple clients may be served by multiple thread at the same, their log message can be mixed and hard to debug in face of problem and exception.

A naive solution can be init a new logger for different thread and client, which can bring a lot of overhead of logger creation and discouraged.

MDC mark every given client with some unique stamp. This stamp is put by user and can any context information that distinguish the request.

A sample usage can be like following:

MDC.put("username", "Nixon");
logger.info("I am not a crook.");

and appender config:

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> 
  <layout>
    <Pattern>%X{username} - %m%n</Pattern>
  </layout> 
</appender>

then, we have following output:

Nixon - I am not a crook.

To make sure the information contained in the MDC to be correct at all times when a request is processed, a possible approach would be to store the username at the beginning of the process, and remove it at the end of said process. A servlet Filter or AOP comes in handy in this case.

Mis

Logging Performance

logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));

incurs the cost of constructing the message parameter, that is converting both integer i and entry[i] to a String, and concatenating intermediate strings

if(logger.isDebugEnabled()) {
  logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}

This way you will not incur the cost of parameter construction if debugging is disabled for logger. On the other hand, if the logger is enabled for the DEBUG level, you will incur the cost of evaluating whether the logger is enabled or not, twice: once in debugEnabled and once in debug.

Object entry = new SomeObject();
logger.debug("The entry is {}.", entry);

After evaluating whether to log or not, and only if the decision is affirmative, will the logger implementation format the message and replace the ‘{}’ pair with the string value of entry.

Ref

Written with StackEdit.

标签：

评论

发表评论

此博客中的热门博文

Spring Boot: Customize Environment

Spring Boot: Customize Environment Environment variable is a very commonly used feature in daily programming: used in init script used in startup configuration used by logging etc In Spring Boot, all environment variables are a part of properties in Spring context and managed by Environment abstraction. Because Spring Boot can handle the parse of configuration files, when we want to implement a project which uses yml file as a separate config file, we choose the Spring Boot. The following is the problems we met when we implementing the parse of yml file and it is recorded for future reader. Bind to Class Property values can be injected directly into your beans using the @Value annotation, accessed via Spring’s Environment abstraction or bound to structured objects via @ConfigurationProperties. As the document says, there exists three ways to access properties in *.properties or *.yml : @Value : access single value Environment : can access multi
5 条评论
阅读全文

Elasticsearch: Join and SubQuery

Elasticsearch: Join and SubQuery Tony was bothered by the recent change of search engine requirement: they want the functionality of SQL-like join in Elasticsearch! “They are crazy! How can they think like that. Didn’t they understand that Elasticsearch is kind-of NoSQL 1 in which every index should be independent and self-contained? In this way, every index can work independently and scale as they like without considering other indexes, so the performance can boost. Following this design principle, Elasticsearch has little related supports.” Tony thought, after listening their requirements. Leader notice tony’s unwillingness and said, “Maybe it is hard to do, but the requirement is reasonable. We need to search person by his friends, didn’t we? What’s more, the harder to implement, the more you can learn from it, right?” Tony thought leader’s word does make sense so he set out to do the related implementations Application-Side Join “The first implementation
发表评论
阅读全文

Implement isdigit

It is seems very easy to implement c library function isdigit , but for a library code, performance is very important. So we will try to implement it and make it faster. Function So, first we make it right. int isdigit ( char c) { return c >= '0' && c <= '9' ; } Improvements One – Macro When it comes to performance for c code, macro can always be tried. #define isdigit (c) c >= '0' && c <= '9' Two – Table Upper version use two comparison and one logical operation, but we can do better with more space: # define isdigit(c) table[c] This works and faster, but somewhat wasteful. We need only one bit to represent true or false, but we use a int. So what to do? There are many similar functions like isalpha(), isupper ... in c header file, so we can combine them into one int and get result by table[c]&SOME_BIT , which is what source do. Source code of ctype.h : # define _ISbit(bit) (1 << (
发表评论
阅读全文