如何在log4j中打印时间精确到纳秒
排查生产问题时出现了同一毫秒下四条日志,无法分清先后顺序,因此有了需要精确到纳秒的需求。
好在之前对jdk8的LocalTime
有所了解,知道可以取到纳秒,激动输出。
LocalTime.now().getNano();
结果却和所想不太一样,当前时间2021-07-20 18:38:02,929
,输出却是929000000
,后面的六位去哪了。进一步跟踪LocalTime.now()
发现使用到了Clock
类进行创建。
public static LocalTime now(Clock clock) {
Objects.requireNonNull(clock, "clock");
// inline OffsetTime factory to avoid creating object and InstantProvider checks
final Instant now = clock.instant(); // called once
ZoneOffset offset = clock.getZone().getRules().getOffset(now);
long localSecond = now.getEpochSecond() + offset.getTotalSeconds(); // overflow caught later
int secsOfDay = (int) Math.floorMod(localSecond, SECONDS_PER_DAY);
return ofNanoOfDay(secsOfDay * NANOS_PER_SECOND + now.getNano());
}
而在Clock
类的注解上发现,Clock
的精度是不能保证的,不一定能到纳秒。
* @implNote
* The clock implementation provided here is based on {@link System#currentTimeMillis()}.
* That method provides little to no guarantee about the accuracy of the clock.
* Applications requiring a more accurate clock must implement this abstract class
* themselves using a different external clock, such as an NTP server.
因此我们需要自己实现一个NanoClock
。
public class NanoClock extends Clock
{
private final Clock clock;
private final long initialNanos;
private final Instant initialInstant;
public NanoClock()
{
this(Clock.systemUTC());
}
public NanoClock(final Clock clock)
{
this.clock = clock;
initialInstant = clock.instant();
initialNanos = getSystemNanos();
}
@Override
public ZoneId getZone()
{
return clock.getZone();
}
@Override
public Instant instant()
{
return initialInstant.plusNanos(getSystemNanos() - initialNanos);
}
@Override
public Clock withZone(final ZoneId zone)
{
return new NanoClock(clock.withZone(zone));
}
private long getSystemNanos()
{
return System.nanoTime();
}
}
使用自己的Clock就可以精确输出纳秒了。
Clock nanoClock = new NanoClock();
long NANOTIME = LocalTime.now(nanoClock).getNano();
有了纳秒之后,我们想要通过自定义pattern参数进行输出。
首先自定义PatternConverter
@Plugin(name = "NanoPatternConverter", category = PatternConverter.CATEGORY)
@ConverterKeys({ "y" })
public class NanoPatternConverter extends LogEventPatternConverter {
private Clock nanoClock = new NanoClock();
private static final NanoPatternConverter INSTANCE =
new NanoPatternConverter();
public static NanoPatternConverter newInstance(
final String[] options) {
return INSTANCE;
}
private NanoPatternConverter(){
super("NanoPatternConverterName", "NanoPatternConverterStyle");
}
@Override
public void format(LogEvent event, StringBuilder toAppendTo) {
Clock nanoClock = new NanoClock();
long NANOTIME = LocalTime.now(nanoClock).getNano();
toAppendTo.append(NANOTIME);
}
}
原项目中采用的是xml方式配置。在log4j2.xml
中追加
1. 自定义参数转换器的包名,添加为Configuration
的属性。
packages="自定义参数转换器的包名"
自己调试的时候这里犯了一个很低级的错误,一直写成了类的全限定名,怎么也没看出问题,注意是包名。 2. 添加自定义参数
<Property name="Nano">%y</Property>
3. 使用自定义参数
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="${Nano}"/>
</Console>
2021-07-20 19:04:20,717 DEBUG - 716928173
2021-07-20 19:04:20,717 DEBUG - 717079760
2021-07-20 19:04:20,717 DEBUG - 717247531
大成功!