Log4jのレイアウトをカスタマイズする - 闘うITエンジニアの覚え書き

Log4j > Log4jのレイアウトをカスタマイズする

Log4jのレイアウトをカスタマイズする †

以下、ENDのログに START からの経過時間を付加するサンプルを作成する。

log4j2.xml †

<?xml version="1.0" encoding="UTF-8"?>
<Configuration xmlns="http://logging.apache.org/log4j/2.0/config"
       status="OFF" packages="mylogger.pattern">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{DEFAULT_MICROS} %-5level %c{1}.%M %msg%my_proctime%n"/>
    </Console>
  </Appenders>
  <Loggers>
    <Root level="trace">
      <AppenderRef ref="Console"/>
    </Root>
  </Loggers>
</Configuration>

LogEventPatternConverter †

mylogger/pattern/ProcTimePatternConverter.java

package mylogger.pattern;

import java.util.concurrent.ConcurrentHashMap;

import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.pattern.ConverterKeys;
import org.apache.logging.log4j.core.pattern.LogEventPatternConverter;
import org.apache.logging.log4j.message.Message;;

@Plugin(name="ProcTimePatternConverter", category = "Converter")
@ConverterKeys({"my_proctime"})
public class ProcTimePatternConverter extends LogEventPatternConverter{

    private static ConcurrentHashMap<String, Long> startTimeCache = new ConcurrentHashMap<String, Long>();

    protected ProcTimePatternConverter(String name, String style) {
        super(name, style);
    }

    public static ProcTimePatternConverter newInstance(String[] options) {
        return new ProcTimePatternConverter("my_proctime",Thread.currentThread().getName());
    }

    @Override
    public void format(LogEvent event, StringBuilder toAppendTo) {
        String processtime = "";
        Message message = event.getMessage();
        String formatedMessage = message.getFormattedMessage();
        String dataType = getDataType(formatedMessage);
        if (!"START".equals(dataType) && !"END".equals(dataType)) {
            return;
        }

        StackTraceElement stackTraceElement = event.getSource();
        String className  = stackTraceElement.getClassName();
        String methodName = stackTraceElement.getMethodName();

        String key = className + "#" + methodName;

        if ("START".equals(dataType)) {
            startTimeCache.put(key, event.getTimeMillis());
        } else if ("END".equals(dataType)) {
            Long stime = startTimeCache.remove(key);
            if (stime != null) {
                processtime = " (" + (event.getTimeMillis() - stime) + "ms)";
                toAppendTo.append(processtime);
            }
        }
    }

    private String getDataType(String str){
        String[] strs = str.split(" ");
        return strs[0];
    }
}

サンプル処理 †

package service;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.LoggerConfig;

public class Sample1Service {

    static final Logger logger = LogManager.getLogger(Sample1Service.class);

    public static void main(String[] args) {

        logger.info("START");

        logger.info("info log!!!");
        logger.debug("debug log!!!");
        logger.warn("warn log!!!");
        logger.error("error log!!!");
        logger.fatal("fatal log!!!");

        logger.info("END");
    }

}

実行結果 †

2018-06-11 22:02:18,526000 INFO  Sample1Service.main START
2018-06-11 22:02:18,530000 INFO  Sample1Service.main info log!!!
2018-06-11 22:02:18,530000 DEBUG Sample1Service.main debug log!!!
2018-06-11 22:02:18,530000 WARN  Sample1Service.main warn log!!!
2018-06-11 22:02:18,531000 ERROR Sample1Service.main error log!!!
2018-06-11 22:02:18,531000 FATAL Sample1Service.main fatal log!!!
2018-06-11 22:02:18,531000 INFO  Sample1Service.main END (5ms)