我不熟悉Log4j2。我编写了一个简单的程序,实际上使用log4j2将数据记录到RollingRandomAccessFile中。以下是程序:
public class Log4j2Example {
/**
* @param args the command line arguments
*/
public static Logger mlogger = null;
public static void main(String[] args) throws InterruptedException {
mlogger = LogManager.getLogger("Messages-log");
int i = 0;
while (true) {
String str = "Hello" + i;
System.out.println(str);
mlogger.info(str);
i++;
Thread.sleep(20);
}
}
}
我的日志4J2。xml文件
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">
<Appenders>
<RollingRandomAccessFile name="Messages-log" fileName="Log4J/Messages-${date:yyyy-MM-dd}.log"
immediateflush="true" filePattern="Log4J/Messages-%d{MM-dd-yyyy-HH}-%i.log.gz">
<PatternLayout>
<Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %p %m%n</Pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="500 MB"/>
</Policies>
<DefaultRolloverStrategy max="50"/>
</RollingRandomAccessFile>
</Appenders>
<Loggers>
<Logger name="Messages-log" level="info" additivity="false">
<appender-ref ref="Messages-log" level="info"/>
</Logger>
<root level="info">
<appender-ref ref="Messages-log"/>
</root>
</Loggers>
</Configuration>
我在日志文件中写了一个简单的语句,每个记录休眠20毫秒。现在,文件中的时间戳应该是:
如果第一条语句记录在17:20:32:354,那么下一条语句应该记录在17:20:32:374,但它记录在17:20:32:384。每个记录都会不断增加11毫秒。下面是我的日志文件输出
2017-12-04 17:40:42.205 INFO Hello11
2017-12-04 17:40:42.236 INFO Hello12
2017-12-04 17:40:42.268 INFO Hello13
2017-12-04 17:40:42.299 INFO Hello14
2017-12-04 17:40:42.330 INFO Hello15
2017-12-04 17:40:42.361 INFO Hello16
2017-12-04 17:40:42.393 INFO Hello17
2017-12-04 17:40:42.424 INFO Hello18
您可以看到第一条语句记录在。205毫秒,第二条语句记录在。236毫秒。事实上,我正在休眠线程20毫秒,因此正确的时间戳应该是。226毫秒。我做错了什么?我需要准确的时间戳写,因为它是非常重要的生产。我也用log4j 1试过了,但结果是一样的。我还将我的系统时间与互联网时间同步。有一件事,我发现它在5毫秒和15毫秒的睡眠中效果很好,但从20毫秒开始,这就造成了一个大问题。